Bugzilla – Full Text Bug Listing
| Summary: | [build] StressTest fails in jetty-server | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | [RT] Jetty | Reporter: | Davide De Rosa <keeshux> | ||||||
| Component: | build | Assignee: | Thomas Becker <tbecker> | ||||||
| Status: | CLOSED FIXED | QA Contact: | |||||||
| Severity: | minor | ||||||||
| Priority: | P3 | CC: | jetty-inbox, mgorovoy, tbecker | ||||||
| Version: | unspecified | ||||||||
| Target Milestone: | 7.2.x | ||||||||
| Hardware: | Macintosh | ||||||||
| OS: | Mac OS X - Carbon (unsup.) | ||||||||
| Whiteboard: | |||||||||
| Attachments: |
|
||||||||
|
Description
Davide De Rosa
Created attachment 187767 [details]
StressTest.java.patch
2011-01-27 20:47:43.841:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:44.842:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:45.842:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:46.842:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:47.843:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:48.843:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:49.843:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:50.843:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:51.844:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:52.844:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:53.844:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:54.845:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:55.845:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:56.845:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:57.846:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:58.846:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:47:59.846:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:00.847:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:01.847:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:02.847:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:03.848:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:04.848:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:05.848:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:06.849:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:07.849:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:08.849:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:09.850:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:10.850:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:11.850:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:12.850:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:13.851:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:14.851:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:15.851:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:16.852:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:17.852:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=13/17/23/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:18.852:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=19/22/28/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:19.852:INFO::qtp225912260{8<=20<=23/200,1} min/ave/max/target=44/51/61/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:20.853:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=72/80/91/100 errors/finished/loops=0/0/20 idle/threads=20/23
2011-01-27 20:48:21.853:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=99/99/100/100 errors/finished/loops=0/19/20 idle/threads=20/23
2011-01-27 20:48:22.853:INFO::qtp225912260{8<=20<=23/200,0} min/ave/max/target=100/100/100/100 errors/finished/loops=0/20/20 idle/threads=20/23
This is the STDOUT output on MacOs. Question is why the status remains unchanged so many times. Will have a short look at it tomorrow.
I wonder if it's a matter of max open sockets, because the test alone runs just fine but fails when executed right after testNonPersistent(). Perhaps the first thread, trying to spawn a new socket, keeps waiting for previous test sockets to leave the TIME_WAIT state. Putting a delay of some secs before testPersistent() starts makes execution more consistent. Gregw, I spent 15 min. to fully understand what the test is doing and found root cause and solution. David partially right. Both tests depend on each other. The problem is that if you close a connection it'll stay in TIME_WAIT state for a couple of seconds. The test runs fine on linux as is, but not anymore on MacOS since your last change (more stress). Root cause is: http://en.wikipedia.org/wiki/Ephemeral_port [...]The IANA suggests 49152 to 65535 as "dynamic and/or private ports.[...] [...]Many Linux kernels use 32768 to 61000.[...] The problem is that the ephemeral ports on MacOS are limited to about 16.383. This is also what I see when doing a while(true) on "neststat -an | wc": 10062 60596 779784 12615 75914 976359 15835 95234 1224299 16507 99258 1275994 # This is at the end of the first test! 16870 101436 1303925 16870 101436 1303925 16870 101436 1303925 16870 101436 1303925 16870 101436 1303925 Sometimes I reach the theoretically possible 16.383. Sometimes it stops close below like in the run above. No idea why. The test stalls until sockets get released from TIME_WAIT and are available again. That's why David's patch works around the issue. The fix is to tell MacOS to use a bigger port range: sudo sysctl -w net.inet.ip.portrange.first=32768 sudo sysctl -w net.inet.ip.portrange.hifirst=32768 However we can't tell anybody who wants to build on MacOS to apply this system changes (on the other hand you need to raise file descriptor limit anyhow). If we restart the server between both test runs the problem seems to be solved as well: - @BeforeClass - public static void init() throws Exception + @Before + public void init() throws Exception For me the problem is solved now by changing OS settings. The rest is up to you. I'd just change BeforeClass to Before at the cost of having to stop/start the server. Done. :) @David: If you read this. Could you please test the sysctl commands above and see if they work on Leopard as well? Thx again for raising this and the help provided. Yes, the tweak did the trick on Leopard. By the way, the Wikipedia statement on recent Windows ephemeral ranges tells that the same problem is likely to occur on those platforms. Given that I would go for the test initialization patch. Thank you Thomas! Yes, that's what I thought as well. As I have another Windows specific bug to investigate, I will test it on Windows and report back if it fails there as well. Created attachment 187827 [details]
StressTest.java.patch
reinitializes server before each test
i wouldn't be against a wiki page that details this information and put an entry in the FAQ about 'Test Failures on Windows and MacOSX' these things stress for a reason generally and short of putting it behind -DSTRESS I rather like them Jesse, apart from the ephemeral ranges issue, it's worth pointing that the test alone succeeds. In fact Thomas patch makes the suite complete correctly. Of course the FAQ entry still makes sense as I'm facing minor test issues here and there. Jesse, I think this issue can be closed. I'd work on the Wiki page, but I'm not a committer. So I can't do it myself. If you want, I prepare the text and send it to you unformatted. FAQ entry: Why does StressTest.java fail on MacOS? StressTest in jetty-server might fail on MacOSX due to an insufficient port range. Most OS have a limit of 65535 available TCP/IP ports. Read the following wikipedia entry for details: http://en.wikipedia.org/wiki/Ephemeral_port [...]The IANA suggests 49152 to 65535 as "dynamic and/or private ports.[...] [...]Many Linux kernels use 32768 to 61000.[...] We've fixed the test's code to make it run successfully on MacOS. If it fails however on your MacOS you've to raise the port range by executing the following to commands in a terminal: sudo sysctl -w net.inet.ip.portrange.first=32768 sudo sysctl -w net.inet.ip.portrange.hifirst=32768 It seems like Apple raised the limits for MacOS Lion, so on Lion it should work from scratch. If not, apply the sysctl commands and retry. thanks thomas |