Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=162348582&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/e5O-cR2FSgWGPOaUPruv-A/runs/0/artifacts/public/logs/live_backing.log 06:34:22 INFO - TEST-START | browser\components\migration\tests\marionette\test_refresh_firefox.py TestFirefoxRefresh.testReset 06:34:22 INFO - 1518676462530 Marionette DEBUG Accepted connection 5 from 127.0.0.1:52045 06:34:22 INFO - 1518676462530 Marionette TRACE 5 -> [0,1,"newSession",{}] 06:34:22 INFO - 1518676462532 Marionette DEBUG Register listener.js for window 4294967297 06:34:22 INFO - 1518676462534 Marionette TRACE 5 <- [1,1,null,{"sessionId":"4384712c-be6d-4875-93a7-f2af3c6868be","capabilities":{"browserName":"firefox","browserVersion":"60.0a ... cWorker\\AppData\\Local\\Temp\\tmpmy2yxv.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 06:34:22 INFO - 1518676462534 Marionette TRACE 5 -> [0,2,"setTimeouts",{"script":30000}] 06:34:22 INFO - 1518676462534 Marionette TRACE 5 <- [1,2,null,{}] 06:34:22 INFO - 1518676462536 Marionette TRACE 5 -> [0,3,"setTimeouts",{"pageLoad":300000}] 06:34:22 INFO - 1518676462536 Marionette TRACE 5 <- [1,3,null,{}] 06:34:22 INFO - 1518676462536 Marionette TRACE 5 -> [0,4,"setTimeouts",{"implicit":0}] 06:34:22 INFO - 1518676462538 Marionette TRACE 5 <- [1,4,null,{}] 06:34:22 INFO - 1518676462538 Marionette TRACE 5 -> [0,5,"setContext",{"value":"chrome"}] 06:34:22 INFO - 1518676462538 Marionette TRACE 5 <- [1,5,null,{}] 06:34:22 INFO - 1518676462540 Marionette TRACE 5 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":false,"args":[],"filename":"test_refresh_firefox.py","script":"\n ... = Cu.import(\"resource://gre/modules/FormHistory.jsm\", {}).FormHistory;\n ","sandbox":"firefox-refresh","line":439}] 06:34:22 INFO - 1518676462544 Marionette TRACE 5 <- [1,6,null,{"value":null}] 06:34:22 INFO - 1518676462544 Marionette TRACE 5 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":false,"args":[],"filename":"test_refresh_firefox.py","script":"\n ... atch(e) {\n return false;\n }\n return true;\n ","sandbox":"firefox-refresh","line":439}] 06:34:22 INFO - 1518676462550 Marionette TRACE 5 <- [1,7,null,{"value":true}] 06:34:22 INFO - 1518676462550 Marionette TRACE 5 -> [0,8,"executeScript",{"scriptTimeout":null,"newSandbox":false,"args":["marionette-test-login","marionette-test-password"],"fi ... \"password\"\n );\n Services.logins.addLogin(myLogin)\n ","sandbox":"firefox-refresh","line":439}] 06:34:22 INFO - 1518676462572 Marionette TRACE 5 <- [1,8,null,{"value":null}] 06:34:22 INFO - 1518676462574 Marionette TRACE 5 -> [0,9,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n let ur ... "newSandbox":false,"line":446,"args":["about:mozilla","Some bookmark from Marionette"],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462582 Marionette TRACE 5 <- [1,9,null,{"value":false}] 06:34:22 INFO - 1518676462582 Marionette TRACE 5 -> [0,10,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n let c ... (false), marionetteScriptFinished);\n ","newSandbox":false,"line":446,"args":[],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462614 Marionette TRACE 5 <- [1,10,null,{"value":false}] 06:34:22 INFO - 1518676462616 Marionette TRACE 5 -> [0,11,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n Place ... ["http://firefox-refresh.marionette-test.mozilla.org/","Test visit for Firefox Reset"],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462622 Marionette TRACE 5 <- [1,11,null,{"value":false}] 06:34:22 INFO - 1518676462622 Marionette TRACE 5 -> [0,12,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n let u ... args":["some-very-unique-marionette-only-firefox-reset-field","special-pumpkin-value"],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462656 Marionette TRACE 5 <- [1,12,null,{"value":false}] 06:34:22 INFO - 1518676462656 Marionette TRACE 5 -> [0,13,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n const ... }).then(marionetteScriptFinished);\n ","newSandbox":false,"line":446,"args":[],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462672 Marionette TRACE 5 <- [1,13,null,{"value":"2c866e9f544d"}] 06:34:22 INFO - 1518676462672 Marionette TRACE 5 -> [0,14,"executeScript",{"scriptTimeout":null,"newSandbox":false,"args":["firefox-refresh.marionette-test.mozilla.org","some/co ... ents[3],\n true, false, false, expireTime);\n ","sandbox":"firefox-refresh","line":439}] 06:34:22 INFO - 1518676462674 Marionette TRACE 5 <- [1,14,null,{"value":null}] 06:34:22 INFO - 1518676462676 Marionette TRACE 5 -> [0,15,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n const ... }\n ","newSandbox":false,"line":446,"args":[["about:robots","about:mozilla"]],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462698 Marionette DEBUG Register listener.js for window 16 06:34:22 INFO - 1518676462726 Marionette DEBUG Register listener.js for window 18 06:34:22 INFO - 1518676462798 Marionette TRACE 5 <- [1,15,null,{"value":null}] 06:34:22 INFO - [Parent 6004, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:22 INFO - [Child 4564, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:22 INFO - [Child 4564, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:22 INFO - 1518676462874 Marionette DEBUG Register listener.js for window 2147483652 06:34:22 INFO - 1518676462880 Marionette TRACE 5 -> [0,16,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n Cu.im ... e().then(marionetteScriptFinished);\n ","newSandbox":false,"line":446,"args":[],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462916 Marionette TRACE 5 <- [1,16,null,{"value":null}] 06:34:22 INFO - 1518676462922 Marionette TRACE 5 -> [0,17,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_refresh_firefox.py","script":"\n ... );\n return ary.length ? ary : {username: \"null\", password: \"null\"};\n ","sandbox":"default","line":196}] 06:34:22 INFO - 1518676462926 Marionette TRACE 5 <- [1,17,null,{"value":[{"init":{},"QueryInterface":{},"guid":"{ecd22616-55a8-4bb3-87a5-312a8b9ce9f0}","timeCreated":15186764625 ... om/some/form/","httpRealm":null,"usernameField":"username","passwordField":"password","equals":{},"matches":{},"clone":{}}]}] 06:34:22 INFO - 1518676462926 Marionette TRACE 5 -> [0,18,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_refresh_firefox.py","script":"\n return Services.logins.getAllLogins().length;\n ","sandbox":"default","line":203}] 06:34:22 INFO - 1518676462932 Marionette TRACE 5 <- [1,18,null,{"value":2}] 06:34:22 INFO - 1518676462936 Marionette TRACE 5 -> [0,19,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n let u ... ed(ex)\n );\n ","newSandbox":false,"line":446,"args":["about:mozilla"],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462940 Marionette TRACE 5 <- [1,19,null,{"value":"Some bookmark from Marionette"}] 06:34:22 INFO - 1518676462940 Marionette TRACE 5 -> [0,20,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n Place ... ndbox":false,"line":446,"args":["http://firefox-refresh.marionette-test.mozilla.org/"],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462942 Marionette TRACE 5 <- [1,20,null,{"value":{"guid":"MEvCotHr9EQD","url":"http://firefox-refresh.marionette-test.mozilla.org/","frecency":100,"title":"Test visit for Firefox Reset"}}] 06:34:22 INFO - 1518676462944 Marionette TRACE 5 -> [0,21,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n let r ... dbox":false,"line":446,"args":["some-very-unique-marionette-only-firefox-reset-field"],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462946 Marionette TRACE 5 <- [1,21,null,{"value":[{"value":"special-pumpkin-value"}]}] 06:34:22 INFO - 1518676462946 Marionette TRACE 5 -> [0,22,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n let c ... l.FormHistory.count({}, callbacks);\n ","newSandbox":false,"line":446,"args":[],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462948 Marionette TRACE 5 <- [1,22,null,{"value":1}] 06:34:22 INFO - 1518676462950 Marionette TRACE 5 -> [0,23,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n retur ... }).then(marionetteScriptFinished);\n ","newSandbox":false,"line":446,"args":[],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462952 Marionette TRACE 5 <- [1,23,null,{"value":[{"given-name":"John","additional-name":"R.","family-name":"Smith","organization":"World Wide Web Consort ... tel-national":"5195555555","tel-area-code":"519","tel-local":"5555555","tel-local-prefix":"555","tel-local-suffix":"5555"}]}] 06:34:22 INFO - 1518676462954 Marionette TRACE 5 -> [0,24,"executeScript",{"scriptTimeout":null,"newSandbox":false,"args":["firefox-refresh.marionette-test.mozilla.org"],"filena ... return \"got exception trying to fetch cookie: \" + ex;\n }\n ","sandbox":"firefox-refresh","line":439}] 06:34:22 INFO - 1518676462956 Marionette TRACE 5 <- [1,24,null,{"value":{"path":"some/cookie/path","name":"somecookie","value":"some cookie value"}}] 06:34:22 INFO - 1518676462958 Marionette TRACE 5 -> [0,25,"executeAsyncScript",{"scriptTimeout":null,"sandbox":"firefox-refresh","debug_script":false,"script":"\n Cu.im ... hed(err.toString());\n });\n ","newSandbox":false,"line":446,"args":[],"filename":"test_refresh_firefox.py"}] 06:34:22 INFO - 1518676462962 Marionette TRACE 5 <- [1,25,null,{"value":{"accountData":{"email":"test@test.com","uid":"uid","keyFetchToken":"top-secret"},"prefUsername":null}}] 06:34:22 INFO - 1518676462964 Marionette TRACE 5 -> [0,26,"executeScript",{"scriptTimeout":null,"newSandbox":false,"args":["c:\\users\\genericworker\\appdata\\local\\temp\\tmpmy ... \", arguments[0]);\n env.set(\"XRE_PROFILE_NAME\", profileName);\n ","sandbox":"firefox-refresh","line":439}] 06:34:22 INFO - 1518676462966 Marionette TRACE 5 <- [1,26,null,{"value":null}] 06:34:22 INFO - 1518676462966 Marionette TRACE 5 -> [0,27,"getContext",{}] 06:34:22 INFO - 1518676462968 Marionette TRACE 5 <- [1,27,null,{"value":"chrome"}] 06:34:22 INFO - 1518676462968 Marionette TRACE 5 -> [0,28,"getContext",{}] 06:34:22 INFO - 1518676462968 Marionette TRACE 5 <- [1,28,null,{"value":"chrome"}] 06:34:22 INFO - 1518676462968 Marionette TRACE 5 -> [0,29,"setContext",{"value":"chrome"}] 06:34:22 INFO - 1518676462970 Marionette TRACE 5 <- [1,29,null,{}] 06:34:22 INFO - 1518676462970 Marionette TRACE 5 -> [0,30,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"marionette.py","script":"\n ... application-requested\", null);\n return cancelQuit.data;\n ","sandbox":"default","line":1052}] 06:34:22 INFO - 1518676462976 Marionette TRACE 5 <- [1,30,null,{"value":false}] 06:34:22 INFO - 1518676462978 Marionette TRACE 5 -> [0,31,"setContext",{"value":"chrome"}] 06:34:22 INFO - 1518676462978 Marionette TRACE 5 <- [1,31,null,{}] 06:34:22 INFO - 1518676462980 Marionette TRACE 5 -> [0,32,"quitApplication",{"flags":["eRestart","eAttemptQuit"]}] 06:34:22 INFO - 1518676462980 Marionette DEBUG New connections will no longer be accepted 06:34:23 INFO - [Parent 6004, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:23 INFO - 1518676463050 Marionette TRACE 5 <- [1,32,null,{"cause":"restart"}] 06:34:23 INFO - [Child 5908, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:23 INFO - 1518676463058 Marionette DEBUG Closed connection 5 06:34:23 INFO - [Child 2560, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:23 INFO - [Child 2560, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:23 INFO - [Child 5400, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:23 INFO - [Child 5400, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 06:34:23 INFO - [Parent 6004, Gecko_IOThread] WARNING: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 188 06:35:18 INFO - *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 06:38:24 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/fZFJ2VXGRmy3UIdati2kTg/artifacts/public/build/target.crashreporter-symbols.zip 06:38:29 INFO - mozcrash Copy/paste: Z:\task_1518674506\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmpmy2yxv.mozrunner\minidumps\3dcfcad1-1ab2-46de-8385-43113dd6ec89.dmp c:\users\genericworker\appdata\local\temp\tmpnzocqr 06:38:38 INFO - mozcrash Saved minidump as Z:\task_1518674506\build\blobber_upload_dir\3dcfcad1-1ab2-46de-8385-43113dd6ec89.dmp 06:38:38 INFO - mozcrash Saved app info as Z:\task_1518674506\build\blobber_upload_dir\3dcfcad1-1ab2-46de-8385-43113dd6ec89.extra 06:38:38 ERROR - PROCESS-CRASH | browser\components\migration\tests\marionette\test_refresh_firefox.py TestFirefoxRefresh.testReset | application crashed [@ mozilla::`anonymous namespace'::RunWatchdog] 06:38:38 INFO - Crash dump filename: c:\users\genericworker\appdata\local\temp\tmpmy2yxv.mozrunner\minidumps\3dcfcad1-1ab2-46de-8385-43113dd6ec89.dmp 06:38:38 INFO - Operating system: Windows NT 06:38:38 INFO - 6.1.7601 Service Pack 1 06:38:38 INFO - CPU: x86 06:38:38 INFO - GenuineIntel family 6 model 63 stepping 2 06:38:38 INFO - 8 CPUs 06:38:38 INFO - GPU: UNKNOWN 06:38:38 INFO - Crash reason: EXCEPTION_BREAKPOINT 06:38:38 INFO - Crash address: 0x581d3671 06:38:38 INFO - Process uptime: 70 seconds 06:38:38 INFO - Thread 51 (crashed) 06:38:38 INFO - 0 xul.dll!mozilla::`anonymous namespace'::RunWatchdog [nsTerminator.cpp:e0ac728caeaa88cddaf54f0bd0936587158151f3 : 206 + 0xb] 06:38:38 INFO - eip = 0x581d3671 esp = 0x123ffb80 ebp = 0x123ffb94 ebx = 0x0d657240 06:38:38 INFO - esi = 0x00000000 edi = 0x0000003f eax = 0x725645cc ecx = 0x5a7016e8 06:38:38 INFO - edx = 0x771f70b4 efl = 0x00000246 06:38:38 INFO - Found by: given as instruction pointer in context 06:38:38 INFO - 1 nss3.dll!_PR_NativeRunThread [pruthr.c:e0ac728caeaa88cddaf54f0bd0936587158151f3 : 397 + 0x6] 06:38:38 INFO - eip = 0x67a7b4ba esp = 0x123ffb9c ebp = 0x123ffbb0 06:38:38 INFO - Found by: previous frame's frame pointer 06:38:38 INFO - 2 nss3.dll!pr_root [w95thred.c:e0ac728caeaa88cddaf54f0bd0936587158151f3 : 137 + 0xa] 06:38:38 INFO - eip = 0x67a70eda esp = 0x123ffbb8 ebp = 0x123ffbbc 06:38:38 INFO - Found by: call frame info 06:38:38 INFO - 3 ucrtbase.dll!_o___stdio_common_vsprintf_s + 0x7d 06:38:38 INFO - eip = 0x67b7aa5d esp = 0x123ffbc4 ebp = 0x123ffbf8 06:38:38 INFO - Found by: call frame info 06:38:38 INFO - 4 kernel32.dll!BaseThreadInitThunk + 0x12 06:38:38 INFO - eip = 0x756b3c45 esp = 0x123ffc00 ebp = 0x123ffc04 06:38:38 INFO - Found by: call frame info 06:38:38 INFO - 5 mozglue.dll!patched_BaseThreadInitThunk [WindowsDllBlocklist.cpp:e0ac728caeaa88cddaf54f0bd0936587158151f3 : 835 + 0x6] 06:38:38 INFO - eip = 0x7254c0ad esp = 0x123ffc0c ebp = 0x123ffc20 06:38:38 INFO - Found by: call frame info 06:38:38 INFO - 6 ntdll.dll!__RtlUserThreadStart + 0x27 06:38:38 INFO - eip = 0x772137f5 esp = 0x123ffc28 ebp = 0x123ffc60 06:38:38 INFO - Found by: call frame info 06:38:38 INFO - 7 ntdll.dll!_RtlUserThreadStart + 0x1b 06:38:38 INFO - eip = 0x772137c8 esp = 0x123ffc68 ebp = 0x123ffc78 06:38:38 INFO - Found by: call frame info 06:38:38 INFO - Thread 0