1434010 - Intermittent Test-Verify TEST-UNEXPECTED-TIMEOUT | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | application timed out after 370 seconds with no output

Status: RESOLVED DUPLICATE of bug 1496135

(Toolkit :: Form Autofill, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nbeleuzu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=159098511&repo=autoland

https://queue.taskcluster.net/v1/task/ZPPvYHXvT-KiBYSBzLYG2g/runs/0/artifacts/public/logs/live_backing.log

Comment 1

[Intermittent Failures Robot]

12 failures in 735 pushes (0.016 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 12

Platform breakdown:
* linux64: 4
* windows7-32: 3
* windows10-64: 3
* osx-10-10: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1434010&startday=2018-01-29&endday=2018-02-04&tree=all

Comment 2

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 3

[Intermittent Failures Robot]

28 failures in 130 pushes (0.215 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-central: 17
* mozilla-inbound: 11

Platform breakdown:
* windows7-32: 6
* windows10-64: 6
* linux64: 6
* osx-10-10: 4
* macosx64-nightly: 2
* linux64-nightly: 2
* windows7-32-nightly: 1
* windows10-64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1434010&startday=2018-04-20&endday=2018-04-20&tree=trunk

Comment 4

[Eliza Balazs [:ebalazs_]]

There are 30 failures in the last 7 days.
Last occurence: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=174884903&lineNumber=9836

Comment 5

[Intermittent Failures Robot]

31 failures in 782 pushes (0.04 failures/push) were associated with this bug in the last 7 days.   

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* mozilla-central: 19
* mozilla-inbound: 12

Platform breakdown:
* windows7-32: 7
* windows10-64: 7
* linux64: 5
* osx-10-10: 4
* windows7-32-nightly: 2
* windows10-64-nightly: 2
* macosx64-nightly: 2
* linux64-nightly: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1434010&startday=2018-04-16&endday=2018-04-22&tree=trunk

Comment 6

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 7

[Cristina Coroiu [:ccoroiu]]

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=181769011&repo=mozilla-central&lineNumber=1390

Comment 8

[Intermittent Failures Robot]

25 failures in 99 pushes (0.253 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-central: 13
* mozilla-inbound: 12

Platform breakdown:
* windows10-64: 8
* linux64: 8
* windows7-32: 5
* osx-10-10: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1434010&startday=2018-06-04&endday=2018-06-04&tree=trunk

Comment 9

[Intermittent Failures Robot]

25 failures in 669 pushes (0.037 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 13
* mozilla-inbound: 12

Platform breakdown:
* windows10-64: 8
* linux64: 8
* windows7-32: 5
* osx-10-10: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1434010&startday=2018-06-04&endday=2018-06-10&tree=trunk

Comment 10

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 11

[Noemi Erli[:noemi_erli]]

This started happening again: https://treeherder.mozilla.org/logviewer.html#?job_id=203136153&repo=autoland&lineNumber=1454

[task 2018-10-03T16:30:55.465Z] 16:30:55     INFO - TEST-START | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js
[task 2018-10-03T16:37:06.000Z] 16:37:06     INFO - Buffered messages logged at 16:30:55
[task 2018-10-03T16:37:06.001Z] 16:37:06     INFO - Entering test bound test_manageCreditCardsInitialState
[task 2018-10-03T16:37:06.002Z] 16:37:06     INFO - TEST-PASS | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | No credit card - 0 == 0 - 
[task 2018-10-03T16:37:06.004Z] 16:37:06     INFO - TEST-PASS | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | Remove button disabled - true == true - 
[task 2018-10-03T16:37:06.005Z] 16:37:06     INFO - TEST-PASS | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | Show Credit Cards button disabled - true == true - 
[task 2018-10-03T16:37:06.006Z] 16:37:06     INFO - TEST-PASS | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | Add button enabled - false == false - 
[task 2018-10-03T16:37:06.007Z] 16:37:06     INFO - TEST-PASS | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | Edit button disabled - true == true - 
[task 2018-10-03T16:37:06.007Z] 16:37:06     INFO - Leaving test bound test_manageCreditCardsInitialState
[task 2018-10-03T16:37:06.008Z] 16:37:06     INFO - Entering test bound test_cancelManageCreditCardsDialogWithESC
[task 2018-10-03T16:37:06.008Z] 16:37:06     INFO - must wait for load
[task 2018-10-03T16:37:06.009Z] 16:37:06     INFO - must wait for focus
[task 2018-10-03T16:37:06.010Z] 16:37:06     INFO - TEST-PASS | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | Manage credit cards dialog is closed with ESC key - 
[task 2018-10-03T16:37:06.012Z] 16:37:06     INFO - Leaving test bound test_cancelManageCreditCardsDialogWithESC
[task 2018-10-03T16:37:06.013Z] 16:37:06     INFO - Entering test bound test_removingSingleAndMultipleCreditCards
[task 2018-10-03T16:37:06.014Z] 16:37:06     INFO - expecting credit card saved
[task 2018-10-03T16:37:06.015Z] 16:37:06     INFO - Buffered messages finished
[task 2018-10-03T16:37:06.015Z] 16:37:06    ERROR - TEST-UNEXPECTED-TIMEOUT | browser/extensions/formautofill/test/browser/browser_manageCreditCardsDialog.js | application timed out after 370 seconds with no output
[task 2018-10-03T16:37:06.016Z] 16:37:06    ERROR - Force-terminating active process(es).
[task 2018-10-03T16:37:06.017Z] 16:37:06     INFO - Determining child pids from psutil...
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - [1154, 1220, 1175, 1282, 1258]
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - ==> process 1068 launched child process 1091
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - ==> process 1068 launched child process 1154
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - ==> process 1068 launched child process 1175
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - ==> process 1068 launched child process 1220
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - ==> process 1068 launched child process 1258
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - ==> process 1068 launched child process 1282
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - Found child pids: set([1154, 1091, 1220, 1258, 1282, 1175])
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - Failed to get child procs
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - Killing process: 1154
[task 2018-10-03T16:37:06.029Z] 16:37:06     INFO - TEST-INFO | started process screentopng
[task 2018-10-03T16:37:06.319Z] 16:37:06     INFO - TEST-INFO | screentopng: exit 0
[task 2018-10-03T16:37:06.321Z] 16:37:06     INFO - Killing process: 1091
[task 2018-10-03T16:37:06.322Z] 16:37:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-10-03T16:37:06.324Z] 16:37:06     INFO - Can't trigger Breakpad, process no longer exists
[task 2018-10-03T16:37:06.325Z] 16:37:06     INFO - Killing process: 1220
[task 2018-10-03T16:37:06.326Z] 16:37:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-10-03T16:37:06.328Z] 16:37:06     INFO - Killing process: 1258
[task 2018-10-03T16:37:06.329Z] 16:37:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-10-03T16:37:06.330Z] 16:37:06     INFO - Killing process: 1282
[task 2018-10-03T16:37:06.331Z] 16:37:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-10-03T16:37:06.333Z] 16:37:06     INFO - Killing process: 1175
[task 2018-10-03T16:37:06.334Z] 16:37:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-10-03T16:37:06.336Z] 16:37:06     INFO - Killing process: 1068
[task 2018-10-03T16:37:06.337Z] 16:37:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-10-03T16:37:06.501Z] 16:37:06     INFO - psutil found pid 1068 dead
[task 2018-10-03T16:37:06.541Z] 16:37:06  WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - TEST-INFO | Main app process: exit 0
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - runtests.py | Application ran for: 0:06:16.641035
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - zombiecheck | Reading PID log: /tmp/tmpIDkPrwpidlog
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - ==> process 1068 launched child process 1091
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - ==> process 1068 launched child process 1154
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - ==> process 1068 launched child process 1175
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - ==> process 1068 launched child process 1220
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - ==> process 1068 launched child process 1258
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - ==> process 1068 launched child process 1282
[task 2018-10-03T16:37:06.541Z] 16:37:06     INFO - zombiecheck | Checking for orphan process with PID: 1282
[task 2018-10-03T16:37:06.542Z] 16:37:06     INFO - zombiecheck | Checking for orphan process with PID: 1091
[task 2018-10-03T16:37:06.543Z] 16:37:06     INFO - zombiecheck | Checking for orphan process with PID: 1220
[task 2018-10-03T16:37:06.543Z] 16:37:06     INFO - zombiecheck | Checking for orphan process with PID: 1258
[task 2018-10-03T16:37:06.544Z] 16:37:06     INFO - zombiecheck | Checking for orphan process with PID: 1154
[task 2018-10-03T16:37:06.545Z] 16:37:06     INFO - zombiecheck | Checking for orphan process with PID: 1175
[task 2018-10-03T16:37:06.553Z] 16:37:06     INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/XNPm8nwvRg-BvWN4b_bbpA/artifacts/public/build/target.crashreporter-symbols.zip
[task 2018-10-03T16:37:13.156Z] 16:37:13     INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpgMQS1D.mozrunner/minidumps/35b1c2f0-12cb-4ecb-e9e6-d074e568531d.dmp /tmp/tmprxnKVB
[task 2018-10-03T16:37:23.474Z] 16:37:23     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/35b1c2f0-12cb-4ecb-e9e6-d074e568531d.dmp
[task 2018-10-03T16:37:23.474Z] 16:37:23     INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/35b1c2f0-12cb-4ecb-e9e6-d074e568531d.extra
[task 2018-10-03T16:37:23.584Z] 16:37:23     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ libc-2.23.so + 0xfb74d]
[task 2018-10-03T16:37:23.584Z] 16:37:23     INFO - Crash dump filename: /tmp/tmpgMQS1D.mozrunner/minidumps/35b1c2f0-12cb-4ecb-e9e6-d074e568531d.dmp
[task 2018-10-03T16:37:23.585Z] 16:37:23     INFO - Operating system: Linux
[task 2018-10-03T16:37:23.586Z] 16:37:23     INFO -                   0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2018-10-03T16:37:23.586Z] 16:37:23     INFO - CPU: amd64
[task 2018-10-03T16:37:23.587Z] 16:37:23     INFO -      family 6 model 62 stepping 4
[task 2018-10-03T16:37:23.587Z] 16:37:23     INFO -      2 CPUs
[task 2018-10-03T16:37:23.587Z] 16:37:23     INFO - 
[task 2018-10-03T16:37:23.588Z] 16:37:23     INFO - GPU: UNKNOWN
[task 2018-10-03T16:37:23.588Z] 16:37:23     INFO - 
[task 2018-10-03T16:37:23.589Z] 16:37:23     INFO - Crash reason:  SIGABRT
[task 2018-10-03T16:37:23.589Z] 16:37:23     INFO - Crash address: 0x3e8000003f2
[task 2018-10-03T16:37:23.590Z] 16:37:23     INFO - Process uptime: not available
[task 2018-10-03T16:37:23.590Z] 16:37:23     INFO - 
[task 2018-10-03T16:37:23.591Z] 16:37:23     INFO - Thread 0 (crashed)
[task 2018-10-03T16:37:23.591Z] 16:37:23     INFO -  0  libc-2.23.so + 0xfb74d
[task 2018-10-03T16:37:23.592Z] 16:37:23     INFO -     rax = 0xfffffffffffffffc   rdx = 0x00000000ffffffff
[task 2018-10-03T16:37:23.592Z] 16:37:23     INFO -     rcx = 0x00007fa449b7574d   rbx = 0x00007fa4498473c0
[task 2018-10-03T16:37:23.593Z] 16:37:23     INFO -     rsi = 0x0000000000000004   rdi = 0x00007fa428f9aec0
[task 2018-10-03T16:37:23.593Z] 16:37:23     INFO -     rbp = 0x00007ffdd1e360a0   rsp = 0x00007ffdd1e36050
[task 2018-10-03T16:37:23.593Z] 16:37:23     INFO -      r8 = 0x0000000000000004    r9 = 0x0000000000000001
[task 2018-10-03T16:37:23.594Z] 16:37:23     INFO -     r10 = 0x00007fa428f2ad40   r11 = 0x0000000000000293
[task 2018-10-03T16:37:23.595Z] 16:37:23     INFO -     r12 = 0x00007fa428f9aec0   r13 = 0x00007ffdd1e36070
[task 2018-10-03T16:37:23.595Z] 16:37:23     INFO -     r14 = 0x00000000ffffffff   r15 = 0x0000000000000004
[task 2018-10-03T16:37:23.597Z] 16:37:23     INFO -     rip = 0x00007fa449b7574d
[task 2018-10-03T16:37:23.598Z] 16:37:23     INFO -     Found by: given as instruction pointer in context
[task 2018-10-03T16:37:23.598Z] 16:37:23     INFO -  1  libxul.so!PollWrapper(_GPollFD*, unsigned int, int) [nsAppShell.cpp:32cde67dd330391a0fb6735be8309a64e646a5f7 : 55 + 0xf]
[task 2018-10-03T16:37:23.599Z] 16:37:23     INFO -     rbp = 0x00007ffdd1e360a0   rsp = 0x00007ffdd1e36060
[task 2018-10-03T16:37:23.599Z] 16:37:23     INFO -     rip = 0x00007fa43c433ae6
[task 2018-10-03T16:37:23.600Z] 16:37:23     INFO -     Found by: stack scanning
[task 2018-10-03T16:37:23.600Z] 16:37:23     INFO -  2  libglib-2.0.so.0.4800.2 + 0x4a38c
[task 2018-10-03T16:37:23.601Z] 16:37:23     INFO -     rbx = 0x00007fa4498b8450   rbp = 0x0000000000000004
[task 2018-10-03T16:37:23.602Z] 16:37:23     INFO -     rsp = 0x00007ffdd1e360b0   r12 = 0x00007fa428f9aec0
[task 2018-10-03T16:37:23.602Z] 16:37:23     INFO -     r13 = 0x00000000ffffffff   r14 = 0x00007fa43c433a30
[task 2018-10-03T16:37:23.602Z] 16:37:23     INFO -     r15 = 0x0000000000000004   rip = 0x00007fa44618138c
[task 2018-10-03T16:37:23.603Z] 16:37:23     INFO -     Found by: call frame info
[task 2018-10-03T16:37:23.603Z] 16:37:23     INFO -  3  libglib-2.0.so.0.4800.2 + 0x4a49c
[task 2018-10-03T16:37:23.603Z] 16:37:23     INFO -     rsp = 0x00007ffdd1e36110   rip = 0x00007fa44618149c
[task 2018-10-03T16:37:23.603Z] 16:37:23     INFO -     Found by: stack scanning
[task 2018-10-03T16:37:23.603Z] 16:37:23     INFO -  4  libxul.so!nsAppShell::ProcessNextNativeEvent(bool) [nsAppShell.cpp:32cde67dd330391a0fb6735be8309a64e646a5f7 : 301 + 0x7]
[task 2018-10-03T16:37:23.604Z] 16:37:23     INFO -     rsp = 0x00007ffdd1e36130   rip = 0x00007fa43c433c6b
[task 2018-10-03T16:37:23.604Z] 16:37:23     INFO -     Found by: stack scanning
[task 2018-10-03T16:37:23.604Z] 16:37:23     INFO -  5  libxul.so!nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal*, bool) [nsBaseAppShell.cpp:32cde67dd330391a0fb6735be8309a64e646a5f7 : 140 + 0xe]
[task 2018-10-03T16:37:23.604Z] 16:37:23     INFO -     rsp = 0x00007ffdd1e36140   rip = 0x00007fa43c3fd925
[task 2018-10-03T16:37:23.605Z] 16:37:23     INFO -     Found by: stack scanning
[task 2018-10-03T16:37:23.605Z] 16:37:23     INFO -  6  libxul.so!non-virtual thunk to nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal*, bool) [nsBaseAppShell.cpp:32cde67dd330391a0fb6735be8309a64e646a5f7 : 0 + 0x5]
[task 2018-10-03T16:37:23.605Z] 16:37:23     INFO -     rsp = 0x00007ffdd1e361a0   rip = 0x00007fa43c3fda0d
[task 2018-10-03T16:37:23.605Z] 16:37:23     INFO -     Found by: stack scanning
[task 2018-10-03T16:37:23.606Z] 16:37:23     INFO -  7  libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:32cde67dd330391a0fb6735be8309a64e646a5f7 : 1144 + 0x10]
[task 2018-10-03T16:37:23.606Z] 16:37:23     INFO -     rsp = 0x00007ffdd1e361b0   rip = 0x00007fa43a3541d1
[task 2018-10-03T16:37:23.606Z] 16:37:23     INFO -     Found by: stack scanning

Comment 13

[Intermittent Failures Robot]

11 failures in 2708 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 3
* try: 8

Platform breakdown:
* linux64-devedition: 1
* linux64: 8
* linux64-nightly: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1434010&startday=2018-10-01&endday=2018-10-07&tree=all