Closed Bug 699868 Opened 14 years ago Closed 14 years ago

Intermittent TEST-UNEXPECTED-FAIL | xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | test failed (with xpcshell return code: 0) | | error.login.reason.network == error.login.reason.account

Categories

(Cloud Services :: General, defect)

Product:
Cloud Services
Component:
General
Platform:
x86_64
All
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED
Milestone:
mozilla10

People

(Reporter: mbrubeck, Assigned: rnewman)

References

Details

(Keywords: intermittent-failure, Whiteboard: [inbound])

This happened in two different test runs on the same push. That plus the error makes me think that maybe this test depends on an external network resource or something. https://tbpl.mozilla.org/php/getParsedLog.php?id=7208394&tree=Mozilla-Inbound Rev3 Fedora 12x64 mozilla-inbound debug test xpcshell on 2011-11-04 07:18:46 PDT for push dd25b9224c76 TEST-INFO | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncengine_sync.js | running test ... TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncengine_sync.js | test passed (time: 4465.629ms) TEST-INFO | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | running test ... TEST-UNEXPECTED-FAIL | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | test failed (with xpcshell return code: 0), see following log: >>>>>>> ### XPCOM_MEM_LEAK_LOG defined -- logging leaks to /tmp/tmpeAHV7C/runxpcshelltests_leaks.log Setting the identity for passphrase TEST-INFO | (xpcshell/head.js) | test 1 pending TEST-INFO | (xpcshell/head.js) | test 2 pending TEST-INFO | (xpcshell/head.js) | test 2 finished TEST-INFO | (xpcshell/head.js) | running event loop Sync.SyncScheduler TRACE Handling weave:service:ready TEST-INFO | (xpcshell/head.js) | test 2 pending TEST-INFO | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | Starting test_prefAttributes Test various attributes corresponding to preferences. The 'nextSync' attribute stores a millisecond timestamp rounded down to the nearest second. TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 92] 0 == 0 TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 94] 1275493471000 == 1275493471000 'syncInterval' defaults to singleDeviceInterval. TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 97] undefined == undefined TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 98] 86400000 == 86400000 'syncInterval' corresponds to a preference setting. TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 102] 2520000 == 2520000 TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 103] 2520000 == 2520000 'syncThreshold' corresponds to preference, defaults to SINGLE_USER_THRESHOLD TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 106] undefined == undefined TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 107] 1000 == 1000 TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 109] 3142 == 3142 'globalScore' corresponds to preference, defaults to zero. Skipping 2192 lines... Sync.Status INFO Resetting Status. Sync.Status DEBUG Status.service: service.client_not_configured => success.status_ok TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_loginError_fatal_clearsTriggers : 919] 0 == 0 TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_loginError_fatal_clearsTriggers : 920] null == null Sync.Status DEBUG Status.service: success.status_ok => success.status_ok TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_loginError_fatal_clearsTriggers : 921] success.status_ok == success.status_ok TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_loginError_fatal_clearsTriggers : 922] success.login == success.login Sync.SyncScheduler TRACE Requested sync should happen right away. TEST-INFO | (xpcshell/head.js) | test 2 finished Sync.Service DEBUG User-Agent: XPCShell/1 FxSync/1.13.0.20100621. Sync.Service INFO Starting sync at 2011-11-04 07:44:59 Sync.Service DEBUG In sync: should login. Sync.Service TRACE Event: weave:service:login:start Sync.Status DEBUG Status.service: success.status_ok => success.status_ok Sync.Status DEBUG Status.service: success.status_ok => success.status_ok Sync.Service INFO Logging in user johndoe Sync.Service TRACE Event: weave:service:verify-login:start Sync.Resource DEBUG mesg: GET fail 401 http://localhost:8080/1.1/johndoe/info/collections Sync.Resource DEBUG GET fail 401 http://localhost:8080/1.1/johndoe/info/collections Sync.Service WARN 401: login failed. Sync.Service DEBUG Finding cluster for user johndoe Sync.Resource DEBUG mesg: GET fail 500 https://auth.services.mozilla.com/user/1.0/johndoe/node/weave Sync.Resource DEBUG GET fail 500 https://auth.services.mozilla.com/user/1.0/johndoe/node/weave Sync.Service DEBUG verifyLogin failed: Unexpected response code: 500 No traceback available Sync.Status DEBUG Status.login: success.login => error.login.reason.network Sync.Status DEBUG Status.service: success.status_ok => error.login.failed Sync.Service TRACE Event: weave:service:verify-login:finish Sync.Service TRACE Event: weave:service:login:error Sync.SyncScheduler TRACE Handling weave:service:login:error Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. Sync.SyncScheduler TRACE _checkSync returned "". Sync.SyncScheduler DEBUG Next sync in 86400000 ms. Sync.Service DEBUG Exception: Login failed: error.login.reason.network No traceback available Sync.Service DEBUG Not syncing: login returned false. TEST-UNEXPECTED-FAIL | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | error.login.reason.network == error.login.reason.account - See following stack: JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/head.js :: do_throw :: line 453 JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/head.js :: _do_check_eq :: line 547 JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/head.js :: do_check_eq :: line 568 JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js :: aLittleBitAfterLoginError :: line 909 TEST-INFO | (xpcshell/head.js) | exiting test Sync.SyncScheduler TRACE Handling network:offline-status-changed Sync.SyncScheduler TRACE Network offline status change: offline Sync.SyncScheduler TRACE _checkSync returned "Network is offline". Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. ************************************************************ * Call to xpconnect wrapped JSObject produced this error: * [Exception... "'[JavaScript Error: "dumpn is not a function" {file: "/home/cltbld/talos-slave/test/build/firefox/components/httpd.js" line: 494}]' when calling method: [nsIRunnable::run]" nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)" location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0" data: yes] ************************************************************ WARNING: nsExceptionService ignoring thread destruction after shutdown: file /builds/slave/m-in-lnx64-dbg/build/xpcom/base/nsExceptionService.cpp, line 197 WARNING: OOPDeinit() without successful OOPInit(): file /builds/slave/m-in-lnx64-dbg/build/toolkit/crashreporter/nsExceptionHandler.cpp, line 1938 nsStringStats => mAllocCount: 17163 => mReallocCount: 1400 => mFreeCount: 17163 => mShareCount: 11967 => mAdoptCount: 1315 => mAdoptFreeCount: 1315 <<<<<<< TEST-INFO | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncstoragerequest.js | running test ... TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncstoragerequest.js | test passed (time: 5899.168ms)
https://tbpl.mozilla.org/php/getParsedLog.php?id=7208233&tree=Mozilla-Inbound Rev4 MacOSX Snow Leopard 10.6 mozilla-inbound debug test xpcshell on 2011-11-04 07:28:03 PDT for push dd25b9224c76 TEST-INFO | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncengine.js | running test ... TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncengine.js | test passed (time: 315.695ms) TEST-INFO | skipping /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncengine_sync.js | skip-if: (os == "mac" && debug) || os == "android" TEST-INFO | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | running test ... TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | test failed (with xpcshell return code: 0), see following log: >>>>>>> ### XPCOM_MEM_LEAK_LOG defined -- logging leaks to /var/folders/Hs/HsDn6a9SG8idoIya6p9mtE+++TI/-Tmp-/tmp3kKvPa/runxpcshelltests_leaks.log Setting the identity for passphrase TEST-INFO | (xpcshell/head.js) | test 1 pending TEST-INFO | (xpcshell/head.js) | test 2 pending TEST-INFO | (xpcshell/head.js) | test 2 finished TEST-INFO | (xpcshell/head.js) | running event loop Sync.SyncScheduler TRACE Handling weave:service:ready TEST-INFO | (xpcshell/head.js) | test 2 pending TEST-INFO | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | Starting test_prefAttributes Test various attributes corresponding to preferences. The 'nextSync' attribute stores a millisecond timestamp rounded down to the nearest second. TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 92] 0 == 0 TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 94] 1275493471000 == 1275493471000 'syncInterval' defaults to singleDeviceInterval. TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 97] undefined == undefined TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 98] 86400000 == 86400000 'syncInterval' corresponds to a preference setting. TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 102] 2520000 == 2520000 TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 103] 2520000 == 2520000 'syncThreshold' corresponds to preference, defaults to SINGLE_USER_THRESHOLD TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 106] undefined == undefined TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 107] 1000 == 1000 TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | [test_prefAttributes : 109] 3142 == 3142 'globalScore' corresponds to preference, defaults to zero. Skipping 2193 lines... TEST-INFO | (xpcshell/head.js) | test 2 finished Sync.Service DEBUG User-Agent: XPCShell/1 FxSync/1.13.0.20100621. Sync.Service INFO Starting sync at 2011-11-04 07:39:20 Sync.Service DEBUG In sync: should login. Sync.Service TRACE Event: weave:service:login:start Sync.Status DEBUG Status.service: success.status_ok => success.status_ok Sync.Status DEBUG Status.service: success.status_ok => success.status_ok Sync.Service INFO Logging in user johndoe Sync.Service TRACE Event: weave:service:verify-login:start Sync.Resource DEBUG mesg: GET fail 401 http://localhost:8080/1.1/johndoe/info/collections Sync.Resource DEBUG GET fail 401 http://localhost:8080/1.1/johndoe/info/collections Sync.Service WARN 401: login failed. Sync.Service DEBUG Finding cluster for user johndoe Sync.Resource DEBUG mesg: GET success 200 https://auth.services.mozilla.com/user/1.0/johndoe/node/weave Sync.Resource DEBUG GET success 200 https://auth.services.mozilla.com/user/1.0/johndoe/node/weave Sync.Service TRACE _findCluster successfully returning https://phx-sync434.services.mozilla.com/ Sync.Service DEBUG Cluster value = https://phx-sync434.services.mozilla.com/ Sync.Service DEBUG Setting cluster to https://phx-sync434.services.mozilla.com/ Sync.Service DEBUG Caching URLs under storage user base: https://phx-sync434.services.mozilla.com/1.1/johndoe/ Sync.Service TRACE Event: weave:service:verify-login:start Sync.Resource DEBUG mesg: GET fail 401 https://phx-sync434.services.mozilla.com/1.1/johndoe/info/collections Sync.Resource DEBUG GET fail 401 https://phx-sync434.services.mozilla.com/1.1/johndoe/info/collections Sync.Service WARN 401: login failed. Sync.Service DEBUG Finding cluster for user johndoe Sync.Resource DEBUG mesg: GET fail 500 https://auth.services.mozilla.com/user/1.0/johndoe/node/weave Sync.Resource DEBUG GET fail 500 https://auth.services.mozilla.com/user/1.0/johndoe/node/weave Sync.Service DEBUG verifyLogin failed: Unexpected response code: 500 No traceback available Sync.Status DEBUG Status.login: success.login => error.login.reason.network Sync.Status DEBUG Status.service: success.status_ok => error.login.failed Sync.Service TRACE Event: weave:service:verify-login:finish Sync.Service TRACE Event: weave:service:verify-login:finish Sync.Service TRACE Event: weave:service:login:error Sync.SyncScheduler TRACE Handling weave:service:login:error Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. Sync.SyncScheduler TRACE _checkSync returned "". Sync.SyncScheduler DEBUG Next sync in 86400000 ms. Sync.Service DEBUG Exception: Login failed: error.login.reason.network No traceback available Sync.Service DEBUG Not syncing: login returned false. TEST-UNEXPECTED-FAIL | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js | error.login.reason.network == error.login.reason.account - See following stack: JS frame :: /Users/cltbld/talos-slave/test/build/xpcshell/head.js :: do_throw :: line 453 JS frame :: /Users/cltbld/talos-slave/test/build/xpcshell/head.js :: _do_check_eq :: line 547 JS frame :: /Users/cltbld/talos-slave/test/build/xpcshell/head.js :: do_check_eq :: line 568 JS frame :: /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncscheduler.js :: aLittleBitAfterLoginError :: line 909 TEST-INFO | (xpcshell/head.js) | exiting test !!! error running onStopped callback: TypeError: callback is not a function Sync.SyncScheduler TRACE Handling network:offline-status-changed Sync.SyncScheduler TRACE Network offline status change: offline Sync.SyncScheduler TRACE _checkSync returned "Network is offline". Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. WARNING: nsExceptionService ignoring thread destruction after shutdown: file /builds/slave/m-in-osx64-dbg/build/xpcom/base/nsExceptionService.cpp, line 197 WARNING: OOPDeinit() without successful OOPInit(): file /builds/slave/m-in-osx64-dbg/build/toolkit/crashreporter/nsExceptionHandler.cpp, line 1938 nsStringStats => mAllocCount: 17701 => mReallocCount: 1471 => mFreeCount: 17701 => mShareCount: 12344 => mAdoptCount: 1258 => mAdoptFreeCount: 1258 <<<<<<< TEST-INFO | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncstoragerequest.js | running test ... TEST-PASS | /Users/cltbld/talos-slave/test/build/xpcshell/tests/services/sync/tests/unit/test_syncstoragerequest.js | test passed (time: 5395.217ms)
This is just like Bug 700051 / Bug 700071, so I applied the same fix and pushed to Inbound: https://hg.mozilla.org/integration/mozilla-inbound/rev/52c70934f6f2 If we're happy with these two fixes, and this orange doesn't recur, then we should probably land on Aurora and Beta to avoid further spurious orange…
Assignee: nobody → rnewman
Status: NEW → ASSIGNED
Whiteboard: [orange] → [orange][inbound]
https://hg.mozilla.org/mozilla-central/rev/52c70934f6f2 hoping this is fixed, can be reopened if it still happens.
Status: ASSIGNED → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla10
Whiteboard: [orange][inbound] → [inbound]
You need to log in before you can comment on or make changes to this bug.