Closed
Bug 1703441
Opened 4 years ago
Closed 4 years ago
Intermittent telemetry/marionette/tests/client/test_event_ping.py TestEventPing.test_event_ping | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Process unexpectedly quit without restarting (exit code: 0))
Categories
(Toolkit :: Telemetry, defect, P5)
Toolkit
Telemetry
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=335660525&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/R8sVF2tmTo6KfSzCWg1wDg/runs/0/artifacts/public/logs/live_backing.log
[task 2021-04-07T04:16:36.936Z] 04:16:36 INFO - pingserver pings_handler received 'main' ping with reason 'shutdown'
[task 2021-04-07T04:16:36.981Z] 04:16:36 INFO - 1617768996979 Toolkit.Telemetry INFO TelemetrySend::_doPing - successfully loaded, status: 200
[task 2021-04-07T04:16:36.981Z] 04:16:36 INFO - 1617768996979 Toolkit.Telemetry TRACE TelemetrySend::_onPingRequestFinished - success: true, persisted: true
[task 2021-04-07T04:16:36.982Z] 04:16:36 INFO - 1617768996980 Toolkit.Telemetry TRACE TelemetryStorage::removePendingPing - deleting ping with id: 883600a9-89b7-4a7d-8fa9-500d3ba8ca5b, path: Z:\task_1617768576\build\tmpnjdu6g_b.mozrunner\saved-telemetry-pings\883600a9-89b7-4a7d-8fa9-500d3ba8ca5b
[task 2021-04-07T04:16:37.034Z] 04:16:37 INFO - 1617768997032 Toolkit.Telemetry TRACE TelemetrySend::Scheduler::_doSendTask - bailing out after sending, shutdown: false, pendingPingCount: 0
[task 2021-04-07T04:16:37.047Z] 04:16:37 INFO - 1617768997044 Toolkit.Telemetry TRACE TelemetryStorage::loadPingfile - unreadable ping Z:\task_1617768576\build\tmpnjdu6g_b.mozrunner\datareporting\aborted-session-ping: {"operation":"open","path":"Z:\\task_1617768576\\build\\tmpnjdu6g_b.mozrunner\\datareporting\\aborted-session-ping","winLastError":2}
[task 2021-04-07T04:16:37.047Z] 04:16:37 INFO - 1617768997045 Toolkit.Telemetry TRACE TelemetryStorage::loadAbortedSessionPing - no such file
[task 2021-04-07T04:16:37.048Z] 04:16:37 INFO - 1617768997045 Toolkit.Telemetry TRACE TelemetryController::checkAbortedSessionPing - found aborted-session ping: false
[task 2021-04-07T04:16:37.048Z] 04:16:37 INFO - 1617768997046 Toolkit.Telemetry TRACE TelemetrySession::_saveAbortedSessionPing
[task 2021-04-07T04:16:37.048Z] 04:16:37 INFO - 1617768997046 Toolkit.Telemetry TRACE TelemetrySession::getSessionPayload - reason: aborted-session, clearSubsession: false
[task 2021-04-07T04:16:37.049Z] 04:16:37 INFO - 1617768997048 Toolkit.Telemetry TRACE TelemetrySession::assemblePayloadWithMeasurements - reason: aborted-session, submitting subsession data: true
[task 2021-04-07T04:16:37.060Z] 04:16:37 INFO - 1617768997058 Toolkit.Telemetry TRACE TelemetryController::saveAbortedSessionPing
[task 2021-04-07T04:16:37.060Z] 04:16:37 INFO - 1617768997059 Toolkit.Telemetry TRACE TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true}
[task 2021-04-07T04:16:37.077Z] 04:16:37 INFO - 1617768997076 Toolkit.Telemetry TRACE TelemetryStorage::saveAbortedSessionPing - ping path: Z:\task_1617768576\build\tmpnjdu6g_b.mozrunner\datareporting\aborted-session-ping
[task 2021-04-07T04:16:37.106Z] 04:16:37 INFO - 1617768997105 Toolkit.Telemetry TRACE TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-04-07T04:16:37.107Z] 04:16:37 INFO - 1617768997105 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: Z:\task_1617768576\build\tmpnjdu6g_b.mozrunner\datareporting\aborted-session-ping
[task 2021-04-07T04:16:37.125Z] 04:16:37 INFO - 1617768997124 Toolkit.Telemetry TRACE TelemetryEnvironment::registerChangeListener for TelemetrySession::onEnvironmentChange
[task 2021-04-07T04:16:37.127Z] 04:16:37 INFO - 1617768997126 Toolkit.Telemetry TRACE TelemetryScheduler::init
[task 2021-04-07T04:16:37.128Z] 04:16:37 INFO - 1617768997126 Toolkit.Telemetry TRACE TelemetryScheduler::_rescheduleTimeout - isUserIdle: false
[task 2021-04-07T04:16:37.128Z] 04:16:37 INFO - 1617768997127 Toolkit.Telemetry TRACE TelemetryScheduler::_rescheduleTimeout - scheduling next tick for Wed Apr 07 2021 04:21:37 GMT+0000 (Greenwich Mean Time)
[task 2021-04-07T04:16:37.129Z] 04:16:37 INFO - 1617768997127 Toolkit.Telemetry TRACE TelemetryStorage::cleanArchiveTask
[task 2021-04-07T04:16:37.129Z] 04:16:37 INFO - 1617768997128 Toolkit.Telemetry TRACE TelemetryStorage::removeFHRDatabase
[task 2021-04-07T04:16:37.143Z] 04:16:37 INFO - 1617768997142 Toolkit.Telemetry TRACE TelemetryEventPing::::Starting up.
[task 2021-04-07T04:16:37.144Z] 04:16:37 INFO - 1617768997143 Toolkit.Telemetry TRACE TelemetryPrioPing::Starting up.
[task 2021-04-07T04:16:37.144Z] 04:16:37 INFO - 1617768997143 Toolkit.Telemetry TRACE TelemetryController::saveUninstallPing
[task 2021-04-07T04:16:37.146Z] 04:16:37 INFO - 1617768997145 Toolkit.Telemetry INFO TelemetryController::saveUninstallPing - otherInstalls: 0
[task 2021-04-07T04:16:37.147Z] 04:16:37 INFO - 1617768997145 Toolkit.Telemetry TRACE TelemetryController::assemblePing - Type uninstall, aOptions {"addClientId":true,"addEnvironment":true}
[task 2021-04-07T04:16:37.153Z] 04:16:37 INFO - 1617768997152 Toolkit.Telemetry TRACE TelemetryStorage::_purgeOldPings
[task 2021-04-07T04:16:37.195Z] 04:16:37 INFO - 1617768997193 Toolkit.Telemetry TRACE TelemetryStorage::removeUninstallPings - removing: C:\ProgramData\Mozilla\uninstall_ping_EA1A06E644B47E91_6b31cc9a-940b-4a0e-811b-4366a47af76e.json
[task 2021-04-07T04:16:37.222Z] 04:16:37 INFO - 1617768997221 Toolkit.Telemetry TRACE TelemetryStorage::_scanArchive
[task 2021-04-07T04:16:37.262Z] 04:16:37 INFO - [Child 4508, Main Thread] WARNING: Scrolled rect smaller than scrollport?: file /builds/worker/checkouts/gecko/layout/generic/nsGfxScrollFrame.cpp:7064
[task 2021-04-07T04:16:37.281Z] 04:16:37 INFO - 1617768997279 Toolkit.Telemetry TRACE TelemetryStorage::removeUninstallPings - success
[task 2021-04-07T04:16:37.353Z] 04:16:37 INFO - 1617768997351 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: C:\ProgramData\Mozilla\uninstall_ping_EA1A06E644B47E91_baa50418-98b2-4336-b948-77bb17138812.json
[task 2021-04-07T04:16:37.390Z] 04:16:37 INFO - [2021-04-07T04:16:37Z WARN neqo_transport::recovery] [LossRecovery] ignoring in-1 from dropped space
[task 2021-04-07T04:16:37.443Z] 04:16:37 INFO - 1617768997442 Toolkit.Telemetry TRACE TelemetryStorage::_scanArchive - checking in subdir: Z:\task_1617768576\build\tmpnjdu6g_b.mozrunner\datareporting\archived\2021-04
[task 2021-04-07T04:16:37.459Z] 04:16:37 INFO - 1617768997458 Toolkit.Telemetry TRACE TelemetryStorage::_enforceArchiveQuota
[task 2021-04-07T04:19:39.954Z] 04:19:39 INFO - Exiting due to channel error.
[task 2021-04-07T04:19:43.696Z] 04:19:43 INFO - TEST-UNEXPECTED-ERROR | telemetry/marionette/tests/client/test_event_ping.py TestEventPing.test_event_ping | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Process unexpectedly quit without restarting (exit code: 0))
[task 2021-04-07T04:19:43.696Z] 04:19:43 INFO - Traceback (most recent call last):
[task 2021-04-07T04:19:43.696Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 214, in run
[task 2021-04-07T04:19:43.696Z] 04:19:43 INFO - testMethod()
[task 2021-04-07T04:19:43.696Z] 04:19:43 INFO - File "Z:\task_1617768576\build\tests\telemetry\marionette\tests\client\test_event_ping.py", line 51, in test_event_ping
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - payload = self.wait_for_ping(self.restart_browser, EVENT_PING)["payload"]
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\telemetry_harness\testcase.py", line 170, in wait_for_ping
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - action_func, ping_filter, 1, ping_server=ping_server
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\telemetry_harness\testcase.py", line 156, in wait_for_pings
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - action_func()
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\telemetry_harness\testcase.py", line 176, in restart_browser
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - return self.marionette.restart(clean=False, in_app=True)
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_driver\decorators.py", line 37, in _
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - m._handle_socket_failure()
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_driver\marionette.py", line 716, in _handle_socket_failure
[task 2021-04-07T04:19:43.697Z] 04:19:43 INFO - IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\six.py", line 702, in reraise
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - raise value.with_traceback(tb)
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_driver\decorators.py", line 27, in _
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - return func(*args, **kwargs)
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1107, in restart
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - tb,
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\six.py", line 702, in reraise
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - raise value.with_traceback(tb)
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1087, in restart
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - self.raise_for_port(timeout=timeout_restart, check_process_status=False)
[task 2021-04-07T04:19:43.698Z] 04:19:43 INFO - File "Z:\task_1617768576\build\venv\lib\site-packages\marionette_driver\marionette.py", line 598, in raise_for_port
[task 2021-04-07T04:19:43.699Z] 04:19:43 INFO - self.host, self.port
[task 2021-04-07T04:19:43.699Z] 04:19:43 INFO - TEST-INFO took 197264ms```
Comment hidden (Intermittent Failures Robot) |
Comment 2•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•