1458179 - Intermittent toolkit/components/normandy/test/browser/browser_AddonStudies.js | Uncaught exception - ConstraintError: A mutation operation in the transaction failed because a constraint was not satisfied. For example, an object such as an object store or

Status: RESOLVED INCOMPLETE

(Firefox :: Normandy Client, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=176363886&repo=mozilla-inbound

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

[task 2018-04-30T23:31:02.105Z] 23:31:02     INFO - TEST-START | toolkit/components/normandy/test/browser/browser_AddonStudies.js
[task 2018-04-30T23:31:02.315Z] 23:31:02     INFO - GECKO(14073) | ++DOMWINDOW == 2 (0x7fe23b25ac00) [pid = 14227] [serial = 2] [outer = 0x7fe23b1bcc00]
[task 2018-04-30T23:31:02.776Z] 23:31:02     INFO - GECKO(14073) | --DOMWINDOW == 17 (0x7fab5fbbac00) [pid = 14073] [serial = 15] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:02.779Z] 23:31:02     INFO - GECKO(14073) | --DOMWINDOW == 16 (0x7fab6b2b3400) [pid = 14073] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:02.780Z] 23:31:02     INFO - GECKO(14073) | --DOMWINDOW == 15 (0x7fab5fbb8800) [pid = 14073] [serial = 12] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:02.781Z] 23:31:02     INFO - GECKO(14073) | --DOMWINDOW == 14 (0x7fab5fbb8000) [pid = 14073] [serial = 11] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:03.081Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:03.082Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:03.083Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:03.313Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:03.314Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:03.315Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:03.547Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:03.547Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:03.548Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:03.939Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:03.940Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:03.941Z] 23:31:03     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:04.345Z] 23:31:04     INFO - GECKO(14073) | --DOMWINDOW == 3 (0x7ff4f3686400) [pid = 14125] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:04.345Z] 23:31:04     INFO - GECKO(14073) | --DOMWINDOW == 2 (0x7ff4f3693800) [pid = 14125] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:04.387Z] 23:31:04     INFO - GECKO(14073) | [Parent 14073, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 338
[task 2018-04-30T23:31:04.754Z] 23:31:04     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:04.757Z] 23:31:04     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:05.318Z] 23:31:05     INFO - GECKO(14073) | --DOMWINDOW == 13 (0x7fab6144bc00) [pid = 14073] [serial = 7] [outer = (nil)] [url = about:blank]
[task 2018-04-30T23:31:05.340Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 338
[task 2018-04-30T23:31:05.551Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:05.553Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:05.627Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:05.628Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:05.629Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:05.710Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, StreamTrans #8] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 417
[task 2018-04-30T23:31:05.746Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:05.747Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:05.748Z] 23:31:05     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:06.248Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 338
[task 2018-04-30T23:31:06.433Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:06.433Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:06.481Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:06.483Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:06.484Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:06.593Z] 23:31:06     INFO - GECKO(14073) | monitorConsole | [0] did not match {"message":"1525131066582\tapp.normandy.addon-studies\tWARN\tStudy Test study ending for unknown reason.","errorMessage":null,"sourceName":null,"sourceLine":null,"lineNumber":null,"columnNumber":null,"category":null,"windowID":null,"isScriptError":false,"isConsoleEvent":false,"isWarning":false,"isException":false,"isStrict":false}
[task 2018-04-30T23:31:06.602Z] 23:31:06     INFO - GECKO(14073) | monitorConsole | [0] matched {"message":"1525131066592\tapp.normandy.addon-studies\tWARN\tCould not uninstall addon [e-mail] for recipe 9:: Error: No addon with ID [[e-mail]] found. (resource://normandy/lib/Addons.jsm:100:13) JS Stack trace: [e-mail]:100:13\nasync*[e-mail]:350:13\nasync*testStopWarn/<@browser_AddonStudies.js:303:7\ntestStopWarn@browser_AddonStudies.js:300:11\nasync*[e-mail]:136:39\nAsync*Tester_execTest/<@browser-test.js:1078:34\nasync*[e-mail]:1069:16\nnextTest/<@browser-test.js:965:9\nSimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@SimpleTest.js:795:59","errorMessage":null,"sourceName":null,"sourceLine":null,"lineNumber":null,"columnNumber":null,"category":null,"windowID":null,"isScriptError":false,"isConsoleEvent":false,"isWarning":false,"isException":false,"isStrict":false}
[task 2018-04-30T23:31:06.618Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageConnection.cpp, line 756
[task 2018-04-30T23:31:06.619Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file /builds/worker/workspace/build/src/storage/mozStorageService.cpp, line 713
[task 2018-04-30T23:31:06.620Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: Received NS_ERROR_STORAGE_BUSY when attempting to open database '3561288849sdhlie.sqlite', retrying for up to 10 seconds: file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 4441
[task 2018-04-30T23:31:06.857Z] 23:31:06     INFO - GECKO(14073) | [Parent 14073, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 338
[task 2018-04-30T23:31:07.040Z] 23:31:07     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:07.041Z] 23:31:07     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:07.064Z] 23:31:07     INFO - TEST-INFO | started process screentopng
[task 2018-04-30T23:31:07.492Z] 23:31:07     INFO - TEST-INFO | screentopng: exit 0
[task 2018-04-30T23:31:07.492Z] 23:31:07     INFO - Buffered messages logged at 23:31:02
[task 2018-04-30T23:31:07.499Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.500Z] 23:31:07     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 170}]
[task 2018-04-30T23:31:07.500Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | get returns null when the requested study does not exist - 
[task 2018-04-30T23:31:07.501Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.502Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.504Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | get retrieved a study from storage. - {"recipeId":0,"name":"test-study","description":"fake","active":true,"addonId":"[e-mail]","addonUrl":"http://test/addon.xpi","addonVersion":"1.0.0","studyStartDate":"2018-04-30T23:31:02.606Z"} deepEqual {"recipeId":0,"name":"test-study","description":"fake","active":true,"addonId":"[e-mail]","addonUrl":"http://test/addon.xpi","addonVersion":"1.0.0","studyStartDate":"2018-04-30T23:31:02.606Z"} - 
[task 2018-04-30T23:31:07.505Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.507Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.508Z] 23:31:07     INFO - Buffered messages logged at 23:31:03
[task 2018-04-30T23:31:07.509Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | getAll returns every stored study. - {} deepEqual {} - 
[task 2018-04-30T23:31:07.516Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.517Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.519Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | has returns true for a study that exists in storage. - 
[task 2018-04-30T23:31:07.520Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | has returns false for a study that doesn't exist in storage. - 
[task 2018-04-30T23:31:07.522Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.526Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.528Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.534Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.535Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | Before calling clear, both studies are in storage. - 
[task 2018-04-30T23:31:07.537Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | After calling clear, all studies are removed from storage. - 
[task 2018-04-30T23:31:07.538Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.539Z] 23:31:07     INFO - Entering test bound testStartRequiredArguments
[task 2018-04-30T23:31:07.541Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when missing required argument recipeId. - 
[task 2018-04-30T23:31:07.542Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when missing required argument name. - 
[task 2018-04-30T23:31:07.543Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when missing required argument description. - 
[task 2018-04-30T23:31:07.545Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when missing required argument addonUrl. - 
[task 2018-04-30T23:31:07.546Z] 23:31:07     INFO - Leaving test bound testStartRequiredArguments
[task 2018-04-30T23:31:07.547Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.553Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when a study exists with the given recipeId already. - 
[task 2018-04-30T23:31:07.555Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.556Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.557Z] 23:31:07     INFO - Buffered messages logged at 23:31:04
[task 2018-04-30T23:31:07.558Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | sendEvent(enrollFailed, addon_study, Test, {"reason":"fake/filename.js:42:54 Error"}) should match spec - 
[task 2018-04-30T23:31:07.560Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when the Addons.applyInstall function rejects - 
[task 2018-04-30T23:31:07.561Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | If something fails during start after the add-on is installed, it is uninstalled. - 
[task 2018-04-30T23:31:07.563Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | AddonStudies.start() should send an enroll-failed event when applyInstall rejects - ["enrollFailed","addon_study","Test",{"reason":"fake/filename.js:42:54 Error"}] deepEqual ["enrollFailed","addon_study","Test",{"reason":"fake/filename.js:42:54 Error"}] - 
[task 2018-04-30T23:31:07.564Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.565Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.566Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start rejects when the study add-on is already installed - 
[task 2018-04-30T23:31:07.573Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.574Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.575Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | Before start is called, the add-on is not installed. - 
[task 2018-04-30T23:31:07.581Z] 23:31:07     INFO - Buffered messages logged at 23:31:05
[task 2018-04-30T23:31:07.582Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | sendEvent(enroll, addon_study, Test Study, {"addonId":"[e-mail]","addonVersion":"2.0"}) should match spec - 
[task 2018-04-30T23:31:07.583Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | After start is called, the add-on is installed. - 
[task 2018-04-30T23:31:07.586Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start saves study data to storage - {"recipeId":5,"name":"Test Study","description":"Test Desc","addonId":"[e-mail]","addonVersion":"2.0","addonUrl":"file:///tmp/generated-extension.xpi","active":true,"studyStartDate":"2018-04-30T23:31:04.864Z"} deepEqual {"recipeId":5,"name":"Test Study","description":"Test Desc","addonId":"[e-mail]","addonVersion":"2.0","addonUrl":"file:///tmp/generated-extension.xpi","active":true,"studyStartDate":"2018-04-30T23:31:04.864Z"} - 
[task 2018-04-30T23:31:07.588Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | start assigns a value to the study start date. - 
[task 2018-04-30T23:31:07.589Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | AddonStudies.start() should send the correct telemetry event - ["enroll","addon_study","Test Study",{"addonId":"[e-mail]","addonVersion":"2.0"}] deepEqual ["enroll","addon_study","Test Study",{"addonId":"[e-mail]","addonVersion":"2.0"}] - 
[task 2018-04-30T23:31:07.591Z] 23:31:07     INFO - Console message: 1525131065458	app.normandy.addon-studies	WARN	Study Test Study ending for unknown reason.
[task 2018-04-30T23:31:07.593Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | sendEvent(unenroll, addon_study, Test Study, {"addonId":"[e-mail]","addonVersion":"2.0","reason":"unknown"}) should match spec - 
[task 2018-04-30T23:31:07.597Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.598Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.600Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | stop rejects when no study exists for the given recipe. - 
[task 2018-04-30T23:31:07.601Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.602Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.603Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | stop rejects when the requested study is already inactive. - 
[task 2018-04-30T23:31:07.604Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.605Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.607Z] 23:31:07     INFO - Buffered messages logged at 23:31:06
[task 2018-04-30T23:31:07.608Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | sendEvent(unenroll, addon_study, Test study, {"addonId":"[e-mail]","addonVersion":"1.0.0","reason":"test-reason"}) should match spec - 
[task 2018-04-30T23:31:07.609Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | stop marks the study as inactive. - 
[task 2018-04-30T23:31:07.610Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | stop saves the study end date. - 
[task 2018-04-30T23:31:07.611Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | stop uninstalls the study add-on. - 
[task 2018-04-30T23:31:07.613Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | stop should send the correct telemetry event - ["unenroll","addon_study","Test study",{"addonId":"[e-mail]","addonVersion":"1.0.0","reason":"test-reason"}] deepEqual ["unenroll","addon_study","Test study",{"addonId":"[e-mail]","addonVersion":"1.0.0","reason":"test-reason"}] - 
[task 2018-04-30T23:31:07.613Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.614Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.614Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | Before start is called, the add-on is not installed. - 
[task 2018-04-30T23:31:07.615Z] 23:31:07     INFO - Console message: 1525131066582	app.normandy.addon-studies	WARN	Study Test study ending for unknown reason.
[task 2018-04-30T23:31:07.617Z] 23:31:07     INFO - Console message: 1525131066592	app.normandy.addon-studies	WARN	Could not uninstall addon [e-mail] for recipe 9:: Error: No addon with ID [[e-mail]] found. (resource://normandy/lib/Addons.jsm:100:13) JS Stack trace: [e-mail]:100:13
[task 2018-04-30T23:31:07.620Z] 23:31:07     INFO - async*[e-mail]:350:13
[task 2018-04-30T23:31:07.622Z] 23:31:07     INFO - async*testStopWarn/<@browser_AddonStudies.js:303:7
[task 2018-04-30T23:31:07.624Z] 23:31:07     INFO - testStopWarn@browser_AddonStudies.js:300:11
[task 2018-04-30T23:31:07.625Z] 23:31:07     INFO - async*[e-mail]:136:39
[task 2018-04-30T23:31:07.625Z] 23:31:07     INFO - Async*Tester_execTest/<@browser-test.js:1078:34
[task 2018-04-30T23:31:07.626Z] 23:31:07     INFO - async*[e-mail]:1069:16
[task 2018-04-30T23:31:07.626Z] 23:31:07     INFO - nextTest/<@browser-test.js:965:9
[task 2018-04-30T23:31:07.627Z] 23:31:07     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@SimpleTest.js:795:59
[task 2018-04-30T23:31:07.627Z] 23:31:07     INFO - Console message: SENTINEL
[task 2018-04-30T23:31:07.628Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | monitorConsole | number of messages [{message:/Could not uninstall addon/}] - 
[task 2018-04-30T23:31:07.628Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.629Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.630Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | sendEvent(unenroll, addon_study, Test study, {"addonId":"[e-mail]","addonVersion":"1.0.0","reason":"uninstalled-sideload"}) should match spec - 
[task 2018-04-30T23:31:07.631Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | init marks studies as inactive if their add-on is not installed. - 
[task 2018-04-30T23:31:07.632Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | init sets the study end date if a study's add-on is not installed. - 
[task 2018-04-30T23:31:07.633Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | AddonStudies.init() should send the correct telemetry event - ["unenroll","addon_study","Test study",{"addonId":"[e-mail]","addonVersion":"1.0.0","reason":"uninstalled-sideload"}] deepEqual ["unenroll","addon_study","Test study",{"addonId":"[e-mail]","addonVersion":"1.0.0","reason":"uninstalled-sideload"}] - 
[task 2018-04-30T23:31:07.634Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | init does not modify inactive studies. - 
[task 2018-04-30T23:31:07.635Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | init does not modify studies whose add-on is still installed. - {"recipeId":11,"name":"Test study","description":"fake","active":true,"addonId":"[e-mail]","addonUrl":"http://test/addon.xpi","addonVersion":"1.0.0","studyStartDate":"2018-04-30T23:31:02.622Z"} deepEqual {"recipeId":11,"name":"Test study","description":"fake","active":true,"addonId":"[e-mail]","addonUrl":"http://test/addon.xpi","addonVersion":"1.0.0","studyStartDate":"2018-04-30T23:31:02.622Z"} - 
[task 2018-04-30T23:31:07.636Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | no extra events should be generated - 
[task 2018-04-30T23:31:07.637Z] 23:31:07     INFO - Buffered messages finished
[task 2018-04-30T23:31:07.638Z] 23:31:07     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/normandy/test/browser/browser_AddonStudies.js | Uncaught exception - ConstraintError: A mutation operation in the transaction failed because a constraint was not satisfied. For example, an object such as an object store or index already exists and a new one was being attempted to be created.
[task 2018-04-30T23:31:07.639Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction
[task 2018-04-30T23:31:07.640Z] 23:31:07     INFO - Entering test bound wrappedTestFunction
[task 2018-04-30T23:31:07.640Z] 23:31:07     INFO - GECKO(14073) | JavaScript error: , line 0: uncaught exception: null
[task 2018-04-30T23:31:07.641Z] 23:31:07     INFO - Console message: [JavaScript Error: "uncaught exception: null"]
[task 2018-04-30T23:31:07.642Z] 23:31:07     INFO - GECKO(14073) | [Parent 14073, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 338
[task 2018-04-30T23:31:07.643Z] 23:31:07     INFO - GECKO(14073) | --DOCSHELL 0x7f916d2e4800 == 0 [pid = 14193] [id = {4132a3a5-acb5-401b-b284-598d89d5c197}]
[task 2018-04-30T23:31:07.644Z] 23:31:07     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:07.645Z] 23:31:07     INFO - GECKO(14073) | [Parent 14073, QuotaManager IO] WARNING: 'NS_FAILED( directory->GetDirectoryEntries(getter_AddRefs(entries)))', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 7411
[task 2018-04-30T23:31:07.646Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | Studies are marked as inactive when their add-on is uninstalled. - 
[task 2018-04-30T23:31:07.647Z] 23:31:07     INFO - TEST-PASS | toolkit/components/normandy/test/browser/browser_AddonStudies.js | The study end date is set when the add-on for the study is uninstalled. - 
[task 2018-04-30T23:31:07.667Z] 23:31:07     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-04-30T23:31:07.668Z] 23:31:07     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/normandy/test/browser/browser_AddonStudies.js | A promise chain failed to handle a rejection: (Unable to convert rejection reason to string.) - stack: Transaction/this._completionPromise</transaction.onerror@resource://gre/modules/IndexedDB.jsm:207:9
[task 2018-04-30T23:31:07.671Z] 23:31:07     INFO - EventHandlerNonNull*Transaction/this._completionPromise<@resource://gre/modules/IndexedDB.jsm:206:7
[task 2018-04-30T23:31:07.671Z] 23:31:07     INFO - Transaction@resource://gre/modules/IndexedDB.jsm:204:31
[task 2018-04-30T23:31:07.673Z] 23:31:07     INFO - transaction@resource://gre/modules/IndexedDB.jsm:289:23
[task 2018-04-30T23:31:07.674Z] 23:31:07     INFO - objectStore@resource://gre/modules/IndexedDB.jsm:317:23
[task 2018-04-30T23:31:07.675Z] 23:31:07     INFO - getStore@resource://normandy/lib/AddonStudies.jsm:87:10
[task 2018-04-30T23:31:07.676Z] 23:31:07     INFO - wrappedTestFunction@resource://normandy/lib/AddonStudies.jsm:141:19
[task 2018-04-30T23:31:07.676Z] 23:31:07     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1078:34
[task 2018-04-30T23:31:07.677Z] 23:31:07     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1069:16
[task 2018-04-30T23:31:07.678Z] 23:31:07     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:965:9
[task 2018-04-30T23:31:07.679Z] 23:31:07     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
[task 2018-04-30T23:31:07.680Z] 23:31:07     INFO - Rejection date: Mon Apr 30 2018 23:31:07 GMT+0000 (UTC) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 257
[task 2018-04-30T23:31:07.681Z] 23:31:07     INFO - Stack trace:
[task 2018-04-30T23:31:07.682Z] 23:31:07     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
[task 2018-04-30T23:31:07.683Z] 23:31:07     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1103
[task 2018-04-30T23:31:07.684Z] 23:31:07     INFO - Leaving test bound wrappedTestFunction

Comment 1

[Intermittent Failures Robot]

1 failures in 551 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1

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

Comment 2

[Emma Humphries ☕️🎸🧞‍♀️✨ (she/they) [:emceeaich] (Pacific Time) use needinfo]

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