1848386 - Implement telemetry for shopping network request success/failure details

Status: RESOLVED FIXED

(Firefox :: Shopping, task, P3)

Description

[:Gijs (he/him)]

We'll want to record things like:

0. OHTTP gateway config fetching success/failure
1. HTTP status codes for outer (OHTTP) requests and inner requests (maybe OHTTP succeeds but the eventual server of the actual response returns errors).
2. bogus responses from the server (ie 200 OK but the JSON isn't valid, doesn't match schema, or other issues with its content)
3. timeouts
4. request cancellations because the user navigated before we got a response

for the product + recommendation/ad requests. We may want some of these for the image request as well.

Given that the other data collection for this project is using Glean, I guess we should use Glean here, too. The data needs for this bug should be the same for Desktop and Android. Based on this, I think we should be using a toolkit/components/shopping/ metrics yaml file that ends up in gecko_metrics. But the existing yaml file there only records desktop data relating to the desktop nimbus and onboarding work, and is in firefox_desktop_metrics. I'm not sure how best to resolve this - I thought we could just move the existing toolkit metrics file to the browser/components/shopping directory (as the probes are only recorded to from browser/ code anyway) and add a different one in the original toolkit location that does get put in gecko_metrics, but conversation on slack suggests that maybe this isn't the best solution. :chutten, can you help?

Comment 1

[Chris H-C :chutten]

The downstream effects of changing which definitions files are included in which products can be subtle, but nothing you suggest should be a problem. Just be sure to add one of us to the review so we can work through the ramifications before it lands.

Also note that another solution could be to have multiple definitions files in the same folder. This is a relatively-new relaxing of previous rules that required they be called metrics.yaml: now we could have shared_metrics.yaml and put that in gecko_metrics and leave the other as it is, if you wanted.

Comment 2

[Perry McManis [:perry.mcmanis]]

Another possibility is that the toolkit metrics.yaml file can be used for your needs, and I can move the shopping_settings to a completely new file without the need to have differing names or really even do that much updating.

There's going to be a need to check that we can move without issue. If we want to move it, we will, but we of course don't want to explode anything in the process. I am going to start that effort on Monday morning so we can support getting the current metrics.yaml relocated at a minimum, but we can pursue the other approach I outlined if that sounds appealing.

Comment 3

[Jared Hirsch [:jhirsch] (PTO, back 5/28) (he/him) (Needinfo please)]

Moving open telemetry bugs into the general shopping backlog

Comment 4

[Fred Chasen [:fchasen]]

Attachment: Bug 1848386 - Add reporting for Shopping request failures. r=#shopping-reviewers

Comment 5

[Fred Chasen [:fchasen]]

Attachment: Bug 1848386 - Add reporting for Shopping request failures. r=#shopping-reviewers

• Adds shopping.requestFailure to Glean for reporting requests to the Fakespot API that fail.
• Updates how errors from the analysis status are passed so that we don't report those API responses as request failures.

Comment 6

[Perry McManis [:perry.mcmanis]]

Attachment: Data Review request

Comment 7

[Travis Long [:travis_]]

Comment on attachment 9372242 [details]
Data Review request

Data Review

1. Is there or will there be documentation that describes the schema for the ultimate data set in a public, complete, and accurate way?

Yes, through the metrics.yaml file and the Glean Dictionary.

2. Is there a control mechanism that allows the user to turn the data collection on and off?

Yes, through the data preferences in the application settings.

3. If the request is for permanent data collection, is there someone who will monitor the data over time?

N/A, collection to end or be renewed by version 134

4. Using the category system of data types on the Mozilla wiki, what collection type of data do the requested measurements fall under?

Category 1, Technical data

5. Is the data collection request for default-on or default-off?

Default-on

6. Does the instrumentation include the addition of any new identifiers (whether anonymous or otherwise; e.g., username, random IDs, etc. See the appendix for more details)?

No

7. Is the data collection covered by the existing Firefox privacy notice?

Yes

8. Does the data collection use a third-party collection tool?

No

Result

data-review+

Comment 8

[Fred Chasen [:fchasen]]

Attachment: WIP: Bug 1848386 - Error on Shopping request failures.

Allows the Shopping request methods to throw errors on request failures and validation failures.

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/0706debbd354
Add reporting for Shopping request failures. r=shopping-reviewers,jhirsch

Comment 10

[Iulian Moraru]

Backed out for causing bc failures on browser_shopping_request_telemetry.js.

• Push with failures

• Failure log

• Backout link

