Bug 1200276
| Summary: | NIO2: Creating concurrent requests (non keep alive) to HTTPS results in Exceptions shown in debug log | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [JBoss] JBoss Enterprise Application Platform 6 | Reporter: | Radim Hatlapatka <rhatlapa> | ||||||||||
| Component: | Web | Assignee: | Rémy Maucherat <rmaucher> | ||||||||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Radim Hatlapatka <rhatlapa> | ||||||||||
| Severity: | medium | Docs Contact: | |||||||||||
| Priority: | unspecified | ||||||||||||
| Version: | 6.4.0 | CC: | bbaranow, cdewolf, chaowan, jstefl | ||||||||||
| Target Milestone: | CR2 | Keywords: | Reopened | ||||||||||
| Target Release: | EAP 6.4.1 | ||||||||||||
| Hardware: | Unspecified | ||||||||||||
| OS: | Unspecified | ||||||||||||
| Whiteboard: | |||||||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||||||
| Doc Text: | Story Points: | --- | |||||||||||
| Clone Of: | Environment: | ||||||||||||
| Last Closed: | 2015-03-30 13:29:24 UTC | Type: | Bug | ||||||||||
| Regression: | --- | Mount Type: | --- | ||||||||||
| Documentation: | --- | CRM: | |||||||||||
| Verified Versions: | Category: | --- | |||||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||||
| Embargoed: | |||||||||||||
| Bug Depends On: | |||||||||||||
| Bug Blocks: | 1188828, 1207953 | ||||||||||||
| Attachments: |
|
||||||||||||
|
Description
Radim Hatlapatka
2015-03-10 08:05:11 UTC
Created attachment 999761 [details]
Example config file
Created attachment 999762 [details]
Server certificate
Created attachment 999763 [details]
Server key
Since this looked 100% SSL related, I tried porting the Tomcat changes to handle incomplete writes, and this does seem to fix the issues for me. So is it possible to test with the change I committed ? I have tried it with the committed change [1] and I am getting still the same behaviour, I am still seeing [2] in debug log. Could it be somehow related to "Connection: close" header send by ApacheBench client for non keep alive connections? [1] https://source.jboss.org/changelog/JBossWeb?cs=2597 [2] 11:20:33,412 DEBUG [org.apache.tomcat.util] (http-/127.0.0.1:8443-9) JBWEB003023: Channel processing failed: javax.net.ssl.SSLException: java.util.concurrent.ExecutionException: java.io.IOException: Broken pipe at org.apache.tomcat.util.net.jsse.SecureNioChannel.handshake(SecureNioChannel.java:642) [jbossweb-7.5.7.Final.jar:7.5.7.Final] at org.apache.tomcat.util.net.jsse.NioJSSESocketChannelFactory.handshake(NioJSSESocketChannelFactory.java:227) [jbossweb-7.5.7.Final.jar:7.5.7.Final] at org.apache.tomcat.util.net.NioEndpoint$HandshakeHandler.run(NioEndpoint.java:635) [jbossweb-7.5.7.Final.jar:7.5.7.Final] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_75] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_75] at org.apache.tomcat.util.net.NioEndpoint$DefaultThreadFactory$1$1.run(NioEndpoint.java:1249) [jbossweb-7.5.7.Final.jar:7.5.7.Final] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_75] Caused by: java.util.concurrent.ExecutionException: java.io.IOException: Broken pipe at sun.nio.ch.CompletedFuture.get(CompletedFuture.java:69) [rt.jar:1.7.0_75] at org.apache.tomcat.util.net.jsse.SecureNioChannel.doHandshake(SecureNioChannel.java:760) [jbossweb-7.5.7.Final.jar:7.5.7.Final] at org.apache.tomcat.util.net.jsse.SecureNioChannel.handshake(SecureNioChannel.java:640) [jbossweb-7.5.7.Final.jar:7.5.7.Final] ... 6 more Caused by: java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.write0(Native Method) [rt.jar:1.7.0_75] at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) [rt.jar:1.7.0_75] at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) [rt.jar:1.7.0_75] at sun.nio.ch.IOUtil.write(IOUtil.java:51) [rt.jar:1.7.0_75] at sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:691) [rt.jar:1.7.0_75] at sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:381) [rt.jar:1.7.0_75] at sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:386) [rt.jar:1.7.0_75] ... 8 more I'm not running into any handshake issue, but let's assume there's a problem there. Can you verify the keepalive variant too by adding -k ? Handshake occurs less often obviously, and I think the rest is probably fine now. With keepalive variant it also behaves still the same => via two concurrent clients sending three messages results in only two messages written to access log, third timeouts on ApacheBench side. I am going to debug it a little bit more and if I find out anything interesting, I will post here my findings. Ok, something went wrong again during my testing, so problem solved. According to my testing, hopefully correct now (...), it seems sendfile is causing the issue in this case and can be disabled to fix it. I will continue testing. I have tried it with disabled sendfile done in [1] and I no longer see the issues connected to both bugs. [1] https://source.jboss.org/changelog/JBossWeb?cs=2598 Disabled sendfile on NIO2 connector makes all data to be transmitted as whole in both cases (for connection using keep-alive and without it). => The main issue is fixed, nevertheless I still see for non keep-alive connections the exception described in comment 9 in debug log. Not sure why I haven't notice during pretesting. There seems that there are still remaining some incomplete writes resulting in exception being thrown even when all data were already delivered to client (from statistics of apachebench client I see that client received all the data) This issue is partially fixed. The first and main issue was that not all data were delivered to requestor, which is now fixed. The second is that there occurs exception (IO exception or closed channel exception) in debug log of JBoss Web. The first part is fixed, the second isn't as the exceptions still occur with non-keepalive connection. Hypothesis is that there are still attempts to write to the channel which is closed in the meantime resulting in the broken pipe exceptions in the log. From the ab client the behaviour seems correct (all requested data are recieved). The exceptions in the debug log needs to be further investigated. Comment 9 is an exception during handshake, so if it is exclusively this one it is not related to the other issue. Yes, the exception I am seeing is the one from comment 9. As per https://bugzilla.redhat.com/show_bug.cgi?id=1200276#c28 the functionality works and the exception is a 'debug' exception thrown during connection setup. If we really want to deal with that exception differently we should have a new BZ (which I might just consider a RFE). I have created separate BZ#1225403 to track the occurrence of the exception in the debug log during handshaking. Setting this one as verified as per comment 27 and comment 28 the behaviour is otherwise correct and the exception in log appears as different issue tracked now in separate BZ. Retroactively bulk-closing issues from released EAP 6.4 cummulative patches. Retroactively bulk-closing issues from released EAP 6.4 cummulative patches. |