Closed
Bug 1454666
Opened 7 years ago
Closed 7 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | dom/push/test/xpcshell/test_register_5xxCode_http2.js | Test timed out
Categories
(Core :: DOM: Push Subscriptions, defect, P5)
Core
DOM: Push Subscriptions
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: csabou [at] mozilla.com
https://treeherder.mozilla.org/logviewer.html#?job_id=174095273&repo=mozilla-inbound
https://queue.taskcluster.net/v1/task/JXHhWwXBQ3moD9NynwtY8g/runs/0/artifacts/public/logs/live_backing.log
13:30:48 INFO - TEST-START | dom/push/test/xpcshell/test_register_5xxCode_http2.js
13:35:48 WARNING - TEST-UNEXPECTED-TIMEOUT | dom/push/test/xpcshell/test_register_5xxCode_http2.js | Test timed out
13:35:48 INFO - TEST-INFO took 300000ms
13:35:48 INFO - >>>>>>>
13:35:48 INFO - PID 3960 | JavaScript strict warning: resource://gre/modules/PushService.jsm, line 18: ReferenceError: reference to undefined property "getCryptoParams"
13:35:48 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
13:35:48 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
13:35:48 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
13:35:48 INFO - running event loop
13:35:48 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "getCryptoParams"" {file: "resource://gre/modules/PushService.jsm" line: 18}]"
13:35:48 INFO - dom/push/test/xpcshell/test_register_5xxCode_http2.js | Starting test1
13:35:48 INFO - (xpcshell/head.js) | test test1 pending (2)
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | PushDB()
13:35:48 INFO - (xpcshell/head.js) | test pending (3)
13:35:48 INFO - (xpcshell/head.js) | test pending (4)
13:35:48 INFO - (xpcshell/head.js) | test pending (5)
13:35:48 INFO - (xpcshell/head.js) | test pending (6)
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | init()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | setState()
13:35:48 INFO - PID 3960 | new state
13:35:48 INFO - PID 3960 | 2
13:35:48 INFO - PID 3960 | old state
13:35:48 INFO - PID 3960 | 0
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | register()
13:35:48 INFO - PID 3960 | Object
13:35:48 INFO - PID 3960 | - scope = https://example.com/retry5xxCode
13:35:48 INFO - PID 3960 | - originAttributes =
13:35:48 INFO - (xpcshell/head.js) | test run_next_test 0 finished (6)
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | changeServerURL()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | findService()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | startService()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | init()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | startObservers()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | dropExpiredRegistrations()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getAllExpired()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getAllByPushQuota()
13:35:48 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | changeStateConnectionEnabledEvent()
13:35:48 INFO - PID 3960 | true
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | changeStateOfflineEvent()
13:35:48 INFO - PID 3960 | false
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getAllUnexpired()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getAllByPushQuota()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | setState()
13:35:48 INFO - PID 3960 | new state
13:35:48 INFO - PID 3960 | 5
13:35:48 INFO - PID 3960 | old state
13:35:48 INFO - PID 3960 | 2
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getByIdentifiers()
13:35:48 INFO - PID 3960 | Object
13:35:48 INFO - PID 3960 | - scope = https://example.com/retry5xxCode
13:35:48 INFO - PID 3960 | - originAttributes =
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | registerWithServer()
13:35:48 INFO - PID 3960 | Object
13:35:48 INFO - PID 3960 | - scope = https://example.com/retry5xxCode
13:35:48 INFO - PID 3960 | - originAttributes =
13:35:48 INFO - PID 3960 | - appServerKey = null
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | subscribeResource()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | subscribeResourceInternal()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | SubscriptionListener()
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 21] Subscribe 5xx code - true == true
13:35:48 INFO - (xpcshell/head.js) | test finished (5)
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | SubscriptionListener: onStopRequest()
13:35:48 INFO - PID 3960 | JavaScript error: resource://gre/modules/PushServiceHttp2.jsm, line 772: TypeError: this._listenersPendingRetry.remove is not a function
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | subscribeResourceInternal()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | SubscriptionListener()
13:35:48 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "TypeError: this._listenersPendingRetry.remove is not a function" {file: "resource://gre/modules/PushServiceHttp2.jsm" line: 772}]"
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 26] Subscribed - true == true
13:35:48 INFO - (xpcshell/head.js) | test finished (4)
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | SubscriptionListener: onStopRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | onStopRequest: subscriptionUri
13:35:48 INFO - PID 3960 | http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | linkParser: pushEndpoint
13:35:48 INFO - PID 3960 | /pushEndpoint
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | linkParser: pushReceiptEndpoint
13:35:48 INFO - PID 3960 | /receiptPushEndpoint
13:35:48 INFO - PID 3960 | JavaScript strict warning: resource://gre/modules/PushRecord.jsm, line 39: ReferenceError: reference to undefined property "quota"
13:35:48 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "quota"" {file: "resource://gre/modules/PushRecord.jsm" line: 39}]"
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | listenForMsgs()
13:35:48 INFO - PID 3960 | http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener()
13:35:48 INFO - PID 3960 | console.debug: PushService:
13:35:48 INFO - PID 3960 | _onRegisterSuccess()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | put()
13:35:48 INFO - PID 3960 | Object
13:35:48 INFO - PID 3960 | - pushEndpoint = http://localhost:65295/pushEndpoint
13:35:48 INFO - PID 3960 | - scope = https://example.com/retry5xxCode
13:35:48 INFO - PID 3960 | - originAttributes =
13:35:48 INFO - PID 3960 | - pushCount = 0
13:35:48 INFO - PID 3960 | - lastPush = 0
13:35:48 INFO - PID 3960 | - p256dhPublicKey = ArrayBuffer {}
13:35:48 INFO - PID 3960 | - p256dhPrivateKey = {"crv":"P-256","d":"apiEP-08yT1QZywgnEtKM4-vG5_k48-zxAz5Q7MQN-k","ext":true,"key_ops":["deriveBits"],"kty":"EC","x":"clysfArxAvftvL75y5yEpI58YDGEZcsGX6QQGcTYuJI","y":"h1_6rQtDDjLaDKK56OZHvzJ5F5Uo58tnzEkDpJ6MaMA"}
13:35:48 INFO - PID 3960 | - authenticationSecret = Uint8Array {"0":65,"1":30,"2":26,"3":99,"4":200,"5":204,"6":49,"7":207,"8":118,"9":164,"10":186,"11":132,"12":3,"13":179,"14":115,"15":225}
13:35:48 INFO - PID 3960 | - systemRecord = false
13:35:48 INFO - PID 3960 | - appServerKey = null
13:35:48 INFO - PID 3960 | - recentMessageIDs = undefined
13:35:48 INFO - PID 3960 | - quota = 16
13:35:48 INFO - PID 3960 | - ctime = 1523971850131
13:35:48 INFO - PID 3960 | - subscriptionUri = http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | - pushReceiptEndpoint = http://localhost:65295/receiptPushEndpoint
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | put: Request successful. Updated record
13:35:48 INFO - PID 3960 | http://localhost:65295/subscription
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 95] Wrong push endpoint in registration record - "http://localhost:65295/pushEndpoint" == "http://localhost:65295/pushEndpoint"
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 98] Wrong push endpoint receipt in registration record - "http://localhost:65295/receiptPushEndpoint" == "http://localhost:65295/receiptPushEndpoint"
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getByKeyID()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getByKeyID: Got record
13:35:48 INFO - PID 3960 | Object
13:35:48 INFO - PID 3960 | - pushEndpoint = http://localhost:65295/pushEndpoint
13:35:48 INFO - PID 3960 | - scope = https://example.com/retry5xxCode
13:35:48 INFO - PID 3960 | - originAttributes =
13:35:48 INFO - PID 3960 | - pushCount = 0
13:35:48 INFO - PID 3960 | - lastPush = 0
13:35:48 INFO - PID 3960 | - p256dhPublicKey = ArrayBuffer {}
13:35:48 INFO - PID 3960 | - p256dhPrivateKey = {"crv":"P-256","d":"apiEP-08yT1QZywgnEtKM4-vG5_k48-zxAz5Q7MQN-k","ext":true,"key_ops":["deriveBits"],"kty":"EC","x":"clysfArxAvftvL75y5yEpI58YDGEZcsGX6QQGcTYuJI","y":"h1_6rQtDDjLaDKK56OZHvzJ5F5Uo58tnzEkDpJ6MaMA"}
13:35:48 INFO - PID 3960 | - authenticationSecret = Uint8Array {"0":65,"1":30,"2":26,"3":99,"4":200,"5":204,"6":49,"7":207,"8":118,"9":164,"10":186,"11":132,"12":3,"13":179,"14":115,"15":225}
13:35:48 INFO - PID 3960 | - systemRecord = false
13:35:48 INFO - PID 3960 | - appServerKey = null
13:35:48 INFO - PID 3960 | - recentMessageIDs = undefined
13:35:48 INFO - PID 3960 | - quota = 16
13:35:48 INFO - PID 3960 | - ctime = 1523971850131
13:35:48 INFO - PID 3960 | - subscriptionUri = http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | - pushReceiptEndpoint = http://localhost:65295/receiptPushEndpoint
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 102] Wrong subscription ID in database record - "http://localhost:65295/subscription" == "http://localhost:65295/subscription"
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 104] Wrong push endpoint in database record - "http://localhost:65295/pushEndpoint" == "http://localhost:65295/pushEndpoint"
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 106] Wrong push endpoint receipt in database record - "http://localhost:65295/receiptPushEndpoint" == "http://localhost:65295/receiptPushEndpoint"
13:35:48 INFO - TEST-PASS | dom/push/test/xpcshell/test_register_5xxCode_http2.js | test1 - [test1 : 108] Wrong scope in database record - "https://example.com/retry5xxCode" == "https://example.com/retry5xxCode"
13:35:48 INFO - (xpcshell/head.js) | test run_next_test 1 pending (4)
13:35:48 INFO - (xpcshell/head.js) | test test1 finished (4)
13:35:48 INFO - (xpcshell/head.js) | test run_next_test 1 finished (3)
13:35:48 INFO - (xpcshell/head.js) | test finished (2)
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener: onStartRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener: onStopRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | connOnStop() succeeded
13:35:48 INFO - PID 3960 | false
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | retryAfterBackoff()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | retryAfterBackoff: Retry in
13:35:48 INFO - PID 3960 | 1091.43267591788
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | listenForMsgs()
13:35:48 INFO - PID 3960 | http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener: onStartRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener: onStopRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | connOnStop() succeeded
13:35:48 INFO - PID 3960 | false
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | retryAfterBackoff()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | retryAfterBackoff: Retry in
13:35:48 INFO - PID 3960 | 1863.1708471383442
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | listenForMsgs()
13:35:48 INFO - PID 3960 | http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener: onStartRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | PushSubscriptionListener: onStopRequest()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | connOnStop() succeeded
13:35:48 INFO - PID 3960 | false
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | retryAfterBackoff()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | shutdownSubscriptions()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getByKeyID()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | getByKeyID: Got record
13:35:48 INFO - PID 3960 | Object
13:35:48 INFO - PID 3960 | - pushEndpoint = http://localhost:65295/pushEndpoint
13:35:48 INFO - PID 3960 | - scope = https://example.com/retry5xxCode
13:35:48 INFO - PID 3960 | - originAttributes =
13:35:48 INFO - PID 3960 | - pushCount = 0
13:35:48 INFO - PID 3960 | - lastPush = 0
13:35:48 INFO - PID 3960 | - p256dhPublicKey = ArrayBuffer {}
13:35:48 INFO - PID 3960 | - p256dhPrivateKey = {"crv":"P-256","d":"apiEP-08yT1QZywgnEtKM4-vG5_k48-zxAz5Q7MQN-k","ext":true,"key_ops":["deriveBits"],"kty":"EC","x":"clysfArxAvftvL75y5yEpI58YDGEZcsGX6QQGcTYuJI","y":"h1_6rQtDDjLaDKK56OZHvzJ5F5Uo58tnzEkDpJ6MaMA"}
13:35:48 INFO - PID 3960 | - authenticationSecret = Uint8Array {"0":65,"1":30,"2":26,"3":99,"4":200,"5":204,"6":49,"7":207,"8":118,"9":164,"10":186,"11":132,"12":3,"13":179,"14":115,"15":225}
13:35:48 INFO - PID 3960 | - systemRecord = false
13:35:48 INFO - PID 3960 | - appServerKey = null
13:35:48 INFO - PID 3960 | - recentMessageIDs = undefined
13:35:48 INFO - PID 3960 | - quota = 16
13:35:48 INFO - PID 3960 | - ctime = 1523971850131
13:35:48 INFO - PID 3960 | - subscriptionUri = http://localhost:65295/subscription
13:35:48 INFO - PID 3960 | - pushReceiptEndpoint = http://localhost:65295/receiptPushEndpoint
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | subscribeResource()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | subscribeResourceInternal()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | SubscriptionListener()
13:35:48 INFO - PID 3960 | console.debug: PushServiceHttp2:
13:35:48 INFO - PID 3960 | SubscriptionListener: onStopRequest()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | delete()
13:35:48 INFO - PID 3960 | console.debug: PushDB:
13:35:48 INFO - PID 3960 | delete: Removing record
13:35:48 INFO - PID 3960 | http://localhost:65295/subscription
13:35:48 INFO - <<<<<<<
13:35:48 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 3960: error 5
13:35:48 INFO - xpcshell return code: None
13:35:48 INFO - dom/push/test/xpcshell/test_register_5xxCode_http2.js | Process still running after test!
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•7 years ago
|
||
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•