[GLASSFISH-18698] Broken Pipe errors are polluting the logs Created: 07/May/12  Updated: 16/Jan/13  Resolved: 16/Jan/13

Status: Resolved
Project: glassfish
Component/s: grizzly-kernel
Affects Version/s: 4.0_b23
Fix Version/s: None

Type: Bug Priority: Minor
Reporter: preston001 Assignee: Tim Quinn
Resolution: Duplicate Votes: 1
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Red Hat Enterprise


Issue Links:
Related
is related to GRIZZLY-1409 Change logging level for "broken pipe... Resolved

 Description   

In bug 14938 Tim Quinn states "The broken pipe messages are annoying but do not cause any loss of functionality. They seem to be logged when Java Web Start on the client already has some up-to-date JARs in its cache. "

I get thousands of these every day after migrating to 3.12. I'm having some other stability issues, and if these really aren't an issue then they shouldn't be reporting, or they should have a message that makes sense. As it is now, they're just polluting the logs.



 Comments   
Comment by Tim Quinn [ 08/May/12 ]

I am, at least temporarily, changing this to the Grizzly component.

The messages in 14938 come from Grizzly. As I wrote in my comments in that issue, it seems as if the messages occur when Java Web Start on a client gets information about - or attempts to download - a JAR that turns out to be already up-to-date on the client (although I am not positive about this). If that is the case, the Java Web Start client software is not GlassFish-specific but is part of the Java runtime and, as such, we have no control over it.

Comment by oleksiys [ 14/May/12 ]

just to make sure, which GF version this issue is related to?
thx.

Comment by Ryan Lubke [ 17/May/12 ]

Tim, could you please attach a stack trace coming from 3.1.2? The stack traces from the issue you referenced don't match up - it seems those were from 3.1. If that is the case, there have been many changes since that release.

Comment by Ryan Lubke [ 29/Oct/12 ]

Preston, does this issue persist in 3.1.2.2?

Comment by preston001 [ 30/Oct/12 ]

Something changed with 3.122. It's not as frequent (before it was just out of control) but it's still there quite a bit. There's also a similar stack that appears a lot as well. It's identical if you swap "Connection reset by peer" for "Broken Pipe".

java.io.IOException: Connection reset by peer
at sun.nio.ch.FileDispatcher.write0(Native Method)
at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:29)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:69)
at sun.nio.ch.IOUtil.write(IOUtil.java:40)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:334)
at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:108)
at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:76)
at com.sun.grizzly.util.SSLOutputWriter.flushChannel(SSLOutputWriter.java:102)
at com.sun.grizzly.ssl.SSLOutputBuffer.flushChannel(SSLOutputBuffer.java:138)
at com.sun.grizzly.http.SocketChannelOutputBuffer.flushBuffer(SocketChannelOutputBuffer.java:498)
at com.sun.grizzly.http.SocketChannelOutputBuffer.realWriteBytes0(SocketChannelOutputBuffer.java:381)
at com.sun.grizzly.http.SocketChannelOutputBuffer.realWriteBytes(SocketChannelOutputBuffer.java:364)
at com.sun.grizzly.tcp.http11.InternalOutputBuffer$OutputStreamOutputBuffer.doWrite(InternalOutputBuffer.java:894)
at com.sun.grizzly.tcp.http11.filters.IdentityOutputFilter.doWrite(IdentityOutputFilter.java:159)
at com.sun.grizzly.tcp.http11.InternalOutputBuffer.doWrite(InternalOutputBuffer.java:661)
at com.sun.grizzly.tcp.Response.doWrite(Response.java:685)
at com.sun.grizzly.tcp.StaticResourcesAdapter.service(StaticResourcesAdapter.java:237)
at org.glassfish.appclient.server.core.jws.RestrictedContentAdapter.processContent(RestrictedContentAdapter.java:267)
at org.glassfish.appclient.server.core.jws.RestrictedContentAdapter.serviceContent(RestrictedContentAdapter.java:227)
at org.glassfish.appclient.server.core.jws.AppClientHTTPAdapter.service(AppClientHTTPAdapter.java:158)
at com.sun.grizzly.tcp.http11.GrizzlyAdapter.service(GrizzlyAdapter.java:179)
at com.sun.enterprise.v3.server.HK2Dispatcher.dispath(HK2Dispatcher.java:117)
at com.sun.enterprise.v3.services.impl.ContainerMapper$Hk2DispatcherCallable.call(ContainerMapper.java:354)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:849)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:746)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1045)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:228)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
at java.lang.Thread.run(Thread.java:662)

