Repository: netty/netty
Issue: Spdy error -> Error 337 (net::ERR_SPDY_PROTOCOL_ERROR): Unknown error
Labels: defect

hi,

I have added spdy support to a web server. The pipeline is fairly typical:

``` java
      pipeline.addLast("decoder", new SpdyFrameDecoder(spdyVersion));
      pipeline.addLast("spdy_encoder", new SpdyFrameEncoder(spdyVersion));
      pipeline.addLast("spdy_session_handler", new SpdySessionHandler(spdyVersion, true));
      pipeline.addLast("spdy_http_encoder", new SpdyHttpEncoder(spdyVersion));
      pipeline.addLast("spdy_http_decoder", new SpdyHttpDecoder(spdyVersion, config.getMaxContentSize()));
      if (config != null && config.getProcessingExecutor() != null) {
        pipeline.addLast("executor", new ExecutionHandler(config.getProcessingExecutor()));
      } //if
      pipeline.addLast("handler", new HttpServerHandler(channelGroup, handlers));
```

<i>spdyVersion</i> is set to either <b>2</b> or <b>3</b> depending on the outcome of NPN.

Using chrome 20.0.1132.43 and netty 3.5.2. 

Every once in a while chome would return the error:
Error 337 (net::ERR_SPDY_PROTOCOL_ERROR): Unknown error

Restarting chrome allows one to browse more before encountering the error again.

Switching on packet tracing in chrome results in:

> t=1341569010002 [st=58620]    SPDY_SESSION_SEND_RST_STREAM
>                               --> description = "Could not parse Spdy Control Frame Header."
>                               --> status = 1
>                               --> stream_id = 397

This error can be triggered with and without the ExecutionHandler. Any idea where one can start looking for the problem?


Issue comments:
hexdump of the frame causing the error would be helpful

On Fri, Jul 6, 2012 at 3:17 AM, naude-r
reply@reply.github.com
wrote:

> hi,
> 
> I have added spdy support to a web server. The pipeline is fairly typical:
> 
> ``` java
>       pipeline.addLast("decoder", new SpdyFrameDecoder(spdyVersion));
>       pipeline.addLast("spdy_encoder", new SpdyFrameEncoder(spdyVersion));
>       pipeline.addLast("spdy_session_handler", new SpdySessionHandler(spdyVersion, true));
>       pipeline.addLast("spdy_http_encoder", new SpdyHttpEncoder(spdyVersion));
>       pipeline.addLast("spdy_http_decoder", new SpdyHttpDecoder(spdyVersion, config.getMaxContentSize()));
>       if (config != null && config.getProcessingExecutor() != null) {
>         pipeline.addLast("executor", new ExecutionHandler(config.getProcessingExecutor()));
>       } //if
>       pipeline.addLast("handler", new HttpServerHandler(channelGroup, handlers));
> ```
> 
> <i>spdyVersion</i> is set to either <b>2</b> or <b>3</b> depending on the outcome of NPN.
> 
> Using chrome 20.0.1132.43 and netty 3.5.2.
> 
> Every once in a while chome would return the error:
> Error 337 (net::ERR_SPDY_PROTOCOL_ERROR): Unknown error
> 
> Restarting chrome allows one to browse more before encountering the error again.
> 
> Switching on packet tracing in chrome results in:
> 
> > t=1341569010002 [st=58620]    SPDY_SESSION_SEND_RST_STREAM
> >                               --> description = "Could not parse Spdy Control Frame Header."
> >                               --> status = 1
> >                               --> stream_id = 397
> 
> This error can be triggered with and without the ExecutionHandler. Any idea where one can start looking for the problem?
> 
> ---
> 
> Reply to this email directly or view it on GitHub:
> https://github.com/netty/netty/issues/442

@jpinner 

have created a gist with both the hex dump (from logginghandler) and the chrome trace:
https://gist.github.com/720271be47ffd4b54a25

please let me know if you need anything else....

Thanks for the gist. I've figured out the error -- it's a race condition:

The responses were compressed through the SpdyFrameDecoder in this order: 1, 3, 13, 15, 11, 9, 5, 17, 19

17 was written by worker #5 and 19 was written by worker #6, however, worker #6 was able to write to the channel before worker #5 so the responses were written to the channel in this order: 1, 3, 13, 15, 11, 9, 5, 19, 17

@trustin, @normanmaurer : how would you suggest addressing this for netty 3?

