1662906 - Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py <test> | application crashed [@ RustMozCrash(char const*, int, char const*)]

Reporter

Description

•

5 years ago

treeherder

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=314736668&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OPT4Zm8sQ0uyvyZYXEZqng/runs/0/artifacts/public/logs/live_backing.log

[task 2020-09-02T20:21:55.730Z] 20:21:55     INFO -  TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestQuitRestartWithWorkspace.test_quit_keeps_same_profile
[task 2020-09-02T20:21:55.730Z] 20:21:55     INFO -  1599078115729	Marionette	DEBUG	Closed connection 3
[task 2020-09-02T20:21:55.732Z] 20:21:55     INFO -  1599078115730	Marionette	DEBUG	Accepted connection 4 from 127.0.0.1:51488
[task 2020-09-02T20:21:55.734Z] 20:21:55     INFO -  1599078115731	Marionette	DEBUG	4 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-09-02T20:21:55.734Z] 20:21:55     INFO -  1599078115733	Marionette	TRACE	[20] Frame script loaded
[task 2020-09-02T20:21:55.736Z] 20:21:55     INFO -  1599078115734	Marionette	TRACE	[20] Frame script registered
[task 2020-09-02T20:21:55.738Z] 20:21:55     INFO -  1599078115736	Marionette	DEBUG	4 <- [1,1,null,{"sessionId":"67ed6c7e-c2fb-47be-b183-f47450fa608d","capabilities":{"browserName":"firefox","browserVersion":"82.0a ... x\\tmp9bfkcq.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-09-02T20:21:55.740Z] 20:21:55     INFO -  1599078115737	Marionette	DEBUG	4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2020-09-02T20:21:55.740Z] 20:21:55     INFO -  1599078115737	Marionette	DEBUG	4 <- [1,2,null,{"value":null}]
[task 2020-09-02T20:21:55.740Z] 20:21:55     INFO -  1599078115738	Marionette	DEBUG	4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2020-09-02T20:21:55.740Z] 20:21:55     INFO -  1599078115739	Marionette	DEBUG	4 <- [1,3,null,{"value":null}]
[task 2020-09-02T20:21:55.742Z] 20:21:55     INFO -  1599078115740	Marionette	DEBUG	4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2020-09-02T20:21:55.742Z] 20:21:55     INFO -  1599078115741	Marionette	DEBUG	4 <- [1,4,null,{"value":null}]
[task 2020-09-02T20:21:55.813Z] 20:21:55     INFO -  Application command: Z:\task_1599076063\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile c:\users\task_1599076063\appdata\local\temp\tmpyyu7cx\tmp9bfkcq.mozrunner
[task 2020-09-02T20:21:59.271Z] 20:21:59     INFO -  Exiting due to channel error.
[task 2020-09-02T20:21:59.271Z] 20:21:59     INFO -  Exiting due to channel error.
[task 2020-09-02T20:21:59.271Z] 20:21:59     INFO -  Exiting due to channel error.
[task 2020-09-02T20:21:59.271Z] 20:21:59     INFO -  Exiting due to channel error.
[task 2020-09-02T20:23:56.064Z] 20:23:56     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Dc4BTpPmRg67J-ZIGxRYVw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2020-09-02T20:24:00.817Z] 20:24:00     INFO -  mozcrash Copy/paste: Z:/task_1599076063/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1599076063\appdata\local\temp\tmpyyu7cx\tmp9bfkcq.mozrunner\minidumps\c386978e-ec2b-43a1-86cd-5c171b469190.dmp c:\users\task_1599076063\appdata\local\temp\tmpgj7er3
[task 2020-09-02T20:24:06.081Z] 20:24:06     INFO -  mozcrash Saved minidump as Z:\task_1599076063\build\blobber_upload_dir\c386978e-ec2b-43a1-86cd-5c171b469190.dmp
[task 2020-09-02T20:24:06.083Z] 20:24:06     INFO -  mozcrash Saved app info as Z:\task_1599076063\build\blobber_upload_dir\c386978e-ec2b-43a1-86cd-5c171b469190.extra
[task 2020-09-02T20:24:06.088Z] 20:24:06    ERROR -  PROCESS-CRASH | testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestQuitRestartWithWorkspace.test_quit_keeps_same_profile | application crashed [@ RustMozCrash(char const*, int, char const*)]
[task 2020-09-02T20:24:06.088Z] 20:24:06     INFO -  Mozilla crash reason: Setting upload enabled failed!
[task 2020-09-02T20:24:06.089Z] 20:24:06     INFO -  Crash dump filename: c:\users\task_1599076063\appdata\local\temp\tmpyyu7cx\tmp9bfkcq.mozrunner\minidumps\c386978e-ec2b-43a1-86cd-5c171b469190.dmp
[task 2020-09-02T20:24:06.090Z] 20:24:06     INFO -  Operating system: Windows NT
[task 2020-09-02T20:24:06.090Z] 20:24:06     INFO -                    10.0.17134
[task 2020-09-02T20:24:06.090Z] 20:24:06     INFO -  CPU: amd64
[task 2020-09-02T20:24:06.091Z] 20:24:06     INFO -       family 6 model 85 stepping 4
[task 2020-09-02T20:24:06.092Z] 20:24:06     INFO -       8 CPUs
[task 2020-09-02T20:24:06.092Z] 20:24:06     INFO -  GPU: UNKNOWN
[task 2020-09-02T20:24:06.093Z] 20:24:06     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
[task 2020-09-02T20:24:06.093Z] 20:24:06     INFO -  Crash address: 0xb0f486b0
[task 2020-09-02T20:24:06.094Z] 20:24:06     INFO -  Process uptime: 4 seconds
[task 2020-09-02T20:24:06.094Z] 20:24:06     INFO -  Thread 0 (crashed)
[task 2020-09-02T20:24:06.094Z] 20:24:06     INFO -   0  xul.dll!RustMozCrash(char const*, int, char const*) [wrappers.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 16 + 0x10]
[task 2020-09-02T20:24:06.095Z] 20:24:06     INFO -      rax = 0x00007ffae30797b8   rdx = 0x000000000000007b
[task 2020-09-02T20:24:06.095Z] 20:24:06     INFO -      rcx = 0x000000000000007b   rbx = 0x0000000000000023
[task 2020-09-02T20:24:06.096Z] 20:24:06     INFO -      rsi = 0x000000000000007b   rdi = 0x00007ffab197f998
[task 2020-09-02T20:24:06.096Z] 20:24:06     INFO -      rbp = 0x000000ffebdfc030   rsp = 0x000000ffebdfbf80
[task 2020-09-02T20:24:06.097Z] 20:24:06     INFO -       r8 = 0x000000ffebdfc1e2    r9 = 0x0000000000000000
[task 2020-09-02T20:24:06.097Z] 20:24:06     INFO -      r10 = 0x000000ffebdfbd58   r11 = 0x0000000000000023
[task 2020-09-02T20:24:06.098Z] 20:24:06     INFO -      r12 = 0x0000000000000001   r13 = 0x00007ffab1be4a90
[task 2020-09-02T20:24:06.098Z] 20:24:06     INFO -      r14 = 0x00007ffab1a30e88   r15 = 0x000000ffebdfcc70
[task 2020-09-02T20:24:06.099Z] 20:24:06     INFO -      rip = 0x00007ffab0f486b0
[task 2020-09-02T20:24:06.099Z] 20:24:06     INFO -      Found by: given as instruction pointer in context
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -   1  xul.dll!mozglue_static::panic_hook(core::panic::PanicInfo*) [lib.rs:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 89 + 0x7]
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -      rsp = 0x000000ffebdfbfb0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.101Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab01a9293
[task 2020-09-02T20:24:06.101Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.102Z] 20:24:06     INFO -   2  xul.dll!core::ops::function::Fn::call<fn(core::panic::PanicInfo*),(core::panic::PanicInfo*)>(void (**)(core::panic::PanicInfo*), core::panic::PanicInfo*) [function.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 154 + 0x12]
[task 2020-09-02T20:24:06.102Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.103Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc410   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.103Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.104Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab01a91a2
[task 2020-09-02T20:24:06.104Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.104Z] 20:24:06     INFO -   3  xul.dll!std::panicking::rust_panic_with_hook() [panicking.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 474 + 0x6]
[task 2020-09-02T20:24:06.105Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.106Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc440   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.106Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.107Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab036aba1
[task 2020-09-02T20:24:06.107Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.108Z] 20:24:06     INFO -   4  xul.dll!std::panicking::begin_panic_handler() [panicking.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 378 + 0x11]
[task 2020-09-02T20:24:06.108Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.109Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc540   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.109Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.110Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab03709da
[task 2020-09-02T20:24:06.111Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.111Z] 20:24:06     INFO -   5  xul.dll!core::panicking::panic_fmt() [panicking.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 85 + 0x5]
[task 2020-09-02T20:24:06.112Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.112Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc590   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.113Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.113Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaafd78690
[task 2020-09-02T20:24:06.114Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.114Z] 20:24:06     INFO -   6  xul.dll!core::option::expect_failed() [option.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 1203 + 0x8]
[task 2020-09-02T20:24:06.115Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.115Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc5e0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.116Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.116Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaafd7eda2
[task 2020-09-02T20:24:06.117Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.117Z] 20:24:06     INFO -   7  xul.dll!fog_control::{{impl}}::allocate::Observe(xpcom::interfaces::idl::nsIObserver*, xpcom::interfaces::idl::nsISupports*, signed char*, short*) [lib.rs:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 219 + 0x64]
[task 2020-09-02T20:24:06.118Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.118Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc660   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.119Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.119Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaaff478a1
[task 2020-09-02T20:24:06.120Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.120Z] 20:24:06     INFO -   8  xul.dll!static nsPrefBranch::NotifyObserver(char const*, void*) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 2686 + 0x17]
[task 2020-09-02T20:24:06.121Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.121Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc7f0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.122Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.122Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac060a92
[task 2020-09-02T20:24:06.123Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.124Z] 20:24:06     INFO -   9  xul.dll!NotifyCallbacks(nsTString<char> const&, PrefWrapper const*) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 1681 + 0x6]
[task 2020-09-02T20:24:06.124Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.125Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc8f0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.125Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.126Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac070481
[task 2020-09-02T20:24:06.126Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.127Z] 20:24:06     INFO -  10  xul.dll!pref_SetPref(nsTString<char> const&, mozilla::PrefType, mozilla::PrefValueKind, PrefValue, bool, bool, bool) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 1639 + 0x25]
[task 2020-09-02T20:24:06.127Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.128Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc940   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.128Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.129Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac098817
[task 2020-09-02T20:24:06.129Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.130Z] 20:24:06     INFO -  11  xul.dll!static mozilla::Preferences::SetBool(char const*, bool, mozilla::PrefValueKind) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 4701 + 0x25]
[task 2020-09-02T20:24:06.130Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.131Z] 20:24:06     INFO -      rsp = 0x000000ffebdfca80   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.131Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.132Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac05d37d
[task 2020-09-02T20:24:06.132Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.133Z] 20:24:06     INFO -  12  xul.dll!nsPrefBranch::SetBoolPref(char const*, bool) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 2078 + 0x7]
[task 2020-09-02T20:24:06.133Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.134Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcb00   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.134Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.135Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac05d2c1
[task 2020-09-02T20:24:06.135Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.136Z] 20:24:06     INFO -  13  xul.dll!XPTC__InvokebyIndex + 0x72
[task 2020-09-02T20:24:06.136Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.137Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcb60   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.137Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.138Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab11a11e2
[task 2020-09-02T20:24:06.138Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.139Z] 20:24:06     INFO -  14  0x25e0a786d60
[task 2020-09-02T20:24:06.140Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.140Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcb70   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.141Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.141Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x0000025e0a786d60
[task 2020-09-02T20:24:06.142Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.142Z] 20:24:06     INFO -  15  xul.dll!truncf + 0x37e80
[task 2020-09-02T20:24:06.143Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcb78   rip = 0x00007ffab11def00
[task 2020-09-02T20:24:06.143Z] 20:24:06     INFO -      Found by: stack scanning
[task 2020-09-02T20:24:06.143Z] 20:24:06     INFO -  16  xul.dll!truncf + 0x37eb0
[task 2020-09-02T20:24:06.143Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcb90   rip = 0x00007ffab11def30
[task 2020-09-02T20:24:06.144Z] 20:24:06     INFO -      Found by: stack scanning
[task 2020-09-02T20:24:06.145Z] 20:24:06     INFO -  17  xul.dll!truncf + 0x37f70
[task 2020-09-02T20:24:06.145Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcba8   rip = 0x00007ffab11deff0
[task 2020-09-02T20:24:06.146Z] 20:24:06     INFO -      Found by: stack scanning
[task 2020-09-02T20:24:06.146Z] 20:24:06     INFO -  18  xul.dll!static XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [XPCWrappedNative.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 1141 + 0xe20]
[task 2020-09-02T20:24:06.147Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcbb0   rip = 0x00007ffaac8b3ab7
[task 2020-09-02T20:24:06.147Z] 20:24:06     INFO -      Found by: stack scanning
[task 2020-09-02T20:24:06.148Z] 20:24:06     INFO -  19  xul.dll!XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [XPCWrappedNativeJSOps.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 946 + 0x8]
[task 2020-09-02T20:24:06.148Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcdf0   rip = 0x00007ffaac8b50e8
[task 2020-09-02T20:24:06.149Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.149Z] 20:24:06     INFO -  20  0xd8e0ac23ea
[task 2020-09-02T20:24:06.150Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcf60   rip = 0x000000d8e0ac23ea
[task 2020-09-02T20:24:06.150Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.151Z] 20:24:06     INFO -  21  xul.dll!truncf + 0x730eb0
[task 2020-09-02T20:24:06.151Z] 20:24:06     INFO -      rsp = 0x000000ffebdfcf88   rip = 0x00007ffab18d7f30
[task 2020-09-02T20:24:06.152Z] 20:24:06     INFO -      Found by: stack scanning
[task 2020-09-02T20:24:06.153Z] 20:24:06     INFO -  Thread 1
[task 2020-09-02T20:24:06.153Z] 20:24:06     INFO -   0  ntdll.dll!NtRemoveIoCompletion + 0x14

Henrik Skupin [:whimboo][⌚️UTC+2]

Comment 1

•

5 years ago

[task 2020-09-02T20:24:06.093Z] 20:24:06     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
[task 2020-09-02T20:24:06.093Z] 20:24:06     INFO -  Crash address: 0xb0f486b0
[task 2020-09-02T20:24:06.094Z] 20:24:06     INFO -  Process uptime: 4 seconds
[task 2020-09-02T20:24:06.094Z] 20:24:06     INFO -  Thread 0 (crashed)
[task 2020-09-02T20:24:06.094Z] 20:24:06     INFO -   0  xul.dll!RustMozCrash(char const*, int, char const*) [wrappers.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 16 + 0x10]
[task 2020-09-02T20:24:06.095Z] 20:24:06     INFO -      rax = 0x00007ffae30797b8   rdx = 0x000000000000007b
[task 2020-09-02T20:24:06.095Z] 20:24:06     INFO -      rcx = 0x000000000000007b   rbx = 0x0000000000000023
[task 2020-09-02T20:24:06.096Z] 20:24:06     INFO -      rsi = 0x000000000000007b   rdi = 0x00007ffab197f998
[task 2020-09-02T20:24:06.096Z] 20:24:06     INFO -      rbp = 0x000000ffebdfc030   rsp = 0x000000ffebdfbf80
[task 2020-09-02T20:24:06.097Z] 20:24:06     INFO -       r8 = 0x000000ffebdfc1e2    r9 = 0x0000000000000000
[task 2020-09-02T20:24:06.097Z] 20:24:06     INFO -      r10 = 0x000000ffebdfbd58   r11 = 0x0000000000000023
[task 2020-09-02T20:24:06.098Z] 20:24:06     INFO -      r12 = 0x0000000000000001   r13 = 0x00007ffab1be4a90
[task 2020-09-02T20:24:06.098Z] 20:24:06     INFO -      r14 = 0x00007ffab1a30e88   r15 = 0x000000ffebdfcc70
[task 2020-09-02T20:24:06.099Z] 20:24:06     INFO -      rip = 0x00007ffab0f486b0
[task 2020-09-02T20:24:06.099Z] 20:24:06     INFO -      Found by: given as instruction pointer in context[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -   1  xul.dll!mozglue_static::panic_hook(core::panic::PanicInfo*) [lib.rs:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 89 + 0x7]
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -      rsp = 0x000000ffebdfbfb0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.100Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.101Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab01a9293
[task 2020-09-02T20:24:06.101Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.102Z] 20:24:06     INFO -   2  xul.dll!core::ops::function::Fn::call<fn(core::panic::PanicInfo*),(core::panic::PanicInfo*)>(void (**)(core::panic::PanicInfo*), core::panic::PanicInfo*) [function.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 154 + 0x12]
[task 2020-09-02T20:24:06.102Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.103Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc410   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.103Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.104Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab01a91a2
[task 2020-09-02T20:24:06.104Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.104Z] 20:24:06     INFO -   3  xul.dll!std::panicking::rust_panic_with_hook() [panicking.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 474 + 0x6]
[task 2020-09-02T20:24:06.105Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.106Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc440   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.106Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.107Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab036aba1
[task 2020-09-02T20:24:06.107Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.108Z] 20:24:06     INFO -   4  xul.dll!std::panicking::begin_panic_handler() [panicking.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 378 + 0x11]
[task 2020-09-02T20:24:06.108Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.109Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc540   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.109Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.110Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffab03709da
[task 2020-09-02T20:24:06.111Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.111Z] 20:24:06     INFO -   5  xul.dll!core::panicking::panic_fmt() [panicking.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 85 + 0x5]
[task 2020-09-02T20:24:06.112Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.112Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc590   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.113Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.113Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaafd78690
[task 2020-09-02T20:24:06.114Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.114Z] 20:24:06     INFO -   6  xul.dll!core::option::expect_failed() [option.rs:4fb7144ed159f94491249e86d5bbd033b5d60550 : 1203 + 0x8]
[task 2020-09-02T20:24:06.115Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.115Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc5e0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.116Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.116Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaafd7eda2
[task 2020-09-02T20:24:06.117Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.117Z] 20:24:06     INFO -   7  xul.dll!fog_control::{{impl}}::allocate::Observe(xpcom::interfaces::idl::nsIObserver*, xpcom::interfaces::idl::nsISupports*, signed char*, short*) [lib.rs:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 219 + 0x64]
[task 2020-09-02T20:24:06.118Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.118Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc660   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.119Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.119Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaaff478a1
[task 2020-09-02T20:24:06.120Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.120Z] 20:24:06     INFO -   8  xul.dll!static nsPrefBranch::NotifyObserver(char const*, void*) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 2686 + 0x17]
[task 2020-09-02T20:24:06.121Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.121Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc7f0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.122Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.122Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac060a92
[task 2020-09-02T20:24:06.123Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.124Z] 20:24:06     INFO -   9  xul.dll!NotifyCallbacks(nsTString<char> const&, PrefWrapper const*) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 1681 + 0x6]
[task 2020-09-02T20:24:06.124Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.125Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc8f0   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.125Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.126Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac070481
[task 2020-09-02T20:24:06.126Z] 20:24:06     INFO -      Found by: call frame info
[task 2020-09-02T20:24:06.127Z] 20:24:06     INFO -  10  xul.dll!pref_SetPref(nsTString<char> const&, mozilla::PrefType, mozilla::PrefValueKind, PrefValue, bool, bool, bool) [Preferences.cpp:85e7a3055098f2f8f8d7abc59d7f0d6215e47984 : 1639 + 0x25]
[task 2020-09-02T20:24:06.127Z] 20:24:06     INFO -      rbx = 0x0000000000000023   rbp = 0x000000ffebdfc030
[task 2020-09-02T20:24:06.128Z] 20:24:06     INFO -      rsp = 0x000000ffebdfc940   r12 = 0x0000000000000001
[task 2020-09-02T20:24:06.128Z] 20:24:06     INFO -      r13 = 0x00007ffab1be4a90   r14 = 0x00007ffab1a30e88
[task 2020-09-02T20:24:06.129Z] 20:24:06     INFO -      r15 = 0x000000ffebdfcc70   rip = 0x00007ffaac098817
[task 2020-09-02T20:24:06.129Z] 20:24:06     INFO -      Found by: call frame info

Nicholas, is that nsPrefBranch::NotifyObserver or the observer implementation which acts badly here? I assume the latter given that only this seems to be implemented in Rust. Nevertheless moving to the preferences back-end component for now.

Component: Marionette → Preferences: Backend

Flags: needinfo?(n.nethercote)

Product: Testing → Core

Comment hidden (Intermittent Failures Robot)

Nicholas Nethercote [inactive]

Comment 3

•

5 years ago

The failure passes through expect_failed() which indicates that the Rust code expected an Option<T> type to have a Some(T) value when it actually had a None value. That definitely seems like the problem is with the observer implementation rather than libpref.

Flags: needinfo?(n.nethercote)

Henrik Skupin [:whimboo][⌚️UTC+2]

Comment 4

•

5 years ago

I assume that means the XPCOM component then.

Component: Preferences: Backend → XPCOM

Henrik Skupin [:whimboo][⌚️UTC+2]

Updated

•

5 years ago

Updated

•

5 years ago

Updated

•

5 years ago

Summary: Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestQuitRestartWithWorkspace.test_quit_keeps_same_profile | application crashed [@ RustMozCrash(char const*, int, char const*)] → Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py <test> | application crashed [@ RustMozCrash(char const*, int, char const*)]

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+2]

Comment 10

•

5 years ago

Nika, can you please have a look? Could this just be a move of the crash stack based on the fix on bug 1660893? See also bug 1660893 comment 6 for details.

Flags: needinfo?(nika)

Nika Layzell [:nika] (ni? for response)

Comment 11

•

5 years ago

This crash occurred due to the expect call on this line failing: https://searchfox.org/mozilla-central/rev/35245411b9e8a911fe3f5adb0632c3394f8b4ccb/toolkit/components/glean/src/api.rs#139. You can tell because the crash stack is coming from rust, and the specific reason is cited as being that string https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=314736668&repo=autoland&lineNumber=32981.

This looks like a bug in fog/glean. Ni? :chutten

Component: XPCOM → Telemetry

Flags: needinfo?(nika) → needinfo?(chutten)

Product: Core → Toolkit

Chris H-C :chutten|PTO (back Oct 23)

Assignee

Comment 12

•

5 years ago

Ohhhh, y'know what, this could be the pref observer firing before the Glean SDK has a chance to init. Interesting.

This is a hole in our preferences handling, then. Because this means a pref change between this line and when the Glean SDK is init is not told to the Glean SDK.

The simplest fix involves two parts:

Don't explode in api::set_upload_enabled if Glean is not init. It's fine.
Call set_upload_enabled immediately after init if the value changed in the interim. We'll be swallowing all changes in between those two lines above, so we'll need to pass the new value to the SDK the first chance we get.

Jan-Erik, how does this sound? It's sounding a little too close to a previous anti-pattern around initialization that I'd like your input before I move ahead with this.

(( Setting severity to S4 as this is unlikely to happen outside of tests and is impossible outside of Nightly ))

Assignee: nobody → chutten

Severity: normal → S4

Status: NEW → ASSIGNED

Flags: needinfo?(chutten) → needinfo?(jrediger)

Priority: -- → P1

Jan-Erik Rediger [:janerik]

Comment 13

•

5 years ago

On other platforms we use the dispatcher queue to call set_upload_enabled. We ignore calls to set_upload_enabled before initialize there.
I think we can just use the dispatcher in FOG too?

Flags: needinfo?(jrediger)

Chris H-C :chutten|PTO (back Oct 23)

Assignee

Comment 14

•

5 years ago

Sounds like a good idea to me. That has some nice benefits on top of the core "let's not crash" one : )

Chris H-C :chutten|PTO (back Oct 23)

Assignee

Comment 15

•

5 years ago

Attached file Bug 1662906 - Dispatch set_upload_enabled r?janerik! — Details

Chris H-C :chutten|PTO (back Oct 23)

Assignee

Comment 16

•

5 years ago

Attached file Bug 1662906 - Test that we don't crash when setting upload enabled during fog init r?janerik! — Details

Depends on D92766

Pulsebot

Comment 17

•

5 years ago

Pushed by chutten@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/47d2699daba3 Dispatch set_upload_enabled r=janerik https://hg.mozilla.org/integration/autoland/rev/6e26565343ec Test that we don't crash when setting upload enabled during fog init r=janerik

Andreea Pavel [:apavel]

Comment 18

•

5 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/47d2699daba3
https://hg.mozilla.org/mozilla-central/rev/6e26565343ec

Status: ASSIGNED → RESOLVED

Closed: 5 years ago

status-firefox83: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → 83 Branch

Comment hidden (Intermittent Failures Robot)

Ryan VanderMeulen [:RyanVM]

Updated

•

5 years ago

status-firefox82: --- → wontfix

status-firefox-esr78: --- → unaffected

Jan-Erik Rediger [:janerik]

Updated

•

5 years ago

Regressions: 1681472

Bug 1662906 - Dispatch set_upload_enabled r?janerik! 5 years ago Chris H-C :chutten\|PTO (back Oct 23) 47 bytes, text/x-phabricator-request		Details \| Review
Bug 1662906 - Test that we don't crash when setting upload enabled during fog init r?janerik! 5 years ago Chris H-C :chutten\|PTO (back Oct 23) 47 bytes, text/x-phabricator-request		Details \| Review