Comment by robal_k [ 13/Dec/12 ]

I'm using GF 3.1.2.2 on Ubuntu 11.04 machine and get similar exception every 30sec or so:

SEVERE: ProtocolChain exception
java.io.IOException: Broken pipe
at sun.nio.ch.FileDispatcher.writev0(Native Method)
at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:33)
at sun.nio.ch.IOUtil.write(IOUtil.java:125)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:367)
at java.nio.channels.SocketChannel.write(SocketChannel.java:360)
at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:206)
at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:170)
at com.sun.grizzly.http.portunif.HttpRedirector.redirect(HttpRedirector.java:257)
at com.sun.grizzly.http.portunif.HttpRedirector.redirect(HttpRedirector.java:228)
at com.sun.grizzly.config.HttpRedirectFilter.execute(HttpRedirectFilter.java:91)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
at com.sun.grizzly.portunif.CustomFilterChainProtocolHandler.handle(CustomFilterChainProtocolHandler.java:74)
at com.sun.grizzly.portunif.PUReadFilter.processProtocolHandler(PUReadFilter.java:319)
at com.sun.grizzly.portunif.PUReadFilter.execute(PUReadFilter.java:213)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
at java.lang.Thread.run(Thread.java:662)

I get it with fresh installation of GF, with no Webapps deployed.

Interestingly, the "Internal Server" (also 3.1.2.2) that came with "Oracle Server Tools" plugin for my Eclipse, runs fine on my Windows machine.

Comment by robal_k [ 14/Jan/13 ]

Just tried installing GF 3.1.2.2 on clean Ubuntu 12.04 LTS box.
Same problem here as well.

Polluted logs make it harder for me to debug webapps :/

Comment by oleksiys [ 14/Jan/13 ]

@robal_k
pls. use this link to patch the GF 3.1.2.2 [1] (unfortunately attachments are not allowed at the moment)

@preston001
the logging you observe is caused by Java Web Start RestrictedContentAdapter class, will reassign this issue to the corresponding team to take a look at it.

[1] http://dl.dropbox.com/u/7319744/grizzly-config.jar

Comment by oleksiys [ 14/Jan/13 ]

Tim, can you pls. doublecheck that?

Comment by robal_k [ 15/Jan/13 ]

@oleksiys
The patch solved the issue. Thanks !

Comment by Tim Quinn [ 16/Jan/13 ]

At Alexey's request I have opened a Grizzly issue for this. In Grizzly 2.3 the method to which GlassFish's Java Web Start support is delegating handles the response asynchronously, so changing the GlassFish logging does not suppress the log messages - that has to happen in Grizzly.

http://java.net/jira/browse/GRIZZLY-1409

Comment by Tim Quinn [ 16/Jan/13 ]

I'm closing this, at least as far as GlassFish is concerned.

I've linked this issue to the new Grizzly one which captures the need to suppress these messages on the Grizzly side (since that's where they originate from now that Grizzly is doing the work asynchronously).

After quite some investigation it's not clear why Java Web Start is requesting a download and then abandoning it; that's what seems to trigger the errors on the server side. I will continue looking into this as time permits.

Generated at Sun Mar 29 22:25:00 UTC 2015 using JIRA 6.2.3#6260-sha1:63ef1d6dac3f4f4d7db4c1effd405ba38ccdc558.