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

Issue 822614 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Apr 2018
Cc:
Components:
EstimatedDays: ----
NextAction: 2018-04-12
OS: ----
Pri: 1
Type: Bug-Regression



Sign in to add a comment

ProxyBrowserTest.BasicAuthWSConnect failing on Asan and Window Dbg bots.

Project Member Reported by sheriff-...@appspot.gserviceaccount.com, Mar 16 2018

Issue description

Filed by sheriff-o-matic@appspot.gserviceaccount.com on behalf of yukishiino@chromium.org

browser_tests failing on chromium.win/Win7 Tests (dbg)(1)

Builders failed on: 
- Win7 Tests (dbg)(1): 
  https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29

ProxyBrowserTest.BasicAuthWSConnect in browser_tests seems flaky and it quite often fails.
https://uberchromegw.corp.google.com/i/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29?numbuilds=200
 
Owner: mmenke@chromium.org
Status: Assigned (was: Available)
Matt, could you triage this issue as an owner?
 Issue 822613  has been merged into this issue.

Comment 3 by mmenke@chromium.org, Mar 19 2018

Cc: ricea@chromium.org
Components: Blink>Network>WebSockets
May have something to do with proxy servicification, something to do with auth servicification, something to do with switching to vpython (Which the SpawnedTestServer uses, see issue 804174).  Or it could actually be a websockets issue.  I have no idea what's going on with that side of things.
Cc: -yukishiino@chromium.org
One of the failure logs 

[ RUN      ] ProxyBrowserTest.BasicAuthWSConnect
[6100:6660:0319/092326.081:WARNING:discovery_network_list_win.cc(195)] Failed to open Wlan client handle: 1062
[6100:4192:0319/092326.315:WARNING:chrome_browser_main_win.cc(630)] Command line too long for RegisterApplicationRestart:  --brave-new-test-launcher --cfi-diag=0 --gtest_also_run_disabled_tests --gtest_filter=ProxyBrowserTest.BasicAuthWSConnect --single_process --test-launcher-bot-mode --test-launcher-output="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir1832_8809\results1832_4332\test_results.xml" --test-launcher-summary-output="e:\b\s\w\io4xqqcu\output.json" --user-data-dir="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir1832_8809\d1832_2471" --disable-offline-auto-reload --proxy-server=127.0.0.1:54378 --no-first-run --no-default-browser-check --enable-logging=stderr --disable-default-apps --wm-window-animations-disabled --disable-component-update --test-type=browser --force-color-profile=srgb --disable-zero-browsers-open-for-tests --ipc-connection-timeout=45 --allow-file-access-from-files --dom-automation --log-gpu-control-list-decisions --disable-backgrounding-occluded-windows --disable-gl-drawing-for-tests --override-use-software-gl-for-tests --force-color-profile=srgb --disable-compositor-ukm-for-tests --enable-features=TestFeatureForBrowserTest1 --disable-features=NetworkPrediction,TestFeatureForBrowserTest2 --flag-switches-begin --flag-switches-end --restore-last-session about:blank
[4856:7080:0319/092326.845:INFO:media_foundation_video_encode_accelerator_win.cc(370)] Windows versions earlier than 8 are not supported.
[6100:2532:0319/092327.048:WARNING:http_network_transaction.cc(319)] Blocked proxy response with status 407 to CONNECT request for www.gstatic.com:443.
[3416:5736:0319/092331.622:ERROR:render_process_impl.cc(200)] WebFrame LEAKED 1 TIMES
[6100:4736:0319/092331.652:ERROR:process_win.cc(151)] Unable to terminate process: Access is denied. (0x5)
[6100:4192:0319/092401.603:INFO:CONSOLE(10)] "WebSocket connection to 'ws://127.0.0.1:54380/echo-request-headers' failed: Error in connection establishment: net::ERR_CONNECTION_TIMED_OUT", source: http://127.0.0.1:54380/proxied_request_check.html (10)
../../chrome/browser/net/proxy_browsertest.cc(149): error: Value of: base::EqualsASCII(result, "PASS")
  Actual: false
