New issue
Advanced search Search tips

Issue 731829 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Jun 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux
Pri: 3
Type: Bug



Sign in to add a comment

HttpServerTest.RequestWithTooLargeBody fails on Linux when run locally by itself

Project Member Reported by wangyix@chromium.org, Jun 9 2017

Issue description

Tested 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.


 
Labels: Needs-Feedback
I can't repro on Linux or Windows.  What error is it failing with?
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.
Labels: -Needs-Feedback
I get the exact same output as eroman@.
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?
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.
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.
Cc: rsleevi@chromium.org
Labels: OS-Linux
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()
Do you have you chrome checkout on a mechanical drive?
mmenke@ mine is on an SSD
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.
Project Member

Comment 11 by bugdroid1@chromium.org, 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

Owner: mmenke@chromium.org
Status: Fixed (was: Untriaged)
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