Closed Bug 1641430 Opened 5 years ago Closed 5 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | services/sync/tests/unit/test_errorhandler_1.js | Test timed out

Categories

(Firefox :: Sync, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2020-05-27T23:43:20.327Z] 23:43:20 INFO - TEST-START | services/sync/tests/unit/test_errorhandler_1.js
[task 2020-05-27T23:48:20.330Z] 23:48:20 WARNING - TEST-UNEXPECTED-TIMEOUT | services/sync/tests/unit/test_errorhandler_1.js | Test timed out
[task 2020-05-27T23:48:20.331Z] 23:48:20 INFO - TEST-INFO took 299999ms
[task 2020-05-27T23:48:20.331Z] 23:48:20 INFO - >>>>>>>
[task 2020-05-27T23:48:20.331Z] 23:48:20 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-05-27T23:48:20.331Z] 23:48:20 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2020-05-27T23:48:20.331Z] 23:48:20 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-05-27T23:48:20.332Z] 23:48:20 INFO - running event loop
[task 2020-05-27T23:48:20.332Z] 23:48:20 INFO - services/sync/tests/unit/test_errorhandler_1.js | Starting head_setup
[task 2020-05-27T23:48:20.332Z] 23:48:20 INFO - (xpcshell/head.js) | test head_setup pending (2)
[task 2020-05-27T23:48:20.332Z] 23:48:20 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2020-05-27T23:48:20.332Z] 23:48:20 INFO - PID 8924 | 1590623001452 Sync.Engine.Addons DEBUG SyncEngine initialized: addons
[task 2020-05-27T23:48:20.332Z] 23:48:20 INFO - PID 8924 | 1590623001453 Sync.AddonsReconciler TRACE Loading json from disk: addonsreconciler
[task 2020-05-27T23:48:20.333Z] 23:48:20 INFO - PID 8924 | 1590623001455 Sync.AddonsReconciler DEBUG No data seen in loaded file: addonsreconciler
[task 2020-05-27T23:48:20.333Z] 23:48:20 INFO - PID 8924 | 1590623001463 Sync.Engine.Forms DEBUG Engine constructed
[task 2020-05-27T23:48:20.333Z] 23:48:20 INFO - PID 8924 | 1590623001469 Sync.Engine.Forms DEBUG SyncEngine initialized: forms
[task 2020-05-27T23:48:20.333Z] 23:48:20 INFO - PID 8924 | 1590623001481 Sync.Engine.History DEBUG Engine constructed
[task 2020-05-27T23:48:20.333Z] 23:48:20 INFO - PID 8924 | 1590623001486 Sync.Engine.History DEBUG SyncEngine initialized: history
[task 2020-05-27T23:48:20.333Z] 23:48:20 INFO - PID 8924 | 1590623001495 Sync.Engine.Passwords DEBUG Engine constructed
[task 2020-05-27T23:48:20.334Z] 23:48:20 INFO - PID 8924 | 1590623001499 Sync.Engine.Passwords DEBUG SyncEngine initialized: passwords
[task 2020-05-27T23:48:20.334Z] 23:48:20 INFO - PID 8924 | 1590623001506 Sync.Engine.Prefs DEBUG Engine constructed
[task 2020-05-27T23:48:20.334Z] 23:48:20 INFO - PID 8924 | 1590623001511 Sync.Engine.Prefs DEBUG SyncEngine initialized: prefs
[task 2020-05-27T23:48:20.335Z] 23:48:20 INFO - PID 8924 | 1590623001518 Sync.Engine.Tabs DEBUG Engine constructed
[task 2020-05-27T23:48:20.335Z] 23:48:20 INFO - PID 8924 | 1590623001523 Sync.Engine.Tabs DEBUG SyncEngine initialized: tabs
[task 2020-05-27T23:48:20.335Z] 23:48:20 INFO - PID 8924 | 1590623001524 Sync.Engine.Tabs DEBUG Resetting tabs last sync time
[task 2020-05-27T23:48:20.336Z] 23:48:20 INFO - PID 8924 | 1590623001545 Sync.Engine.Bookmarks DEBUG Engine constructed
[task 2020-05-27T23:48:20.336Z] 23:48:20 INFO - PID 8924 | 1590623001551 Sync.Engine.Bookmarks DEBUG SyncEngine initialized: bookmarks
[task 2020-05-27T23:48:20.336Z] 23:48:20 INFO - PID 8924 | 1590623001560 Sync.Engine.Extension-Storage DEBUG Engine constructed
[task 2020-05-27T23:48:20.336Z] 23:48:20 INFO - PID 8924 | 1590623001564 Sync.Engine.Extension-Storage DEBUG SyncEngine initialized: extension-storage
[task 2020-05-27T23:48:20.336Z] 23:48:20 INFO - PID 8924 | 1590623001565 Sync.Service INFO Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:78.0) Gecko/20100101 XPCShell/1
[task 2020-05-27T23:48:20.336Z] 23:48:20 INFO - PID 8924 | 1590623001605 Sync.Status DEBUG Status.login: error.login.reason.no_username => error.login.reason.no_username
[task 2020-05-27T23:48:20.337Z] 23:48:20 INFO - PID 8924 | 1590623001605 Sync.Status DEBUG Status.service: service.client_not_configured => service.client_not_configured
[task 2020-05-27T23:48:20.337Z] 23:48:20 INFO - PID 8924 | 1590623001605 Sync.Status DEBUG Status.service: service.client_not_configured => service.client_not_configured
[task 2020-05-27T23:48:20.337Z] 23:48:20 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2020-05-27T23:48:20.338Z] 23:48:20 INFO - (xpcshell/head.js) | test head_setup finished (2)
[task 2020-05-27T23:48:20.338Z] 23:48:20 INFO - PID 8924 | 1590623001610 Sync.SyncScheduler TRACE Handling weave:service:ready
[task 2020-05-27T23:48:20.338Z] 23:48:20 INFO - PID 8924 | 1590623001611 Sync.Telemetry TRACE observed weave:service:ready null
[task 2020-05-27T23:48:20.339Z] 23:48:20 INFO - PID 8924 | 1590623001611 Sync.Telemetry TRACE Not sending telemetry ping for self-hosted Sync user
[task 2020-05-27T23:48:20.339Z] 23:48:20 INFO - services/sync/tests/unit/test_errorhandler_1.js | Starting setup
[task 2020-05-27T23:48:20.339Z] 23:48:20 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2020-05-27T23:48:20.339Z] 23:48:20 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2020-05-27T23:48:20.340Z] 23:48:20 INFO - PID 8924 | 1590623001613 Sync.Engine.Addons.Tracker TRACE stop().
[task 2020-05-27T23:48:20.340Z] 23:48:20 INFO - PID 8924 | 1590623001748 Sync.Engine.Forms.Tracker TRACE stop().
[task 2020-05-27T23:48:20.340Z] 23:48:20 INFO - PID 8924 | 1590623001762 Sync.Engine.History.Tracker TRACE stop().
[task 2020-05-27T23:48:20.340Z] 23:48:20 INFO - PID 8924 | 1590623001774 Sync.Engine.Passwords.Tracker TRACE stop().
[task 2020-05-27T23:48:20.341Z] 23:48:20 INFO - PID 8924 | 1590623001786 Sync.Engine.Prefs.Tracker TRACE stop().
[task 2020-05-27T23:48:20.341Z] 23:48:20 INFO - PID 8924 | 1590623001787 Sync.Engine.Tabs.Tracker TRACE stop().
[task 2020-05-27T23:48:20.341Z] 23:48:20 INFO - PID 8924 | 1590623001816 Sync.Engine.Bookmarks.Tracker TRACE stop().
[task 2020-05-27T23:48:20.342Z] 23:48:20 INFO - PID 8924 | 1590623001819 Sync.Engine.Extension-Storage.Tracker TRACE stop().
[task 2020-05-27T23:48:20.342Z] 23:48:20 INFO - PID 8924 | 1590623001822 Sync.Engine.Catapult DEBUG Engine constructed
[task 2020-05-27T23:48:20.342Z] 23:48:20 INFO - PID 8924 | 1590623001826 Sync.Engine.Catapult DEBUG SyncEngine initialized: catapult
[task 2020-05-27T23:48:20.343Z] 23:48:20 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2020-05-27T23:48:20.343Z] 23:48:20 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2020-05-27T23:48:20.343Z] 23:48:20 INFO - services/sync/tests/unit/test_errorhandler_1.js | Starting test_401_logout
[task 2020-05-27T23:48:20.343Z] 23:48:20 INFO - (xpcshell/head.js) | test test_401_logout pending (2)
[task 2020-05-27T23:48:20.344Z] 23:48:20 INFO - PID 8924 | 1590623001830 Sync.Engine.Clients DEBUG Engine syncIDs: 7-oJbQm-k4Uj,
[task 2020-05-27T23:48:20.344Z] 23:48:20 INFO - (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2020-05-27T23:48:20.344Z] 23:48:20 INFO - PID 8924 | 1590623001832 Sync.Engine.Catapult DEBUG Engine syncIDs: wPJU_x7aSpGb,
[task 2020-05-27T23:48:20.344Z] 23:48:20 INFO - PID 8924 | 1590623001843 Sync.BrowserIDManager INFO Getting keys
[task 2020-05-27T23:48:20.345Z] 23:48:20 INFO - PID 8924 | 1590623001845 Sync.BrowserIDManager INFO Getting an assertion from: http://token-server
[task 2020-05-27T23:48:20.345Z] 23:48:20 INFO - PID 8924 | 1590623001845 Sync.BrowserIDManager DEBUG Getting a token using OAuth
[task 2020-05-27T23:48:20.345Z] 23:48:20 INFO - PID 8924 | 1590623001845 FirefoxAccounts DEBUG getAccessToken enter
[task 2020-05-27T23:48:20.346Z] 23:48:20 INFO - PID 8924 | 1590623001846 FirefoxAccounts DEBUG Fetching scopedKeys data for https://identity.mozilla.com/apps/oldsync
[task 2020-05-27T23:48:20.346Z] 23:48:20 INFO - TEST-PASS | services/sync/tests/unit/test_errorhandler_1.js | test_401_logout - [test_401_logout : 260] "http://token-server" == "http://token-server"
[task 2020-05-27T23:48:20.346Z] 23:48:20 INFO - TEST-PASS | services/sync/tests/unit/test_errorhandler_1.js | test_401_logout - [test_401_logout : 264] oauth token present - "some-access-token" == true

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.