net_unittests occasionally fails to start LocalTestServer on Mac10.10 Tests bot |
|||||||||
Issue descriptionhttps://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mac10.10%20Tests/31532 https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mac10.10%20Tests/31475 https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mac10.10%20Tests/31454 and many more test runs have numerous net_unittests failures. All the failures look like: [ RUN ] OCSPVerify/HTTPSOCSPVerifyTest.VerifyResult/1 [83756:779:0419/211412.166525:47113013464048:ERROR:local_test_server_posix.cc(81)] poll() timed out; bytes_read=0 [83756:779:0419/211412.166573:47113013502817:ERROR:local_test_server_posix.cc(168)] Could not read server_data_len ../../net/url_request/url_request_unittest.cc:10809: Failure Value of: test_server.Start() Actual: false Expected: true Stack trace: 0 net_unittests 0x0000000107bf238b testing::internal::UnitTestImpl::CurrentOsStackTraceExceptTop(int) + 91 1 net_unittests 0x0000000107bf1d49 testing::internal::AssertHelper::operator=(testing::Message const&) const + 89 2 net_unittests 0x00000001078e77bb net::HTTPSOCSPTest::DoConnectionWithDelegate(net::BaseTestServer::SSLOptions const&, net::TestDelegate*, net::SSLInfo*) + 507 3 net_unittests 0x00000001078e6fb7 net::HTTPSOCSPVerifyTest_VerifyResult_Test::TestBody() + 359 ../../net/url_request/url_request_unittest.cc:11564: Failure
,
Apr 27 2018
I was just being the Chromium Build sheriff. I don't have any information other than what is in the bug. It was failing and then I reverted a change and then it stopped failing so I marked it fixed. Sorry I can't be more helpful.
,
May 1 2018
Looks like this hasn't been fixed; three more failures in the last three days: https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mac10.10%20Tests/31754 https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mac10.10%20Tests/31710 https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mac10.10%20Tests/31662
,
May 2 2018
[+iannucci]: Maybe related to the vpython switch / issue 822256 and issue 804174? Test seems to be hanging while starting the python test server.
,
May 2 2018
,
May 3 2018
,
May 3 2018
I don't know the significance, but many of the test logs do have vpython errors: https://logs.chromium.org/v/?s=chromium%2Fbuildbucket%2Fcr-buildbucket.appspot.com%2F8947542763357872384%2F%2B%2Fsteps%2Fnet_unittests_on_Mac-10.10%2F0%2Fstdout [ RUN ] URLRequestTestFTP.RawBodyBytes [E2018-05-03T07:11:30.376412-07:00 4667 0 annotate.go:242] goroutine 1: [E2018-05-03T07:11:30.376501-07:00 4667 0 annotate.go:242] #0 go.chromium.org/luci/vpython/venv/venv.go:475 - venv.(*Env).createLocked() [E2018-05-03T07:11:30.376544-07:00 4667 0 annotate.go:242] reason: failed to remove existing root [E2018-05-03T07:11:30.376613-07:00 4667 0 annotate.go:242] [E2018-05-03T07:11:30.376643-07:00 4667 0 annotate.go:242] #1 go.chromium.org/luci/vpython/venv/venv.go:272 - venv.(*Env).ensure.func1() [E2018-05-03T07:11:30.376688-07:00 4667 0 annotate.go:242] reason: failed to create new VirtualEnv [E2018-05-03T07:11:30.376714-07:00 4667 0 annotate.go:242] [E2018-05-03T07:11:30.376739-07:00 4667 0 annotate.go:242] #2 go.chromium.org/luci/vpython/venv/venv.go:955 - venv.mustReleaseLock() [E2018-05-03T07:11:30.377148-07:00 4667 0 annotate.go:242] #3 go.chromium.org/luci/vpython/venv/venv.go:258 - venv.(*Env).ensure() [E2018-05-03T07:11:30.377178-07:00 4667 0 annotate.go:242] #4 go.chromium.org/luci/vpython/venv/venv.go:328 - venv.(*Env).withImpl() [E2018-05-03T07:11:30.377206-07:00 4667 0 annotate.go:242] #5 go.chromium.org/luci/vpython/venv/venv.go:168 - venv.With() [E2018-05-03T07:11:30.377269-07:00 4667 0 annotate.go:242] #6 go.chromium.org/luci/vpython/run.go:63 - vpython.Run() [E2018-05-03T07:11:30.377295-07:00 4667 0 annotate.go:242] #7 go.chromium.org/luci/vpython/application/application.go:318 - application.(*application).mainImpl() [E2018-05-03T07:11:30.377342-07:00 4667 0 annotate.go:242] #8 go.chromium.org/luci/vpython/application/application.go:402 - application.(*Config).Main.func1() [E2018-05-03T07:11:30.377372-07:00 4667 0 annotate.go:242] #9 go.chromium.org/luci/vpython/application/support.go:47 - application.run() [E2018-05-03T07:11:30.377399-07:00 4667 0 annotate.go:242] #10 go.chromium.org/luci/vpython/application/application.go:401 - application.(*Config).Main() [E2018-05-03T07:11:30.377434-07:00 4667 0 annotate.go:242] #11 vpython/main.go:92 - main.mainImpl() [E2018-05-03T07:11:30.377460-07:00 4667 0 annotate.go:242] #12 vpython/main.go:98 - main.main() [E2018-05-03T07:11:30.377485-07:00 4667 0 annotate.go:242] #13 runtime/proc.go:195 - runtime.main() [E2018-05-03T07:11:30.377511-07:00 4667 0 annotate.go:242] #14 runtime/asm_amd64.s:2337 - runtime.goexit() [4189:779:0503/071130.379904:43345824371351:ERROR:local_test_server_posix.cc(169)] Could not read server_data_len ../../net/url_request/url_request_unittest.cc:12391: Failure Value of: ftp_test_server_.Start() Actual: false Expected: true Stack trace: 0 net_unittests 0x000000010497236b testing::internal::UnitTestImpl::CurrentOsStackTraceExceptTop(int) + 91 1 net_unittests 0x0000000104971d29 testing::internal::AssertHelper::operator=(testing::Message const&) const + 89 2 net_unittests 0x000000010464ee0f net::URLRequestTestFTP_RawBodyBytes_Test::TestBody() + 559 [ FAILED ] URLRequestTestFTP.RawBodyBytes (834 ms) [ RUN ] WebSocketEndToEndTest.HstsHttpsToWebSocket [E2018-05-03T07:11:30.644456-07:00 4673 0 config.go:310] Failed to get runtime information: {"error":"exit status 1"} [E2018-05-03T07:11:30.644893-07:00 4673 0 annotate.go:242] original error: exit status 1 [E2018-05-03T07:11:30.644930-07:00 4673 0 annotate.go:242] [E2018-05-03T07:11:30.644970-07:00 4673 0 annotate.go:242] goroutine 1: [E2018-05-03T07:11:30.644999-07:00 4673 0 annotate.go:242] #0 go.chromium.org/luci/vpython/venv/config.go:311 - venv.fillRuntime() [E2018-05-03T07:11:30.645037-07:00 4673 0 annotate.go:242] reason: failed to get runtime information [E2018-05-03T07:11:30.645065-07:00 4673 0 annotate.go:242] [E2018-05-03T07:11:30.645084-07:00 4673 0 annotate.go:242] #1 go.chromium.org/luci/vpython/venv/config.go:194 - venv.(*Config).makeEnv() [E2018-05-03T07:11:30.645102-07:00 4673 0 annotate.go:242] #2 go.chromium.org/luci/vpython/venv/venv.go:163 - venv.With() [E2018-05-03T07:11:30.645119-07:00 4673 0 annotate.go:242] #3 go.chromium.org/luci/vpython/run.go:63 - vpython.Run() [E2018-05-03T07:11:30.645136-07:00 4673 0 annotate.go:242] #4 go.chromium.org/luci/vpython/application/application.go:318 - application.(*application).mainImpl() [E2018-05-03T07:11:30.645178-07:00 4673 0 annotate.go:242] #5 go.chromium.org/luci/vpython/application/application.go:402 - application.(*Config).Main.func1() [E2018-05-03T07:11:30.645207-07:00 4673 0 annotate.go:242] #6 go.chromium.org/luci/vpython/application/support.go:47 - application.run() [E2018-05-03T07:11:30.645231-07:00 4673 0 annotate.go:242] #7 go.chromium.org/luci/vpython/application/application.go:401 - application.(*Config).Main() [E2018-05-03T07:11:30.645272-07:00 4673 0 annotate.go:242] #8 vpython/main.go:92 - main.mainImpl() [E2018-05-03T07:11:30.645291-07:00 4673 0 annotate.go:242] #9 vpython/main.go:98 - main.main() [E2018-05-03T07:11:30.645325-07:00 4673 0 annotate.go:242] #10 runtime/proc.go:195 - runtime.main() [E2018-05-03T07:11:30.645354-07:00 4673 0 annotate.go:242] #11 runtime/asm_amd64.s:2337 - runtime.goexit() [4399:779:0503/071130.647392:43346091853374:ERROR:local_test_server_posix.cc(169)] Could not read server_data_len ../../net/websockets/websocket_end_to_end_test.cc:396: Failure Value of: wss_server.Start() Actual: false Expected: true Stack trace: 0 net_unittests 0x0000000102fa336b testing::internal::UnitTestImpl::CurrentOsStackTraceExceptTop(int) + 91 1 net_unittests 0x0000000102fa2d29 testing::internal::AssertHelper::operator=(testing::Message const&) const + 89 2 net_unittests 0x0000000102df9477 net::(anonymous namespace)::WebSocketEndToEndTest_HstsHttpsToWebSocket_Test::TestBody() + 967 [ FAILED ] WebSocketEndToEndTest.HstsHttpsToWebSocket (379 ms) etc..
,
May 8 2018
These are the most interesting errors: [E2018-05-03T07:11:30.376412-07:00 4667 0 annotate.go:242] goroutine 1: [E2018-05-03T07:11:30.376501-07:00 4667 0 annotate.go:242] #0 go.chromium.org/luci/vpython/venv/venv.go:475 - venv.(*Env).createLocked() [E2018-05-03T07:11:30.376544-07:00 4667 0 annotate.go:242] reason: failed to remove existing root [E2018-05-03T07:11:30.376613-07:00 4667 0 annotate.go:242] [E2018-05-03T07:11:30.376643-07:00 4667 0 annotate.go:242] #1 go.chromium.org/luci/vpython/venv/venv.go:272 - venv.(*Env).ensure.func1() [E2018-05-03T07:11:30.376688-07:00 4667 0 annotate.go:242] reason: failed to create new VirtualEnv [E2018-05-03T07:11:30.376714-07:00 4667 0 annotate.go:242] Effectively, this means that the Python code will have no environment to run in, and will likely fail to run even the basic system stuff. This might happen if the directory it's trying to write doesn't have write permissions. Since this is invoked from C++, and I'm not familiar with how tests are structured, but I wonder if they have some sort of lockdown mechanism for the file system making it read-only.
,
May 9 2018
,
May 24 2018
Hm, this is very similar to issue 846378, where the same error happens during initial bot_update is ran.
,
May 24 2018
,
May 24 2018
I think same root cause as in issue 846378, will be fixed there. |
|||||||||
►
Sign in to add a comment |
|||||||||
Comment 1 by mmenke@chromium.org
, Apr 27 2018