(isn't this fixed automatically in netty 4 by having the channel be single threaded in both directions?)

@jpinner sorry I guess you mean "SpdyFrameDecoder" right ? So you say the problem is that if you call:

channel.write(new ...);
channel.write(new ...); 

its possible that the second write will be faster then first if they are executed from different threads ? Thats correct as you would need to schedule the second in a ChannelFutureListener if you want to be sure that its executed after the first.

Is that necessarily scalable? what's to prevent 3 threads from writing concurrently? or 16?

I would need each write to be enqueued on a transfer queue that synchronized with the decoder state. And a dedicated thread to read from to transfer from that queue to the channel's write queue. Is there a way to schedule execution for the channel's worker thread?

what you could do is this:

``` java
channel.getChannelPipeline().execute(new Runnable() {
    public void run() {
         channel.write(..)
    }
}
```

This would execute the write request in the IO-Loop/Thread

thanks! :)

On Tue, Jul 10, 2012 at 12:28 AM, Norman Maurer
reply@reply.github.com
wrote:

> what you could do is this:
> 
> ``` java
> channel.getChannelPipeline().execute(new Runnable() {
>     public void run() {
>          channel.write(..)
>     }
> }
> ```
> 
> This would execute the write request in the IO-Loop/Thread
> 
> ---
> 
> Reply to this email directly or view it on GitHub:
> https://github.com/netty/netty/issues/442#issuecomment-6868771

I wonder if it would be a good idea todo this under-the-hood for the user. So on write it would schedule it in the event loop and so make sure that there can be no race. The downside would be that it will add some latency

@trustin wdyt ?

@jpinner thank you. quickly tested the patch and everything is now working as expected.

I prefer to keep the current behavior because it might affect existing applications built on top of 3.

@trustin, how so?

The sender's compression context and receiver's decompression context
must be kept in sync, so frames must be delivered to the socket in the
order they are compressed.

I think the existing race condition is a bug.

On Tue, Jul 10, 2012 at 6:02 AM, Trustin Lee
reply@reply.github.com
wrote:

> I prefer to keep the current behavior because it might affect existing applications built on top of 3.
> 
> ---
> 
> Reply to this email directly or view it on GitHub:
> https://github.com/netty/netty/issues/442#issuecomment-6874734

@jpinner I was talking about @normanmaurer 's proposal to force all downstream event invokcation to be run by an I/O thread.  Your fix is great. :-)


Pull request review comments:

Patch that resolved the issue:
diff --git a/src/main/java/org/jboss/netty/handler/codec/spdy/SpdyFrameEncoder.java b/src/main/java/org/jboss/netty/handler/codec/spdy/SpdyFrameEncoder.java
index d8bdd9b62c0..e6ed2ff325a 100644
--- a/src/main/java/org/jboss/netty/handler/codec/spdy/SpdyFrameEncoder.java
+++ b/src/main/java/org/jboss/netty/handler/codec/spdy/SpdyFrameEncoder.java
@@ -159,11 +159,7 @@ public void handleDownstream(
                 }
                 // Writes of compressed data must occur in order
                 final ChannelBuffer buffer = ChannelBuffers.wrappedBuffer(frame, data);
-                e.getChannel().getPipeline().execute(new Runnable() {
-                    public void run() {
-                        Channels.write(ctx, e.getFuture(), buffer, e.getRemoteAddress());
-                    }
-                });
+                Channels.write(ctx, e.getFuture(), buffer, e.getRemoteAddress());
             }
             return;
 
@@ -197,11 +193,7 @@ public void run() {
                 }
                 // Writes of compressed data must occur in order
                 final ChannelBuffer buffer = ChannelBuffers.wrappedBuffer(frame, data);
-                e.getChannel().getPipeline().execute(new Runnable() {
-                    public void run() {
-                        Channels.write(ctx, e.getFuture(), buffer, e.getRemoteAddress());
-                    }
-                });
+                Channels.write(ctx, e.getFuture(), buffer, e.getRemoteAddress());
             }
             return;
 
@@ -323,11 +315,7 @@ public void run() {
                 }
                 // Writes of compressed data must occur in order
                 final ChannelBuffer buffer = ChannelBuffers.wrappedBuffer(frame, data);
-                e.getChannel().getPipeline().execute(new Runnable() {
-                    public void run() {
-                        Channels.write(ctx, e.getFuture(), buffer, e.getRemoteAddress());
-                    }
-                });
+                Channels.write(ctx, e.getFuture(), buffer, e.getRemoteAddress());
             }
             return;
 


Test patch: