Bugzilla – Full Text Bug Listing
| Summary: | SslSocketConnector hang | ||
|---|---|---|---|
| Product: | [RT] Jetty | Reporter: | Greg Wilkins <gregw> |
| Component: | client | Assignee: | Simone Bordet <simone.bordet> |
| Status: | RESOLVED INVALID | QA Contact: | |
| Severity: | normal | ||
| Priority: | P3 | CC: | jetty-inbox |
| Version: | 7.6.0.RC0 | ||
| Target Milestone: | 7.5.x | ||
| Hardware: | PC | ||
| OS: | Linux | ||
| Whiteboard: | |||
|
Description
Greg Wilkins
Improving the siege class and using da.txt as the target, I can see that all data is received OK: Got 10/10 with 610000B in 3229ms 99 Got 10/10 with 610000B in 3269ms 98 Got 10/10 with 610000B in 3352ms 97 Got 10/10 with 610000B in 3380ms 96 Got 10/10 with 610000B in 3375ms 94 Got 10/10 with 610000B in 3366ms 95 Got 10/10 with 610000B in 3415ms 93 Got 10/10 with 610000B in 3433ms 92 Got 10/10 with 610000B in 3457ms 91 Got 10/10 with 610000B in 3536ms 90 Got 10/10 with 610000B in 3517ms 89 Got 10/10 with 610000B in 3589ms 88 Got 10/10 with 610000B in 3572ms 87 Got 10/10 with 610000B in 3603ms 86 Got 10/10 with 610000B in 3638ms 85 Got 10/10 with 610000B in 3653ms 84 Got 10/10 with 610000B in 3672ms 83 Got 10/10 with 610000B in 3709ms 82 Got 10/10 with 610000B in 3733ms 81 Got 10/10 with 610000B in 3755ms 78 Got 10/10 with 610000B in 3739ms 76 Got 10/10 with 610000B in 3758ms 79 Got 10/10 with 610000B in 3748ms 77 Got 10/10 with 610000B in 3841ms 74 Got 10/10 with 610000B in 3767ms 75 Got 10/10 with 610000B in 3745ms 80 Got 10/10 with 610000B in 3824ms 73 Got 10/10 with 610000B in 3809ms 72 Got 10/10 with 610000B in 3814ms 71 Got 10/10 with 610000B in 3825ms 70 Got 10/10 with 610000B in 3853ms 69 Got 10/10 with 610000B in 3866ms 67 Got 10/10 with 610000B in 3837ms 66 Got 10/10 with 610000B in 3841ms 68 Got 10/10 with 610000B in 3865ms 65 Got 10/10 with 610000B in 3891ms 64 Got 10/10 with 610000B in 3918ms 57 Got 10/10 with 610000B in 3934ms 55 Got 10/10 with 610000B in 3925ms 54 Got 10/10 with 610000B in 3947ms 56 Got 10/10 with 610000B in 3927ms 53 Got 10/10 with 610000B in 3918ms 58 Got 10/10 with 610000B in 3906ms 59 Got 10/10 with 610000B in 3916ms 60 Got 10/10 with 610000B in 3925ms 61 Got 10/10 with 610000B in 3942ms 52 Got 10/10 with 610000B in 3966ms 51 Got 10/10 with 610000B in 3965ms 50 Got 10/10 with 610000B in 3946ms 49 Got 10/10 with 610000B in 3906ms 62 Got 10/10 with 610000B in 3883ms 63 Got 10/10 with 610000B in 3992ms 48 Got 10/10 with 610000B in 3968ms 45 Got 10/10 with 610000B in 3991ms 46 Got 10/10 with 610000B in 3999ms 47 Got 10/10 with 610000B in 4027ms 44 Got 10/10 with 610000B in 4024ms 42 Got 10/10 with 610000B in 4044ms 37 Got 10/10 with 610000B in 4028ms 31 Got 10/10 with 610000B in 4057ms 29 Got 10/10 with 610000B in 4066ms 28 Got 10/10 with 610000B in 4033ms 32 Got 10/10 with 610000B in 4038ms 27 Got 10/10 with 610000B in 4063ms 30 Got 10/10 with 610000B in 4053ms 33 Got 10/10 with 610000B in 4042ms 34 Got 10/10 with 610000B in 4046ms 35 Got 10/10 with 610000B in 4097ms 22 Got 10/10 with 610000B in 4127ms 21 Got 10/10 with 610000B in 4118ms 20 Got 10/10 with 610000B in 4107ms 19 Got 10/10 with 610000B in 4118ms 18 Got 10/10 with 610000B in 4113ms 17 Got 10/10 with 610000B in 4092ms 23 Got 10/10 with 610000B in 4109ms 24 Got 10/10 with 610000B in 4079ms 25 Got 10/10 with 610000B in 4104ms 26 Got 10/10 with 610000B in 4145ms 16 Got 10/10 with 610000B in 4047ms 38 Got 10/10 with 610000B in 4049ms 36 Got 10/10 with 610000B in 4148ms 15 Got 10/10 with 610000B in 4036ms 39 Got 10/10 with 610000B in 4016ms 43 Got 10/10 with 610000B in 4150ms 14 Got 10/10 with 610000B in 4038ms 40 Got 10/10 with 610000B in 4023ms 41 Got 10/10 with 610000B in 32616ms 13 Got 10/10 with 610000B in 32620ms 12 Got 10/10 with 610000B in 32996ms 11 Got 10/10 with 610000B in 33211ms 10 Got 10/10 with 610000B in 33221ms 9 Got 10/10 with 610000B in 33431ms 8 Got 10/10 with 610000B in 33533ms 7 Got 10/10 with 610000B in 33538ms 6 Got 10/10 with 610000B in 33508ms 5 Got 10/10 with 610000B in 33508ms 4 Got 10/10 with 610000B in 33517ms 3 Got 10/10 with 610000B in 33518ms 2 Got 10/10 with 610000B in 33531ms 1 Got 10/10 with 610000B in 33577ms 0 furthermore, looking (as best I can) with wireshark, I can see that the 30s delay is terminated by a connection closing with FIN, but that additional application data is sent after the FIN, so it is not simply a matter of the client waiting to read EOF on the last response Adding logging to the server suggests that there are indeed more request/response cycles completed after the hang. So best guess at this point is that the client has received some complete responses, but has not noticed, so the next requests are not sent. This is backed up by the fact that the server looks idle during the hang. However it is unclear why using the SslSelectChannelConnector on the server does not trigger this apparent client issue? I added a dump to the siege and found that for the 14 hung concurrentExchanges there were 14 connection in need unwrap:
+- HttpConnection@1836684604//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@2138123066{localhost/127.0.0.1:8444->/127.0.0.1:42427,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@1228197450//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@381312122{localhost/127.0.0.1:8444->/127.0.0.1:42428,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@701727186//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@1719451110{localhost/127.0.0.1:8444->/127.0.0.1:42429,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@2096109425//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@2083397407{localhost/127.0.0.1:8444->/127.0.0.1:42430,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@1989360587//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@2097086015{localhost/127.0.0.1:8444->/127.0.0.1:42431,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@1010485566//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@74675057{localhost/127.0.0.1:8444->/127.0.0.1:42432,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@930227286//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@1083228271{localhost/127.0.0.1:8444->/127.0.0.1:42433,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@649045642//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@1545595021{localhost/127.0.0.1:8444->/127.0.0.1:42434,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@1440661981//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@1773272052{localhost/127.0.0.1:8444->/127.0.0.1:42435,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@327794742//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@678314853{localhost/127.0.0.1:8444->/127.0.0.1:42437,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@950674239//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@108966758{localhost/127.0.0.1:8444->/127.0.0.1:42436,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@703601193//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@2058536614{localhost/127.0.0.1:8444->/127.0.0.1:42438,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@1380290369//localhost:8444,g=0,p=-14
| +- Upgradable:SSL:SCEP@1072877218{localhost/127.0.0.1:8444->/127.0.0.1:42439,open,1} NEED_UNWRAP i/u/o=0/0/0
+- HttpConnection@1421876889//localhost:8444,g=0,p=-14
+- Upgradable:SSL:SCEP@1231288225{localhost/127.0.0.1:8444->/127.0.0.1:42440,open,1} NEED_UNWRAP i/u/o=0/0/0
These all look like they are idle. Not dispatched, interested in read, no data
buffered etc. This suggests the server has not sent some data!?!? So my suspicion is back to SslSelectConnector and/or BlockingHttpConnection as the villains
DOH! it was a limited thread pool in the server. nothing to look at here... move on.... |