[task 2024-02-02T20:48:13.486Z] 20:48:13     INFO - TEST-PASS | toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js | {"category":"shopping_product","name":"request_failure"} deepEqual {"category":"shopping_product","name":"request_failure"} - 
[task 2024-02-02T20:48:13.489Z] 20:48:13     INFO - Leaving test bound test_shopping_request_failure_telemetry
[task 2024-02-02T20:48:13.490Z] 20:48:13     INFO - Entering test bound test_shopping_request_retried_telemetry
[task 2024-02-02T20:48:13.491Z] 20:48:13     INFO - Buffered messages finished
[task 2024-02-02T20:48:13.494Z] 20:48:13     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js | Uncaught exception in test bound test_shopping_request_retried_telemetry - at chrome://mochitests/content/browser/toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js:97 - TypeError: can't access property 0, events is null
[task 2024-02-02T20:48:13.495Z] 20:48:13     INFO - Stack trace:
[task 2024-02-02T20:48:13.495Z] 20:48:13     INFO - test_shopping_request_retried_telemetry@chrome://mochitests/content/browser/toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js:97:22
[task 2024-02-02T20:48:13.495Z] 20:48:13     INFO - async*handleTask@chrome://mochikit/content/browser-test.js:1139:26
[task 2024-02-02T20:48:13.495Z] 20:48:13     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18
[task 2024-02-02T20:48:13.496Z] 20:48:13     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14
[task 2024-02-02T20:48:13.496Z] 20:48:13     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1128:14
[task 2024-02-02T20:48:13.496Z] 20:48:13     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13
[task 2024-02-02T20:48:13.496Z] 20:48:13     INFO - Leaving test bound test_shopping_request_retried_telemetry
[task 2024-02-02T20:48:13.496Z] 20:48:13     INFO - Entering test bound test_shopping_response_invalid_telemetry
[task 2024-02-02T20:48:13.497Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f73d94e0000 == 5 [pid = 4548] [id = 14]
[task 2024-02-02T20:48:13.498Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 27 (7f73da2b8100) [pid = 4548] [serial = 43] [outer = 0]
[task 2024-02-02T20:48:13.499Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 28 (7f73d94e0c00) [pid = 4548] [serial = 44] [outer = 7f73da2b8100]
[task 2024-02-02T20:48:13.499Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 29 (7f73d94e2000) [pid = 4548] [serial = 45] [outer = 7f73da2b8100]
[task 2024-02-02T20:48:13.640Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 28 (7f73daa4bc00) [pid = 4548] [serial = 26] [outer = 0] [url = about:blank]
[task 2024-02-02T20:48:13.643Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 27 (7f73dafdb400) [pid = 4548] [serial = 21] [outer = 0] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:13.643Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 26 (7f73da7e0400) [pid = 4548] [serial = 18] [outer = 0] [url = about:blank]
[task 2024-02-02T20:48:13.644Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 25 (7f73db4a3c00) [pid = 4548] [serial = 9] [outer = 0] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:13.662Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 24 (7f73da7dc800) [pid = 4548] [serial = 23] [outer = 0] [url = about:blank]
[task 2024-02-02T20:48:13.663Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 23 (7f73da7ddc00) [pid = 4548] [serial = 15] [outer = 0] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:13.668Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (7f73da7df800) [pid = 4548] [serial = 24] [outer = 0] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:13.676Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f73d9f7e400 == 4 [pid = 4548] [id = 12] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:13.682Z] 20:48:13     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f73da64fc00 == 3 [pid = 4548] [id = 11] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:13.858Z] 20:48:13     INFO - GECKO(4348) | console.error: "Failed to fetch product analysis data" (new Error("request failed", "resource:///actors/ShoppingSidebarChild.sys.mjs", 376))
[task 2024-02-02T20:48:14.116Z] 20:48:14     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (7f73dadc15c0) [pid = 4548] [serial = 25] [outer = 0] [url = about:shoppingsidebar]
[task 2024-02-02T20:48:14.207Z] 20:48:14     INFO - GECKO(4348) | console.error: "Invalid result: [\n  {\n    \"instanceLocation\": \"#\",\n    \"keyword\": \"properties\",\n    \"keywordLocation\": \"#/properties\",\n    \"error\": \"Property \\\"grade\\\" does not match schema.\"\n  },\n  {\n    \"instanceLocation\": \"#/grade\",\n    \"keyword\": \"anyOf\",\n    \"keywordLocation\": \"#/properties/grade/anyOf\",\n    \"error\": \"Instance does not match any subschemas.\"\n  },\n  {\n    \"instanceLocation\": \"#/grade\",\n    \"keyword\": \"type\",\n    \"keywordLocation\": \"#/properties/grade/anyOf/0/type\",\n    \"error\": \"Instance type \\\"number\\\" is invalid. Expected \\\"string\\\".\"\n  },\n  {\n    \"instanceLocation\": \"#/grade\",\n    \"keyword\": \"type\",\n    \"keywordLocation\": \"#/properties/grade/anyOf/1/type\",\n    \"error\": \"Instance type \\\"number\\\" is invalid. Expected \\\"null\\\".\"\n  }\n]"
[task 2024-02-02T20:48:14.277Z] 20:48:14     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-02-02T20:48:14.278Z] 20:48:14     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js | Uncaught exception in test bound test_shopping_response_invalid_telemetry - at chrome://mochitests/content/browser/toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js:117 - TypeError: can't access property 0, events is null
[task 2024-02-02T20:48:14.279Z] 20:48:14     INFO - Stack trace:
[task 2024-02-02T20:48:14.280Z] 20:48:14     INFO - test_shopping_response_invalid_telemetry@chrome://mochitests/content/browser/toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js:117:22
[task 2024-02-02T20:48:14.281Z] 20:48:14     INFO - async*handleTask@chrome://mochikit/content/browser-test.js:1139:26
[task 2024-02-02T20:48:14.282Z] 20:48:14     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18
[task 2024-02-02T20:48:14.283Z] 20:48:14     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14
[task 2024-02-02T20:48:14.284Z] 20:48:14     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1128:14
[task 2024-02-02T20:48:14.285Z] 20:48:14     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13
[task 2024-02-02T20:48:14.288Z] 20:48:14     INFO - Leaving test bound test_shopping_response_invalid_telemetry
[task 2024-02-02T20:48:14.289Z] 20:48:14     INFO - Entering test bound test_shopping_ohttp_invalid_telemetry
[task 2024-02-02T20:48:14.315Z] 20:48:14     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f73d94e3400 == 4 [pid = 4548] [id = 15]
[task 2024-02-02T20:48:14.317Z] 20:48:14     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (7f73da2b7980) [pid = 4548] [serial = 46] [outer = 0]
[task 2024-02-02T20:48:14.324Z] 20:48:14     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 23 (7f73d94e3800) [pid = 4548] [serial = 47] [outer = 7f73da2b7980]
[task 2024-02-02T20:48:14.380Z] 20:48:14     INFO - GECKO(4348) | [Child 4548: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 24 (7f73d9f82000) [pid = 4548] [serial = 48] [outer = 7f73da2b7980]
[task 2024-02-02T20:48:14.563Z] 20:48:14     INFO - GECKO(4348) | console.error: (new Error("Fetching HPKE config from https://example.com/config failed with error 404", "resource://gre/modules/HPKEConfigManager.sys.mjs", 34))
[task 2024-02-02T20:48:14.566Z] 20:48:14     INFO - GECKO(4348) | console.error: (new Error("OHTTP was configured for shopping but we couldn't get a valid config.", "chrome://global/content/shopping/ShoppingProduct.mjs", 406))
[task 2024-02-02T20:48:14.569Z] 20:48:14     INFO - GECKO(4348) | console.error: "Failed to fetch product analysis data" (new Error("request failed", "resource:///actors/ShoppingSidebarChild.sys.mjs", 376))
[task 2024-02-02T20:48:14.625Z] 20:48:14     INFO - GECKO(4348) | console.error: "Failed to fetch product analysis data" (new Error("request failed", "resource:///actors/ShoppingSidebarChild.sys.mjs", 376))
[task 2024-02-02T20:48:14.845Z] 20:48:14     INFO - GECKO(4348) | console.error: (new Error("Fetching HPKE config from https://example.com/config failed with error 404", "resource://gre/modules/HPKEConfigManager.sys.mjs", 34))
[task 2024-02-02T20:48:14.845Z] 20:48:14     INFO - GECKO(4348) | console.error: (new Error("OHTTP was configured for shopping but we couldn't get a valid config.", "chrome://global/content/shopping/ShoppingProduct.mjs", 406))
[task 2024-02-02T20:48:14.868Z] 20:48:14     INFO - GECKO(4348) | console.error: (new Error("Fetching HPKE config from https://example.com/config failed with error 404", "resource://gre/modules/HPKEConfigManager.sys.mjs", 34))
[task 2024-02-02T20:48:14.869Z] 20:48:14     INFO - GECKO(4348) | console.error: (new Error("OHTTP was configured for shopping but we couldn't get a valid config.", "chrome://global/content/shopping/ShoppingProduct.mjs", 406))
[task 2024-02-02T20:48:14.870Z] 20:48:14     INFO - GECKO(4348) | console.error: "Failed to fetch product analysis data" (new Error("request failed", "resource:///actors/ShoppingSidebarChild.sys.mjs", 376))
[task 2024-02-02T20:48:15.028Z] 20:48:15     INFO - TEST-PASS | toolkit/components/shopping/test/browser/browser_shopping_request_telemetry.js | {"category":"shopping_product","name":"invalid_ohttp_config"} deepEqual 

Comment 11

[Fred Chasen [:fchasen]]

My guess would be these intermittent failures might have something to do with the error in the log above:
AbortError: Actor 'ShoppingSidebar' destroyed before query 'GetProductURL' was resolved

Sounds like sometime we can't find the actor and then the tests can't run?

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/77a042c3e846
Add reporting for Shopping request failures. r=shopping-reviewers,jhirsch

Comment 13

[pstanciu]

https://hg.mozilla.org/mozilla-central/rev/77a042c3e846