Community
Participate
Working Groups
When running the LikeJettyXml server with the org.eclipse.jetty.client.Siege client with the args -c 100 -r 10 https://localhost:8444/dump About 20 of the connections hang for approx 30 seconds before completing. You can see this on the last few lines of output: Got 10/10 in 1966ms 99 Got 10/10 in 2087ms 98 Got 10/10 in 2207ms 97 Got 10/10 in 2204ms 95 Got 10/10 in 2212ms 96 Got 10/10 in 2211ms 94 Got 10/10 in 2221ms 93 Got 10/10 in 2221ms 92 Got 10/10 in 2235ms 91 Got 10/10 in 2226ms 90 Got 10/10 in 2261ms 87 Got 10/10 in 2238ms 88 Got 10/10 in 2262ms 89 Got 10/10 in 2319ms 85 Got 10/10 in 2299ms 86 Got 10/10 in 2310ms 84 Got 10/10 in 2306ms 83 Got 10/10 in 2337ms 82 Got 10/10 in 2363ms 77 Got 10/10 in 2333ms 78 Got 10/10 in 2349ms 76 Got 10/10 in 2359ms 74 Got 10/10 in 2337ms 79 Got 10/10 in 2375ms 72 Got 10/10 in 2361ms 71 Got 10/10 in 2391ms 70 Got 10/10 in 2375ms 69 Got 10/10 in 2416ms 64 Got 10/10 in 2398ms 65 Got 10/10 in 2376ms 66 Got 10/10 in 2416ms 61 Got 10/10 in 2421ms 60 Got 10/10 in 2410ms 59 Got 10/10 in 2442ms 57 Got 10/10 in 2442ms 56 Got 10/10 in 2406ms 62 Got 10/10 in 2427ms 55 Got 10/10 in 2443ms 58 Got 10/10 in 2403ms 63 Got 10/10 in 2456ms 53 Got 10/10 in 2462ms 52 Got 10/10 in 2437ms 50 Got 10/10 in 2447ms 54 Got 10/10 in 2445ms 51 Got 10/10 in 2438ms 48 Got 10/10 in 2467ms 47 Got 10/10 in 2442ms 45 Got 10/10 in 2461ms 43 Got 10/10 in 2452ms 41 Got 10/10 in 2459ms 44 Got 10/10 in 2470ms 42 Got 10/10 in 2449ms 49 Got 10/10 in 2440ms 46 Got 10/10 in 2473ms 40 Got 10/10 in 2482ms 39 Got 10/10 in 2384ms 67 Got 10/10 in 2473ms 38 Got 10/10 in 2500ms 33 Got 10/10 in 2523ms 31 Got 10/10 in 2526ms 29 Got 10/10 in 2523ms 28 Got 10/10 in 2502ms 27 Got 10/10 in 2526ms 26 Got 10/10 in 2538ms 25 Got 10/10 in 2511ms 30 Got 10/10 in 2526ms 24 Got 10/10 in 2513ms 23 Got 10/10 in 2488ms 32 Got 10/10 in 2503ms 34 Got 10/10 in 2522ms 21 Got 10/10 in 2549ms 20 Got 10/10 in 2555ms 22 Got 10/10 in 2598ms 19 Got 10/10 in 2480ms 35 Got 10/10 in 2472ms 36 Got 10/10 in 2569ms 17 Got 10/10 in 2563ms 14 Got 10/10 in 2547ms 15 Got 10/10 in 2550ms 16 Got 10/10 in 2561ms 18 Got 10/10 in 2551ms 13 Got 10/10 in 2385ms 73 Got 10/10 in 2499ms 37 Got 10/10 in 2401ms 68 Got 10/10 in 2349ms 75 Got 10/10 in 2346ms 80 Got 10/10 in 2329ms 81 Got 10/10 in 31759ms 12 Got 10/10 in 31956ms 11 Got 10/10 in 31957ms 10 Got 10/10 in 32159ms 9 Got 10/10 in 32179ms 8 Got 10/10 in 32172ms 7 Got 10/10 in 32178ms 6 Got 10/10 in 32182ms 4 Got 10/10 in 32200ms 5 Got 10/10 in 32224ms 3 Got 10/10 in 32200ms 2 Got 10/10 in 32193ms 1 Got 10/10 in 32189ms 0 After the delay, all responses are received (although the test does not currently check the body length). When run against port 8443 (the SslSelectChannelConnector), there is no delay an all complete.
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....
