New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 836036 link

Starred by 5 users

Issue metadata

Status: Duplicate
Owner: ----
Closed: May 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 3
Type: Bug



Sign in to add a comment

net_unittests occasionally fails to start LocalTestServer on Mac10.10 Tests bot

Project Member Reported by thestig@chromium.org, Apr 23 2018

Issue description

https://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
 

Comment 1 by mmenke@chromium.org, Apr 27 2018

Cc: crouleau@chromium.org
[+crouleau]:  Possibly the same as  issue 822256 , which you marked as fixed?
Cc: -crouleau@chromium.org
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.
Cc: iannucci@chromium.org
[+iannucci]:  Maybe related to the vpython switch /  issue 822256  and issue 804174?  Test seems to be hanging while starting the python test server.
Labels: NetworkTriaged
Cc: jbudorick@chromium.org
 Issue 839422  has been merged into this issue.

Comment 7 by mattm@chromium.org, May 3 2018

Components: Infra>Client>Chrome
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..
Cc: sergeybe...@chromium.org
Status: Available (was: Untriaged)
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.
Labels: -NetworkTriaged Network-Triaged
Hm, this is very similar to issue 846378, where the same error happens during initial bot_update is ran.
Status: De (was: Available)
Mergedinto: 846378
Status: Duplicate (was: De)
I think same root cause as in issue 846378, will be fixed there.

Sign in to add a comment