1802333 - Add debug logging to the "activity after idle" message trigger

Status: VERIFIED FIXED

(Firefox :: Messaging System, task)

Description

[Carmen Fat [:cfat] - Ecosystem QA]

[Affected versions]:

• Firefox Beta 108.0b5 - Build ID: 20221122190120

[Affected Platforms]:

• Windows 10 x64

[Prerequisites]:

• Have the "Remote Settings Devtools" add-on installed from here.

[Steps to reproduce]:

1. Open the browser from the prerequisites.
2. Click the "Remote Settings Devtools" toolbar button from the right part of the toolbar.
3. Change the environment to "Stage" and restart the browser.
4. Put the PC to "Hibernate".
5. Wake up the PC and observe the behavior.

[Expected result]:

• The "activityAfterIdle" message is NOT triggered.

[Actual result]:

• The "activityAfterIdle" message is triggered almost instantly.

[Notes]:

• This issue is not reproducible if the PC was put to "Sleep".
• Here is a screen recording of the issue: link.

Comment 1

[Shane Hughes [:aminomancer]]

Attachment: Bug 1802333 - Idle trigger debug logging. r=barret

To debug the idle trigger's interaction with OS sleep state, it's
helpful to know whether sleep/wake notifications were sent. This allows
most of the idle trigger activity to be logged to the console, if the
pref messaging-system.log is set to debug. The new logging will also
be used to debug the behavior reported in bug 1801301.

Comment 2

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e1393a35e060
Idle trigger debug logging. r=barret

Comment 3

[Natalia Csoregi [:nataliaCs]]

Backed out for newtab failure

• backout: https://hg.mozilla.org/integration/autoland/rev/c4d0b77f8b0d3b68cb01c6f3c104aca3300b4b23
• push: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&revision=e1393a35e0605de8cfa1b57bdbdc176c03a2cdcf&selectedTaskRun=d_ERAFxwTD-GLypTieRVjQ.1
• failure log: https://treeherder.mozilla.org/logviewer?job_id=397659627&repo=autoland&lineNumber=232

[task 2022-11-25T04:42:25.798Z] TEST START | karma
[task 2022-11-25T04:43:06.858Z] webpack was not included as a framework in karma configuration, setting this automatically...
[task 2022-11-25T04:43:06.876Z] TEST-UNEXPECTED-FAIL karma | activity-stream:ASRouterTriggerListeners:activityAfterIdle:#init "before each" hook for "should set ._initialized to true and save the triggerHandler": lazy.log.debug is not a function
[task 2022-11-25T04:43:06.876Z] log@http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:117721:14
[task 2022-11-25T04:43:06.876Z] init@http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:117589:12
[task 2022-11-25T04:43:06.876Z] @http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:120381:22
[task 2022-11-25T04:43:06.876Z] 
[task 2022-11-25T04:43:06.876Z] TEST-UNEXPECTED-FAIL karma | activity-stream:ASRouterTriggerListeners:activityAfterIdle:#init "after each" hook for "should set ._initialized to true and save the triggerHandler": lazy.log.debug is not a function
[task 2022-11-25T04:43:06.876Z] log@http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:117721:14
[task 2022-11-25T04:43:06.876Z] uninit@http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:117716:12
[task 2022-11-25T04:43:06.876Z] @http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:120384:22
[task 2022-11-25T04:43:06.876Z] 
[task 2022-11-25T04:43:06.876Z] TEST-UNEXPECTED-FAIL karma | activity-stream:ASRouterTriggerListeners:activityAfterIdle:#uninit "before each" hook for "should set ._initialized to false and clear the triggerHandler and timestamps": lazy.log.debug is not a function
[task 2022-11-25T04:43:06.876Z] log@http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:117721:14
[task 2022-11-25T04:43:06.876Z] init@http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:117589:12
[task 2022-11-25T04:43:06.876Z] @http://localhost:9876/absolute/tmp/_karma_webpack_860055/commons.js?1b7e040c2cb02e56a828988d9a0e7cac5466b4c5:120412:22
[task 2022-11-25T04:43:06.876Z] 
[task 2022-11-25T04:43:06.876Z] -----karma stdout below this line---
[task 2022-11-25T04:43:06.877Z] 
[task 2022-11-25T04:43:06.877Z] > activity-streams@1.14.3 testmc:unit
[task 2022-11-25T04:43:06.877Z] > karma start karma.mc.config.js
[task 2022-11-25T04:43:06.877Z] 

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/04dd3dcc9e70
Idle trigger debug logging. r=barret

Comment 5

[Marian-Vasile Laza]

https://hg.mozilla.org/mozilla-central/rev/04dd3dcc9e70

Comment 6

[Shane Hughes [:aminomancer]]

The fix for this and the Win7 issue should be the same, so we can track those together in bug 1801301 if Marius is OK with that

Comment 7

[BugBot [:suhaib / :marco/ :calixte]]

The patch landed in nightly and beta is affected.
:aminomancer, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
• If no, please set status-firefox108 to wontfix.

For more information, please visit auto_nag documentation.

Comment 8

[Shane Hughes [:aminomancer]]

May uplift the patch for the other bug, this one just adds debug logging

Comment 9

[Shane Hughes [:aminomancer]]

Comment on attachment 9305153 [details]
Bug 1802333 - Idle trigger debug logging. r=barret

Beta/Release Uplift Approval Request

• User impact if declined: (See bug 1801301)
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: No
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: Bug 1801301
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): As with bug 1801301, this only changes test files and a JS object that isn't currently used. This particular patch only adds calls to the Console API, generating log messages under debug conditions and having no effect under normal conditions. It also should graft cleanly so it should be very low risk.
• String changes made/needed:
• Is Android affected?: No

Comment 10

[Dianna Smith [:diannaS]]

Comment on attachment 9305153 [details]
Bug 1802333 - Idle trigger debug logging. r=barret

Approved for 108.0rc1

Comment 11

[Dianna Smith [:diannaS]]

https://hg.mozilla.org/releases/mozilla-beta/rev/4140bc72f3f0

Comment 12

[Shane Hughes [:aminomancer]]

These patches did not fix the underlying issue, which will be tracked in bug 1802865, so we're changing the tracking status to reflect that

Comment 13

[Shane Hughes [:aminomancer]]

Changing the title instead. If manual verification is needed just @ me on slack, as we no longer have a test message for this trigger on remote settings stage.

Comment 14

[Carmen Fat [:cfat] - Ecosystem QA]

I think it’s safe to mark this task as verified since we did manage to generate the Idle trigger logs at the time (screenshot and comment with the Idle Trigger logs). Please reopen the report if considered necessary.