Back to build
Raw log | Switch to full mode | Login

Test 'RestoreOnStartupTestChromeOS.LogInAndVerify' completed with the following status(es): 'FAILURE','SUCCESS' Test 'RestoreOnStartupTestChromeOS.LogInAndVerify' had the following logs when run: ================================================================================ [ RUN ] RestoreOnStartupTestChromeOS.LogInAndVerify [606:606:0525/165457.219267:24732790206:ERROR:local_test_server_posix.cc(142)] LaunchPython called with PYTHONPATH = /b/s/w/ir/third_party/tlslite:/b/s/w/ir/third_party/pywebsocket/src:/b/s/w/ir/out/Release/pyproto:/b/s/w/ir/net/tools/testserver:/b/s/w/ir/third_party/protobuf/python:/b/s/w/ir/out/Release/pyproto/components/policy/proto:/b/s/w/ir/out/Release/pyproto/chrome/browser/chromeos/policy/proto [606:606:0525/165457.219422:24732790344:ERROR:local_test_server_posix.cc(153)] Running: vpython -u /b/s/w/ir/chrome/browser/policy/test/policy_testserver.py --client-state=/b/s/w/itl_X2yX/.org.chromium.Chromium.zHdfVn/clients --config-file=/b/s/w/itl_X2yX/.org.chromium.Chromium.zHdfVn/policy --data-dir=/b/s/w/itl_X2yX/.org.chromium.Chromium.zHdfVn --host=127.0.0.1 --log-level=INFO --log-to-console --policy-key=/b/s/w/itl_X2yX/.org.chromium.Chromium.zHdfVn/signing_key --port=0 --startup-pipe=47 sending server_data: {"host": "127.0.0.1", "port": 46746} (36 bytes) [606:606:0525/165457.968404:24733539338:ERROR:local_test_server_posix.cc(142)] LaunchPython called with PYTHONPATH = /b/s/w/ir/third_party/tlslite:/b/s/w/ir/third_party/pywebsocket/src:/b/s/w/ir/out/Release/pyproto:/b/s/w/ir/net/tools/testserver [606:606:0525/165457.968514:24733539443:ERROR:local_test_server_posix.cc(153)] Running: vpython -u /b/s/w/ir/chrome/browser/chromeos/login/test/https_forwarder.py --data-dir=/b/s/w/ir --forward-target=http://127.0.0.1:40936/ --host=127.0.0.1 --https --log-to-console --ocsp=ok --ocsp-date=valid --ocsp-produced=valid --port=0 --ssl-host=accounts.google.com --https --startup-pipe=47 HTTPS server started on 127.0.0.1:41196... sending server_data: {"host": "127.0.0.1", "port": 41196} (36 bytes) [606:606:0525/165459.079557:ERROR:child_process_security_policy_impl.cc(1414)] Ignoring port number in isolated origin: https://accounts.google.com:41196 [1:1:0525/165459.488937:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [1:1:0525/165459.751132:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [606:606:0525/165500.005565:WARNING:CONSOLE(0)] "HTML Imports is deprecated and will be removed in M73, around March 2019. Please use ES modules instead. See https://www.chromestatus.com/features/5144752345317376 for more details.", source: (0) [606:606:0525/165500.356734:WARNING:CONSOLE(442)] "document.registerElement is deprecated and will be removed in M73, around March 2019. Please use window.customElements.define instead. See https://www.chromestatus.com/features/4642138092470272 for more details.", source: chrome://resources/polymer/v1_0/polymer/polymer-micro-extracted.js (442) [606:606:0525/165512.089484:WARNING:CONSOLE(2083)] "Element.createShadowRoot is deprecated and will be removed in M73, around March 2019. Please use Element.attachShadow instead. See https://www.chromestatus.com/features/4507242028072960 for more details.", source: chrome://resources/polymer/v1_0/polymer/polymer-mini-extracted.js (2083) [606:606:0525/165603.908854:WARNING:CONSOLE(2651)] "Could not find style data in module named", source: chrome://resources/polymer/v1_0/polymer/polymer-extracted.js (2651) [606:606:0525/165605.732640:WARNING:CONSOLE(2651)] "Could not find style data in module named", source: chrome://resources/polymer/v1_0/polymer/polymer-extracted.js (2651) [606:606:0525/165611.739019:WARNING:CONSOLE(2651)] "Could not find style data in module named", source: chrome://resources/polymer/v1_0/polymer/polymer-extracted.js (2651) ALSA lib confmisc.c:768:(parse_card) cannot find card '0' ALSA lib conf.c:4248:(_snd_config_evaluate) function snd_func_card_driver returned error: No such file or directory ALSA lib confmisc.c:392:(snd_func_concat) error evaluating strings ALSA lib conf.c:4248:(_snd_config_evaluate) function snd_func_concat returned error: No such file or directory ALSA lib confmisc.c:1251:(snd_func_refer) error evaluating name ALSA lib conf.c:4248:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory ALSA lib conf.c:4727:(snd_config_expand) Evaluate error: No such file or directory ALSA lib pcm.c:2239:(snd_pcm_open_noupdate) Unknown PCM default [606:681:0525/165623.969156:ERROR:alsa_util.cc(204)] PcmOpen: default,No such file or directory ALSA lib confmisc.c:768:(parse_card) cannot find card '0' ALSA lib conf.c:4248:(_snd_config_evaluate) function snd_func_card_driver returned error: No such file or directory ALSA lib confmisc.c:392:(snd_func_concat) error evaluating strings ALSA lib conf.c:4248:(_snd_config_evaluate) function snd_func_concat returned error: No such file or directory ALSA lib confmisc.c:1251:(snd_func_refer) error evaluating name ALSA lib conf.c:4248:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory ALSA lib conf.c:4727:(snd_config_expand) Evaluate error: No such file or directory ALSA lib pcm.c:2239:(snd_pcm_open_noupdate) Unknown PCM default [606:681:0525/165623.969890:ERROR:alsa_util.cc(204)] PcmOpen: plug:default,No such file or directory [606:606:0525/165628.787953:INFO:signin_screen_handler.cc(1284)] Login WebUI >> active: 1, source: account-picker [606:606:0525/165631.572744:ERROR:proximity_auth_local_state_pref_manager.cc(142)] Failed to find prefs for current user. [606:606:0525/165631.572845:ERROR:proximity_auth_local_state_pref_manager.cc(75)] Failed to get easyunlock_allowed. [606:606:0525/165631.572915:ERROR:proximity_auth_local_state_pref_manager.cc(142)] Failed to find prefs for current user. [606:606:0525/165631.572991:ERROR:proximity_auth_local_state_pref_manager.cc(142)] Failed to find prefs for current user. [606:606:0525/165631.573048:ERROR:proximity_auth_local_state_pref_manager.cc(87)] Failed to get easyunlock_enabled. [606:606:0525/165631.657483:WARNING:chrome_browsing_data_remover_delegate.cc(1032)] Failed to find user for current profile. [606:606:0525/165631.874125:INFO:signin_screen_handler.cc(1284)] Login WebUI >> active: 0, source: account-picker [606:606:0525/165633.964009:INFO:signin_screen_handler.cc(1284)] Login WebUI >> active: 1, source: gaia-signin [1:1:0525/165634.190025:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [606:784:0525/165634.252602:WARNING:fake_gaia.cc(288)] Serving request /embedded/setup/v2/chromeos 127.0.0.1 - - [25/May/2019 16:56:34] "GET /embedded/setup/v2/chromeos?chrometype=chromedevice&client_id=dummytoken&client_version=76.0.3806.0&platform_version=0.0.0.0&endpoint_gen=1.0&mi=ee%2C&is_first_user=true&hl=en-US HTTP/1.1" 200 - [1:1:0525/165634.435109:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [606:784:0525/165634.814180:ERROR:fake_gaia.cc(291)] Unhandled request /favicon.ico [606:784:0525/165634.814262:WARNING:embedded_test_server.cc(238)] Request not handled. Returning 404: /favicon.ico 127.0.0.1 - - [25/May/2019 16:56:34] "GET /favicon.ico HTTP/1.1" 404 - [606:606:0525/165634.862520:WARNING:CONSOLE(268)] "<webview>: The load has aborted with error -102: ERR_CONNECTION_REFUSED.", source: extensions::webViewEvents (268) [606:784:0525/165635.346706:WARNING:fake_gaia.cc(288)] Serving request /_/embedded/signin/challenge 127.0.0.1 - - [25/May/2019 16:56:35] "POST /_/embedded/signin/challenge HTTP/1.1" 200 - [606:784:0525/165635.348641:WARNING:fake_gaia.cc(288)] Serving request /_/embedded/lookup/accountlookup 127.0.0.1 - - [25/May/2019 16:56:35] "POST /_/embedded/lookup/accountlookup HTTP/1.1" 200 - [606:784:0525/165635.486029:WARNING:fake_gaia.cc(288)] Serving request /oauth2/v4/token 127.0.0.1 - - [25/May/2019 16:56:35] "POST /oauth2/v4/token HTTP/1.1" 200 - [606:606:0525/165635.493933:ERROR:gaia_auth_fetcher.cc(72)] Missing ID token on refresh token fetch response. [606:606:0525/165635.495390:ERROR:device_event_log_impl.cc(162)] [16:56:35.495] Login: cryptohome_util.cc:131 GetKeyDataEx failed with no GetKeyDataReply extension in reply. 127.0.0.1 - - [25/May/2019 16:56:35] "POST /device_management?request=policy&devicetype=2&apptype=Chrome&agent=Chromium+76.0.3806.0(96e3ba7eefba6434219255aa7539994d8a04308d-refs%2Fheads%2Fmaster%40%7B%23663419%7D)&platform=Linux%2CCrOS%2Cunknown%7Cx86_64%2Cunknown%7C14.4.0&deviceid=90011b6c-1dad-4f7d-a3ad-2b72fd1ad98f&retry=false HTTP/1.1" 410 - [606:606:0525/165635.546556:WARNING:device_management_service.cc(300)] DMServer sent an error response: 410 [606:606:0525/165635.560144:WARNING:merge_session_throttling_utils.cc(143)] Loading content for a profile without session restore? [606:606:0525/165635.615975:INFO:remote_commands_service.cc(38)] Fetching remote commands. [606:606:0525/165635.616233:WARNING:remote_commands_service.cc(40)] Client is not registered. [606:606:0525/165635.616365:INFO:remote_commands_invalidator.cc(32)] Initialize RemoteCommandsInvalidator. [606:606:0525/165635.616484:INFO:remote_commands_invalidator.cc(57)] Starting RemoteCommandsInvalidator. [606:606:0525/165635.616578:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData. [606:606:0525/165635.616677:INFO:remote_commands_invalidator.cc(167)] Unregister RemoteCommandsInvalidator. [606:606:0525/165635.617333:ERROR:app_search_result_ranker.cc(102)] AppSearchResultRanker::AppSearchResultRankerPredictorName MrfuAppLaunchPredictor [606:606:0525/165635.631949:WARNING:smb_service.cc(588)] SmbService: NetBios discovery disabled. [606:784:0525/165635.772766:WARNING:fake_gaia.cc(288)] Serving request /oauth2/v4/token 127.0.0.1 - - [25/May/2019 16:56:35] "POST /oauth2/v4/token HTTP/1.1" 200 - [606:784:0525/165635.774015:WARNING:fake_gaia.cc(288)] Serving request /oauth2/v4/token 127.0.0.1 - - [25/May/2019 16:56:35] "POST /oauth2/v4/token HTTP/1.1" 200 - [606:784:0525/165636.696390:WARNING:fake_gaia.cc(288)] Serving request /oauth2/v4/token 127.0.0.1 - - [25/May/2019 16:56:36] "POST /oauth2/v4/token HTTP/1.1" 200 - [606:784:0525/165636.698350:WARNING:fake_gaia.cc(288)] Serving request /oauth2/v4/token 127.0.0.1 - - [25/May/2019 16:56:36] "POST /oauth2/v4/token HTTP/1.1" 200 - [1:1:0525/165636.816039:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [606:606:0525/165636.940964:WARNING:chrome_browsing_data_remover_delegate.cc(1032)] Failed to find user for current profile. [606:671:0525/165636.957944:ERROR:checkin_request.cc(219)] Failed to get checkin response. Fetcher failed. Retrying. [1:1:0525/165636.959924:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [1:1:0525/165636.955160:WARNING:stack_trace_posix.cc(818)] WARNING: sanitizers are preventing signal handler installation. WebAssembly trap handlers are disabled. [606:785:0525/165636.980919:WARNING:leveldb_database.cc(106)] Unable to open /b/s/w/itl_X2yX/.org.chromium.Chromium.pt3npm/dmfaq7v/u-user@example.com-hash/shared_proto_db: Invalid argument: /b/s/w/itl_X2yX/.org.chromium.Chromium.pt3npm/dmfaq7v/u-user@example.com-hash/shared_proto_db: does not exist (create_if_missing is false) [689:702:0525/165637.027992:ERROR:ssl_client_socket_impl.cc(943)] handshake failed; returned -1, SSL error code 1, net_error -100 [606:821:0525/165637.037464:WARNING:syncer_proto_util.cc(359)] Error posting from syncer: Response Code (bogus on error): -1 Content-Length (bogus on error): -1 Server Status: CONNECTION_UNAVAILABLE [606:821:0525/165637.037630:ERROR:get_updates_processor.cc(246)] PostClientToServerMessage() failed during GetUpdates 127.0.0.1 - - [25/May/2019 16:56:37] "POST /device_management?request=register&devicetype=2&apptype=Chrome&agent=Chromium+76.0.3806.0(96e3ba7eefba6434219255aa7539994d8a04308d-refs%2Fheads%2Fmaster%40%7B%23663419%7D)&platform=Linux%2CCrOS%2Cunknown%7Cx86_64%2Cunknown%7C14.4.0&oauth_token=fake-all-scope-token&deviceid=90011b6c-1dad-4f7d-a3ad-2b72fd1ad98f&retry=false HTTP/1.1" 200 - [606:606:0525/165637.135148:WARNING:cloud_policy_client.cc(849)] Reregistration DMToken mismatch. [606:606:0525/165637.135254:ERROR:user_cloud_policy_manager_chromeos.cc(488)] Re-registration failed, requiring the user to perform an online sign-in. [685:685:0525/165637.493737:ERROR:shared_image_manager.cc(120)] SharedImageManager::ProduceGLTexture: Trying to produce a representation from a non-existent mailbox. [685:685:0525/165637.494047:ERROR:gles2_cmd_decoder.cc(18531)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name [685:685:0525/165637.494216:ERROR:gles2_cmd_decoder.cc(18552)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.494460:ERROR:gles2_cmd_decoder.cc(10742)] [.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering. [685:685:0525/165637.494652:ERROR:gles2_cmd_decoder.cc(18575)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.494791:ERROR:shared_image_manager.cc(120)] SharedImageManager::ProduceGLTexture: Trying to produce a representation from a non-existent mailbox. [685:685:0525/165637.494929:ERROR:gles2_cmd_decoder.cc(18531)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name [685:685:0525/165637.495072:ERROR:gles2_cmd_decoder.cc(18552)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.495267:ERROR:gles2_cmd_decoder.cc(10742)] [.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering. [685:685:0525/165637.495422:ERROR:gles2_cmd_decoder.cc(18575)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.495526:ERROR:shared_image_manager.cc(120)] SharedImageManager::ProduceGLTexture: Trying to produce a representation from a non-existent mailbox. [685:685:0525/165637.495643:ERROR:gles2_cmd_decoder.cc(18531)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name [685:685:0525/165637.495751:ERROR:gles2_cmd_decoder.cc(18552)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.495902:ERROR:gles2_cmd_decoder.cc(10742)] [.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering. [685:685:0525/165637.496025:ERROR:gles2_cmd_decoder.cc(18575)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.496120:ERROR:shared_image_manager.cc(120)] SharedImageManager::ProduceGLTexture: Trying to produce a representation from a non-existent mailbox. [685:685:0525/165637.496246:ERROR:gles2_cmd_decoder.cc(18531)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name [685:685:0525/165637.496384:ERROR:gles2_cmd_decoder.cc(18552)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.496534:ERROR:gles2_cmd_decoder.cc(10742)] [.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering. [685:685:0525/165637.496659:ERROR:gles2_cmd_decoder.cc(18575)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.496777:ERROR:shared_image_manager.cc(120)] SharedImageManager::ProduceGLTexture: Trying to produce a representation from a non-existent mailbox. [685:685:0525/165637.496901:ERROR:gles2_cmd_decoder.cc(18531)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name [685:685:0525/165637.497011:ERROR:gles2_cmd_decoder.cc(18552)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.497178:ERROR:gles2_cmd_decoder.cc(10742)] [.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering. [685:685:0525/165637.497323:ERROR:gles2_cmd_decoder.cc(18575)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.497421:ERROR:shared_image_manager.cc(120)] SharedImageManager::ProduceGLTexture: Trying to produce a representation from a non-existent mailbox. [685:685:0525/165637.497533:ERROR:gles2_cmd_decoder.cc(18531)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoCreateAndTexStorage2DSharedImageINTERNAL: invalid mailbox name [685:685:0525/165637.497637:ERROR:gles2_cmd_decoder.cc(18552)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoBeginSharedImageAccessCHROMIUM: bound texture is not a shared image [685:685:0525/165637.497796:ERROR:gles2_cmd_decoder.cc(10742)] [.DisplayCompositor]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering. [685:685:0525/165637.497918:ERROR:gles2_cmd_decoder.cc(18575)] [.DisplayCompositor]GL ERROR :GL_INVALID_OPERATION : DoEndSharedImageAccessCHROMIUM: bound texture is not a shared image [606:606:0525/165637.584463:INFO:remote_commands_invalidator.cc(45)] Shutdown RemoteCommandsInvalidator. [606:606:0525/165637.584604:INFO:remote_commands_invalidator.cc(68)] Stopping RemoteCommandsInvalidator. [606:606:0525/165637.584661:INFO:remote_commands_invalidator.cc(167)] Unregister RemoteCommandsInvalidator. [606:671:0525/165637.734946:ERROR:browser_process_sub_thread.cc(221)] Waited 52 ms for network service [606:606:0525/165637.802299:WARNING:pref_notifier_impl.cc(36)] Pref observer for media_router.cast_allow_all_ips found at shutdown. [606:606:0525/165637.802432:WARNING:pref_notifier_impl.cc(36)] Pref observer for browser.relaunch_notification_period found at shutdown. [ OK ] RestoreOnStartupTestChromeOS.LogInAndVerify (100639 ms) ================================================================================