Buffer already pending write (simpleframework issue ?)

[jpcaruana]

Hi,

on one of my webservices, we encounter a lot of [Fluent] - Unexpected error.

What we observe is this web service stops working at the same time we have the stack trace at the end of my post. I don't know if it's related, but it seems so. (and nginx take it out of its pool)

This service provides dynamic images for our users, and I guess they sometime don't wait for the image to come close the connexion abruptly.

Any idea ? Where should I look ?

we use version 2.102

Da stack trace :

Oct  7 17:28:13 [ERROR] [Worker: RequestDispatcher: Thread-21] [Fluent] - Unexpected error:
Oct  7 17:28:13 org.simpleframework.http.core.BodyEncoderException: Error sending response
Oct  7 17:28:13     at org.simpleframework.http.core.CloseEncoder.encode(CloseEncoder.java:137)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseEncoder.write(ResponseEncoder.java:197)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseEncoder.write(ResponseEncoder.java:179)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:210)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:181)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:160)
Oct  7 17:28:13     at java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.java:253)
Oct  7 17:28:13     at java.util.zip.DeflaterOutputStream.write(DeflaterOutputStream.java:211)
Oct  7 17:28:13     at java.util.zip.GZIPOutputStream.write(GZIPOutputStream.java:145)
Oct  7 17:28:13     at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.write(PayloadWriter.java:296)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.writeBytes(PayloadWriter.java:209)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.write(PayloadWriter.java:189)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.writeAndCloseSync(PayloadWriter.java:106)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.writeAndClose(PayloadWriter.java:95)
Oct  7 17:28:13     at net.codestory.http.AbstractWebServer.handleHttp(AbstractWebServer.java:154)
Oct  7 17:28:13     at net.codestory.http.AbstractWebServer$$Lambda$97/1742900195.handle(Unknown Source)
Oct  7 17:28:13     at org.simpleframework.http.socket.service.RouterContainer.handle(RouterContainer.java:106)
Oct  7 17:28:13     at org.simpleframework.http.core.RequestDispatcher.dispatch(RequestDispatcher.java:121)
Oct  7 17:28:13     at org.simpleframework.http.core.RequestDispatcher.run(RequestDispatcher.java:103)
Oct  7 17:28:13     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Oct  7 17:28:13     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Oct  7 17:28:13     at java.lang.Thread.run(Thread.java:745)
Oct  7 17:28:13 Caused by: java.io.IOException: Buffer already pending write
Oct  7 17:28:13     at org.simpleframework.transport.SocketBuffer.write(SocketBuffer.java:133)
Oct  7 17:28:13     at org.simpleframework.transport.SocketBufferWriter.write(SocketBufferWriter.java:72)
Oct  7 17:28:13     at org.simpleframework.transport.SocketTransport.write(SocketTransport.java:233)
Oct  7 17:28:13     at org.simpleframework.transport.TransportWriter.write(TransportWriter.java:125)
Oct  7 17:28:13     at org.simpleframework.http.core.CloseEncoder.encode(CloseEncoder.java:132)
Oct  7 17:28:13     ... 23 more
Oct  7 17:28:13 [ERROR] [Worker: RequestDispatcher: Thread-18] [Fluent] - Unexpected error:
Oct  7 17:28:13 org.simpleframework.http.core.BodyEncoderException: Error sending response
Oct  7 17:28:13     at org.simpleframework.http.core.CloseEncoder.encode(CloseEncoder.java:137)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseEncoder.write(ResponseEncoder.java:197)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseEncoder.write(ResponseEncoder.java:179)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:210)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:181)
Oct  7 17:28:13     at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:160)
Oct  7 17:28:13     at java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.java:253)
Oct  7 17:28:13     at java.util.zip.DeflaterOutputStream.write(DeflaterOutputStream.java:211)
Oct  7 17:28:13     at java.util.zip.GZIPOutputStream.write(GZIPOutputStream.java:145)
Oct  7 17:28:13     at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.write(PayloadWriter.java:296)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.writeBytes(PayloadWriter.java:209)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.write(PayloadWriter.java:189)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.writeAndCloseSync(PayloadWriter.java:106)
Oct  7 17:28:13     at net.codestory.http.payload.PayloadWriter.writeAndClose(PayloadWriter.java:95)
Oct  7 17:28:13     at net.codestory.http.AbstractWebServer.handleHttp(AbstractWebServer.java:154)
Oct  7 17:28:13     at net.codestory.http.AbstractWebServer$$Lambda$97/1742900195.handle(Unknown Source)
Oct  7 17:28:13     at org.simpleframework.http.socket.service.RouterContainer.handle(RouterContainer.java:106)
Oct  7 17:28:13     at org.simpleframework.http.core.RequestDispatcher.dispatch(RequestDispatcher.java:121)
Oct  7 17:28:13     at org.simpleframework.http.core.RequestDispatcher.run(RequestDispatcher.java:103)
Oct  7 17:28:13     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Oct  7 17:28:13     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Oct  7 17:28:13     at java.lang.Thread.run(Thread.java:745)
Oct  7 17:28:13 Caused by: java.io.IOException: Buffer already pending write
Oct  7 17:28:13     at org.simpleframework.transport.SocketBuffer.write(SocketBuffer.java:133)
Oct  7 17:28:13     at org.simpleframework.transport.SocketBufferWriter.write(SocketBufferWriter.java:72)
Oct  7 17:28:13     at org.simpleframework.transport.SocketTransport.write(SocketTransport.java:233)
Oct  7 17:28:13     at org.simpleframework.transport.TransportWriter.write(TransportWriter.java:125)
Oct  7 17:28:13     at org.simpleframework.http.core.CloseEncoder.encode(CloseEncoder.java:132)
Oct  7 17:28:13     ... 23 more

