HttpServerTest.RequestWithTooLargeBody fails on Linux when run locally by itself |
||||
Issue descriptionTested at Chromium commit 28315859335578253ca195fb1a2fedb40889ae6b on Goobuntu. What steps will reproduce the problem? (1) Clone the Chromium repo (2) Build net-unittests (3) Run net-unittests --gtest_filter="HttpServerTest.RequestWithTooLargeBody" What is the expected result? The test passes. What happens instead? The test fails. However, if I run all HttpServerTests together, i.e. net-unittests --gtest_filter="HttpServerTest.*", all tests (including RequestWithTooLargeBody) pass.
,
Jun 9 2017
I can repro on Linux:
Note: Google Test filter = HttpServerTest.RequestWithTooLargeBody
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from HttpServerTest
[ RUN ] HttpServerTest.RequestWithTooLargeBody
../../net/server/http_server_unittest.cc:516: Failure
Value of: RunLoopWithTimeout(&run_loop)
Actual: false
Expected: true
[ FAILED ] HttpServerTest.RequestWithTooLargeBody (1293 ms)
[----------] 1 test from HttpServerTest (1293 ms total)
[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (1293 ms total)
[ PASSED ] 0 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] HttpServerTest.RequestWithTooLargeBody
1 FAILED TEST
[1/1] HttpServerTest.RequestWithTooLargeBody (1293 ms)
1 test failed:
HttpServerTest.RequestWithTooLargeBody (../../net/server/http_server_unittest.cc:486)
Tests took 1 seconds.
,
Jun 9 2017
I get the exact same output as eroman@.
,
Jun 9 2017
Hrm, so it's just timing out...Tests really should include timeouts, anyways. If you guys remove the timeout (Or increase it from seconds to days), does the test pass or hang?
,
Jun 9 2017
Correct. For me the timeout is the cause of the failure. On my linux workstation it takes 1.1 seconds to run that test. ... However on my mac laptop it only takes 18 ms When other tests are run first, it takes just over 1 second to run the test and doesn't trigger the timeout failure.
,
Jun 9 2017
That's weird. My Linux debug build was taking less than 200 milliseconds (Can't remember if it was closer to 100 or 20, but no where near a second). The test was also recent disabled on MSAN, I believe, for being too slow there as well.
,
Jun 9 2017
For me the culprit is NSS, which unfortunately is on the critical path of that test :( i.e. EnsureNSSInit() gets called, and it takes over 1 second to load the database, which causes the test to timeout when run individually. If other tests are run first, it passes since the singleton is already initialized. I didn't dig into the NSS specifics, but Ryan has told me in the past that we have an unholy NSS setup on corp workstations. We could eagerly call crypto::EnsureNSSInit() early, say in the net test suite runner to address this. While it would fix this particular timeout, it would have the potential downside of reducing our coverage of places that forget to initialize NSS. That said, that is of dubious use given just how many tests have the sideffect of initializing that singleton anyways. For the record, here is the backtrace for how we reach NSS initialization in this test: #3 0x7f31f522c6de crypto::EnsureNSSInit() #4 0x7f31f4172851 net::CertDatabase::CertDatabase() #5 0x7f31f3f9fc30 base::DefaultSingletonTraits<>::New() #6 0x7f31f3f9f601 base::Singleton<>::get() #7 0x7f31f3f9f429 net::CertDatabase::GetInstance() #8 0x7f31f416d110 net::CachingCertVerifier::CachingCertVerifier() #9 0x7f31f3fa6fbc _ZN4base10MakeUniqueIN3net19CachingCertVerifierEJSt10unique_ptrINS1_25MultiThreadedCertVerifierESt14default_deleteIS4_EEEEENS_8 internal16MakeUniqueResultIT_E6ScalarEDpOT0_ #10 0x7f31f3fa6356 net::CertVerifier::CreateDefault() #11 0x0000025324b6 net::TestURLRequestContext::Init() #12 0x0000025322d7 net::TestURLRequestContext::TestURLRequestContext() #13 0x000002532227 net::TestURLRequestContext::TestURLRequestContext() #14 0x0000025332f1 net::TestURLRequestContextGetter::GetURLRequestContext() #15 0x7f31f4931f8c net::URLFetcherCore::StartURLRequestWhenAppropriate() #16 0x7f31f4930b9b net::URLFetcherCore::DidInitializeWriter() #17 0x7f31f492c6d5 net::URLFetcherCore::StartOnIOThread() #18 0x7f31f4936267 _ZN4base8internal13FunctorTraitsIMN3net14URLFetcherCoreEFvvEvE6InvokeIRK13scoped_refptrIS3_EJEEEvS5_OT_DpOT0_ #19 0x7f31f49361b1 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIRKMN3net14URLFetcherCoreEFvvEJRK13scoped_refptrIS5_EEEEvOT_DpOT0_ #20 0x7f31f4936152 _ZN4base8internal7InvokerINS0_9BindStateIMN3net14URLFetcherCoreEFvvEJ13scoped_refptrIS4_EEEEFvvEE7RunImplIRKS6_RKSt5tupleIJS8_ EEJLm0EEEEvOT_OT0_NS_13IndexSequenceIJXspT1_EEEE #21 0x7f31f493609c _ZN4base8internal7InvokerINS0_9BindStateIMN3net14URLFetcherCoreEFvvEJ13scoped_refptrIS4_EEEEFvvEE3RunEPNS0_13BindStateBaseE #22 0x7f31f36e718e _ZNO4base8CallbackIFvvELNS_8internal8CopyModeE0ELNS2_10RepeatModeE0EE3RunEv #23 0x7f31f37315fe base::debug::TaskAnnotator::RunTask() #24 0x7f31f37c81bd base::MessageLoop::RunTask() #25 0x7f31f37c8447 base::MessageLoop::DeferOrRunPendingTask() #26 0x7f31f37c875f base::MessageLoop::DoWork() #27 0x7f31f37dd64e base::MessagePumpLibevent::Run() #28 0x7f31f37c7b88 base::MessageLoop::Run() #29 0x7f31f387159d base::RunLoop::Run() #30 0x0000021a48b1 net::(anonymous namespace)::RunLoopWithTimeout() #31 0x0000021aacd3 net::(anonymous namespace)::HttpServerTest_RequestWithTooLargeBody_Test::TestBody()
,
Jun 9 2017
Do you have you chrome checkout on a mechanical drive?
,
Jun 9 2017
mmenke@ mine is on an SSD
,
Jun 9 2017
It's the TPM stuff. There's an environment variable to force an alternative NSS DB directory (and/or running it in a way that remaps $HOME/.pki/nssdb) is sufficient to avoid the problem. Or changing the test timeout.
,
Jun 13 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/8e2811b4b174030c9d0af24781fc2dfdf9e75ad9 commit 8e2811b4b174030c9d0af24781fc2dfdf9e75ad9 Author: mmenke <mmenke@chromium.org> Date: Tue Jun 13 19:00:23 2017 Remove 1 second timeouts from HttpServerTests. On some systems, starting up NSS takes longer than that. In general, tests shouldn't be relying on timeouts, anyways, beyond the shared per-test timeout. BUG= 731829 Review-Url: https://codereview.chromium.org/2935453004 Cr-Commit-Position: refs/heads/master@{#479086} [modify] https://crrev.com/8e2811b4b174030c9d0af24781fc2dfdf9e75ad9/net/server/http_server_unittest.cc
,
Jun 14 2017
Going to close this (Though if someone wants to look at the SSL side of things causing tests to run slowly, even those that don't strictly need TPM, be my guest). |
||||
►
Sign in to add a comment |
||||
Comment 1 by mmenke@chromium.org
, Jun 9 2017