Expected: true
VM1463-M4.golo.chromium.org - code 404, message File not found
Exception in processing request from: ('127.0.0.1', 54396)
Traceback (most recent call last):
  File "e:\b\s\w\ir\.swarming_module\bin\Lib\SocketServer.py", line 596, in process_request_thread
    self.finish_request(request, client_address)
  File "e:\b\s\w\ir\.swarming_module\bin\Lib\SocketServer.py", line 331, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "e:\b\s\w\ir\third_party\pywebsocket\src\mod_pywebsocket\standalone.py", line 695, in __init__
    self, request, client_address, server)
  File "e:\b\s\w\ir\.swarming_module\bin\Lib\SocketServer.py", line 654, in __init__
    self.finish()
  File "e:\b\s\w\ir\.swarming_module\bin\Lib\SocketServer.py", line 713, in finish
    self.wfile.close()
  File "e:\b\s\w\ir\.swarming_module\bin\Lib\socket.py", line 283, in close
    self.flush()
  File "e:\b\s\w\ir\.swarming_module\bin\Lib\socket.py", line 307, in flush
    self._sock.sendall(view[write_offset:write_offset+buffer_size])
error: [Errno 10053] An established connection was aborted by the software in your host machine
[6100:2532:0319/092402.040:WARNING:discardable_shared_memory_manager.cc(436)] Some MojoDiscardableSharedMemoryManagerImpls are still alive. They will be leaked.
[6100:4192:0319/092402.040:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread.
[6100:4192:0319/092402.072:ERROR:activity_tracker.cc(1485)] Recording exit of unknown process #5400
[  FAILED  ] ProxyBrowserTest.BasicAuthWSConnect, where TypeParam =  and GetParam() =  (37502 ms)

Will proceed to disable the test on Windows Debug and ASAN bots.
Summary: ProxyBrowserTest.BasicAuthWSConnect failing on Asan and Window Dbg bots. (was: browser_tests failing on chromium.win/Win7 Tests (dbg)(1))
Project Member

Comment 9 by bugdroid1@chromium.org, Mar 19 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/20db52670d7515ae141cac7f2fef90894a29a910

commit 20db52670d7515ae141cac7f2fef90894a29a910
Author: Karan Bhatia <karandeepb@chromium.org>
Date: Mon Mar 19 19:36:42 2018

Disable flaky ProxyBrowserTest.BasicAuthWSConnect on Windows Dbg and ASAN bots.

BUG= 822614 
TBR=mmenke@chromium.org

Change-Id: I360c120ea72fd7ec215ec3d2e16214a1b77835e0
Reviewed-on: https://chromium-review.googlesource.com/969331
Reviewed-by: Karan Bhatia <karandeepb@chromium.org>
Commit-Queue: Karan Bhatia <karandeepb@chromium.org>
Cr-Commit-Position: refs/heads/master@{#544123}
[modify] https://crrev.com/20db52670d7515ae141cac7f2fef90894a29a910/chrome/browser/net/proxy_browsertest.cc

Labels: -Sheriff-Chromium
Labels: Test-Disabled

Comment 12 by ricea@chromium.org, Mar 20 2018

#6 Thanks for the log.

This is probably https://cs.chromium.org/chromium/src/net/http/http_proxy_client_socket_wrapper.cc?q=ERR_CONNECTION_TIMED_OUT

although

https://cs.chromium.org/chromium/src/net/socket/tcp_socket_win.cc?q=ERR_CONNECTION_TIMED_OUT

is also possible.

While it looks like this is failing on slower bots, the timeouts in question are so long that it's hard to see it making much difference. The timeout for the proxy is normally >= 30 seconds.

There's a NetAdaptiveProxyConnectionTimeout field trial which can make the timeout be shorter, but AFAIK the bot shouldn't be in the field trial?

Comment 13 by ricea@chromium.org, Mar 20 2018

I couldn't reproduce it with a local ASAN build, with 1000 iterations. This may mean that it's a bot environment peculiarity, or it only happens in memory-constrained environments.
Cc: mmenke@chromium.org
Owner: ----
Status: Untriaged (was: Assigned)
Punting ownership of this - I just don't have time to dig into it.

Comment 15 by ricea@chromium.org, Mar 22 2018

Labels: -Pri-2 Pri-3 Type-Bug-Regression
Status: Available (was: Untriaged)
It would be nice to fix this, but since it doesn't reproduce locally it is challenging to do so. Since we have a workaround it is low-priority and will go on the backlog.

Comment 16 by zmin@chromium.org, Apr 4 2018

 Issue 828927  has been merged into this issue.
Project Member

Comment 17 by bugdroid1@chromium.org, Apr 4 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/15aa582408ae06377871b74f665c305b938d9a3a

commit 15aa582408ae06377871b74f665c305b938d9a3a
Author: Owen Min <zmin@chromium.org>
Date: Wed Apr 04 20:38:56 2018

Disable ProxyBrowserTest.BasicAuthWSConnect on more platforms.

Disable the test on Windows and Mac

Tbr: mmenke@chromium.org
Bug:  822614 ,  828927 
Change-Id: Ia9437af60a80ab7468e20dc81e495aa10a893428
Reviewed-on: https://chromium-review.googlesource.com/996405
Reviewed-by: Owen Min <zmin@chromium.org>
Commit-Queue: Owen Min <zmin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#548183}
[modify] https://crrev.com/15aa582408ae06377871b74f665c305b938d9a3a/chrome/browser/net/proxy_browsertest.cc

Hi, another sheriff here. This repros easily for me on a local Linux build. Anything I can look at to help?
Cc: droger@chromium.org
Labels: -Pri-3 Pri-1
OK, I did a local bisect.

The consistent repro I'm seeing is resolved by reverting https://chromium.googlesource.com/chromium/src/+/51f305bf770e7a958a02b46d16357e497307e81f which implies this could be bad interaction with DICE.

Can someone please look at this?
Components: Services>SignIn
#19 Thanks. I don't know what DICE is, although it's apparent it changes auth somehow.

Adding component to Services>SignIn in the hope that it will be apparent to them what the bad interaction with this test is.
Cc: roc...@chromium.org
Dice has nothing to do with net, proxies or websocket.
It's a signin feature, which is about how user sign into Chrome to enable Sync.

The failing test does not use any code related to signin or Dice, I would be really surprised if this were the cause.

Thanks. I don't get it, but the hang is 100% reproducible for me locally,
and reverting that change alone makes the hang go away. Maybe some indirect
interaction + bad test expectations?
I got a timeout when I built at 51f305bf770e7a958a02b46d16357e497307e81f.

The output  contains some mysterious log entries of "CONNECT www.gstatic.com:443 HTTP/1.1" and "CONNECT accounts.google.com:443 HTTP/1.1". Something is doing unrelated requests during the test.

[ RUN      ] ProxyBrowserTest.DISABLED_BasicAuthWSConnect
BasicAuthProxy server started on port 37897...
sending server_data: {"host": "127.0.0.1", "port": 37897} (36 bytes)

(browser_tests:2349): Gtk-WARNING **: Theme parsing error: gtk.css:68:35: The style property GtkButton:child-displacement-x is deprecated and shouldn't be used anymore. It will be removed in a future version

(browser_tests:2349): Gtk-WARNING **: Theme parsing error: gtk.css:69:35: The style property GtkButton:child-displacement-y is deprecated and shouldn't be used anymore. It will be removed in a future version

(browser_tests:2349): Gtk-WARNING **: Theme parsing error: gtk.css:73:46: The style property GtkScrolledWindow:scrollbars-within-bevel is deprecated and shouldn't be used anymore. It will be removed in a future version
[2349:2349:0405/232138.082536:WARNING:password_store_factory.cc(240)] Using basic (unencrypted) store for password storage. See https://chromium.googlesource.com/chromium/src/+/master/docs/linux_password_storage.md for more information about password storage options.
127.0.0.1 - - [05/Apr/2018 23:21:38] "CONNECT www.gstatic.com:443 HTTP/1.1" 407 -
[2349:2399:0405/232138.282417:WARNING:http_network_transaction.cc(341)] Blocked proxy response with status 407 to CONNECT request for www.gstatic.com:443.
127.0.0.1 - - [05/Apr/2018 23:21:38] "CONNECT accounts.google.com:443 HTTP/1.1" 407 -
[2349:2399:0405/232138.293603:WARNING:http_network_transaction.cc(341)] Blocked proxy response with status 407 to CONNECT request for accounts.google.com:443.
。Trying to start websocket server on ws://127.0.0.1:0...
WebSocket server started on ws://127.0.0.1:35689...
sending server_data: {"host": "127.0.0.1", "port": 35689} (36 bytes)
127.0.0.1 - - [05/Apr/2018 23:21:39] "GET http://127.0.0.1:35689/proxied_request_check.html HTTP/1.1" 407 -
127.0.0.1 - - [05/Apr/2018 23:21:39] "CONNECT accounts.google.com:443 HTTP/1.1" 407 -
127.0.0.1 - - [05/Apr/2018 23:21:39] "CONNECT accounts.google.com:443 HTTP/1.1" 200 -
Still waiting for the following processes to finish:
        ./browser_tests --gtest_also_run_disabled_tests --gtest_filter=ProxyBrowserTest.DISABLED_BasicAuthWSConnect --single_process --test-launcher-output=/tmp/.org.chromium.Chromium.8Rt8fH/results4WcDoe/test_results.xml --user-data-dir=/tmp/.org.chromium.Chromium.8Rt8fH/dR9MmPX
Still waiting for the following processes to finish:
        ./browser_tests --gtest_also_run_disabled_tests --gtest_filter=ProxyBrowserTest.DISABLED_BasicAuthWSConnect --single_process --test-launcher-output=/tmp/.org.chromium.Chromium.8Rt8fH/results4WcDoe/test_results.xml --user-data-dir=/tmp/.org.chromium.Chromium.8Rt8fH/dR9MmPX
[2349:2349:0405/232209.406731:INFO:CONSOLE(10)] "WebSocket connection to 'ws://127.0.0.1:35689/echo-request-headers' failed: Error in connection establishment: net::ERR_CONNECTION_TIMED_OUT", source: http://127.0.0.1:35689/proxied_request_check.html (10)
../../chrome/browser/net/proxy_browsertest.cc:151: Failure
Value of: base::EqualsASCII(result, "PASS")
  Actual: false
Expected: true
[2422:2422:0405/232209.491400:WARNING:x11_util.cc(1362)] X error received: serial 187, error_code 3 (BadWindow), request_code 4, minor_code 0 (Unknown)
127.0.0.1 - - [05/Apr/2018 23:22:09] "CONNECT 127.0.0.1:35689 HTTP/1.1" 500 -
testserver.py: Broken pipe
127.0.0.1 - - [05/Apr/2018 23:22:09] "GET http://127.0.0.1:35689/favicon.ico HTTP/1.1" 500 -
testserver.py: Broken pipe
[2349:2349:0405/232209.538670:WARNING:pref_notifier_impl.cc(23)] Pref observer found at shutdown.
[  FAILED  ] ProxyBrowserTest.DISABLED_BasicAuthWSConnect, where TypeParam =  and GetParam() =  (32713 ms)

After digging through a lot of Python code, it appears that the BasicAuthProxyRequestHandler implemented in https://cs.chromium.org/chromium/src/net/tools/testserver/testserver.py only supports one connection at a time. As a consequence, if some other request hogs the proxy, the test will fail.

If there's really no way to stop other bits of Chrome from issuing requests during execution of the browser tests then I will have to try to make that proxy server multi-threaded.
Could also add websockets support to the EmbeddedTestServer instead - that server tends to be more robust (Launched locally on all platforms, no dependency on python, which is slow to load...Supports multiple connections at once, can talk to it at runtime), but that may be more work, not sure.
#25 Supporting websockets in EmbeddedTestServer is definitely on my wishlist, but our problem here is with the --basic-auth-proxy mode of testserver.py.
I assume making the TestServer multi-threaded is somewhat difficult - at least I hope there's a good reason this behavior has resulted in test breakages for the last decade.
#27 In the general case it's a fair amount of work to make testserver.py multi-threaded because all the handlers need to be reviewed and made threadsafe.

In the specific case of the basic auth proxy, it's almost trivial. I've made a CL.

I'm concerned about masking the real cause of the flakiness, which is other bits of the browser randomly firing off requests while my browser test is executing. I don't know how to make a test robust when arbitrary other things are going on out of my control.
Cc: smcgruer@chromium.org
ricea - this is continuing to flake on Linux (both browser_tests and viz_browser_tests). Do you expect the CL mentioned in #29 to fix this flake (and if so, will it land soon?)
https://chromium-review.googlesource.com/c/chromium/src/+/999276 will make the tests stop flaking, yes.
Project Member

Comment 32 by bugdroid1@chromium.org, Apr 6 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/4258b73b0bea431994d884d0751546b647f290c6

commit 4258b73b0bea431994d884d0751546b647f290c6
Author: Adam Rice <ricea@chromium.org>
Date: Fri Apr 06 16:48:30 2018

Enable simultaneous requests in testserver.py proxy

testserver.py only supports one simultaneous request in basic auth proxy
mode. This can lead to test timeouts when an unrelated request hogs the
connection. Use the SelectServer.ThreadingMixIn to switch to
thread-per-connection semantics, allowing the server to support any
number of requests up to the limit of filehandles or memory.

This CL only fixes the basic auth proxy mode. The http and https modes
have the same flaw, but are harder to fix because all the handlers have
to be made threadsafe. However, requests in the http and https modes are
expected to be short-lived and there are no known problems caused by the
deficiency.

BUG= 822614 

Change-Id: Ieb2e91613f15e51a11af93c8da7d639da298b9a6
Reviewed-on: https://chromium-review.googlesource.com/999276
Reviewed-by: Ian Clelland <iclelland@chromium.org>
Reviewed-by: Matt Menke <mmenke@chromium.org>
Commit-Queue: Adam Rice <ricea@chromium.org>
Cr-Commit-Position: refs/heads/master@{#548814}
[modify] https://crrev.com/4258b73b0bea431994d884d0751546b647f290c6/net/tools/testserver/testserver.py

No flakes since the above CL landed. I will give it another 24 hours just to be on the safe side and then land https://chromium-review.googlesource.com/c/chromium/src/+/999374 to re-enable the other platforms.

Comment 34 by ricea@chromium.org, Apr 10 2018

Owner: ricea@chromium.org
Status: Started (was: Available)
Still looks good.
Cc: -smcgruer@chromium.org
Project Member

Comment 36 by bugdroid1@chromium.org, Apr 10 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/2f3efd6162379623a58199665374e46bd7b0843c

commit 2f3efd6162379623a58199665374e46bd7b0843c
Author: Adam Rice <ricea@chromium.org>
Date: Tue Apr 10 13:10:00 2018

Re-enable ProxyBrowserTest.BasicAuthWSConnect

The browser test ProxyBrowserTest.BasicAuthWSConnect was flaky because
the testserver.py proxy it configured could only handle one request at a
time, and other parts of the browser randomly launched unrelated
requests while the test was running, occasionally taking the proxy's one
request until the test timed out.

testserver.py's basic auth proxy mode has been modified to support
multiple simultaneous requests, so the
ProxyBrowserTest.BasicAuthWSConnect test should no longer be
flaky. Re-enable it.

BUG= 822614 

Change-Id: Id390f01807b532316e3aa2d4de199e8082ae0bf0
Reviewed-on: https://chromium-review.googlesource.com/999374
Reviewed-by: Matt Menke <mmenke@chromium.org>
Commit-Queue: Adam Rice <ricea@chromium.org>
Cr-Commit-Position: refs/heads/master@{#549497}
[modify] https://crrev.com/2f3efd6162379623a58199665374e46bd7b0843c/chrome/browser/net/proxy_browsertest.cc

Comment 37 by ricea@chromium.org, Apr 10 2018

NextAction: 2018-04-12

Comment 38 by ricea@chromium.org, Apr 12 2018

Status: Fixed (was: Started)
No new failures.
The NextAction date has arrived: 2018-04-12

Sign in to add a comment