[jpcaruana]

and we don't have a monstruous traffic on this webservice

[jpcaruana]

broken pipe don't seem to break my web service:

Oct  7 18:02:48  [ERROR] [Worker: RequestDispatcher: Thread-25] [Fluent] - Unexpected error:
Oct  7 18:02:48  org.simpleframework.http.core.BodyEncoderException: Error sending response
Oct  7 18:02:48      at org.simpleframework.http.core.CloseEncoder.encode(CloseEncoder.java:137)
Oct  7 18:02:48      at org.simpleframework.http.core.ResponseEncoder.write(ResponseEncoder.java:197)
Oct  7 18:02:48      at org.simpleframework.http.core.ResponseEncoder.write(ResponseEncoder.java:179)
Oct  7 18:02:48      at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:210)
Oct  7 18:02:48      at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:181)
Oct  7 18:02:48      at org.simpleframework.http.core.ResponseBuffer.write(ResponseBuffer.java:160)
Oct  7 18:02:48      at java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.java:253)
Oct  7 18:02:48      at java.util.zip.DeflaterOutputStream.write(DeflaterOutputStream.java:211)
Oct  7 18:02:48      at java.util.zip.GZIPOutputStream.write(GZIPOutputStream.java:145)
Oct  7 18:02:48      at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
Oct  7 18:02:48      at net.codestory.http.payload.PayloadWriter.write(PayloadWriter.java:296)
Oct  7 18:02:48      at net.codestory.http.payload.PayloadWriter.writeBytes(PayloadWriter.java:209)
Oct  7 18:02:48      at net.codestory.http.payload.PayloadWriter.write(PayloadWriter.java:189)
Oct  7 18:02:48      at net.codestory.http.payload.PayloadWriter.writeAndCloseSync(PayloadWriter.java:106)
Oct  7 18:02:48      at net.codestory.http.payload.PayloadWriter.writeAndClose(PayloadWriter.java:95)
Oct  7 18:02:48      at net.codestory.http.AbstractWebServer.handleHttp(AbstractWebServer.java:154)
Oct  7 18:02:48      at net.codestory.http.AbstractWebServer$$Lambda$97/1296612741.handle(Unknown Source)
Oct  7 18:02:48      at org.simpleframework.http.socket.service.RouterContainer.handle(RouterContainer.java:106)
Oct  7 18:02:48      at org.simpleframework.http.core.RequestDispatcher.dispatch(RequestDispatcher.java:121)
Oct  7 18:02:48      at org.simpleframework.http.core.RequestDispatcher.run(RequestDispatcher.java:103)
Oct  7 18:02:48      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Oct  7 18:02:48      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Oct  7 18:02:48      at java.lang.Thread.run(Thread.java:745)
Oct  7 18:02:48  Caused by: java.io.IOException: Relais brisé (pipe)
Oct  7 18:02:48      at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
Oct  7 18:02:48      at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
Oct  7 18:02:48      at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
Oct  7 18:02:48      at sun.nio.ch.IOUtil.write(IOUtil.java:51)
Oct  7 18:02:48      at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471)
Oct  7 18:02:48      at org.simpleframework.transport.SocketBuffer.merge(SocketBuffer.java:179)
Oct  7 18:02:48      at org.simpleframework.transport.SocketBuffer.write(SocketBuffer.java:138)
Oct  7 18:02:48      at org.simpleframework.transport.SocketBufferWriter.write(SocketBufferWriter.java:72)
Oct  7 18:02:48      at org.simpleframework.transport.SocketTransport.write(SocketTransport.java:233)
Oct  7 18:02:48      at org.simpleframework.transport.TransportWriter.write(TransportWriter.java:125)
Oct  7 18:02:48      at org.simpleframework.http.core.CloseEncoder.encode(CloseEncoder.java:132)
Oct  7 18:02:48      ... 23 more

When this occurs, service is still up

[dgageot]

I have no idea. I'll take a look tomorrow.
btw, you might want to deactivate gzip in fluent-http and let nginx do the job

[jpcaruana]

nice design: -Dhttp.disable.gzip=true (could be documented though)