JavaScript error: nsUpdateTimerManager.js, line 311: TypeError: invalid 'in' operand this._timers

RESOLVED FIXED in Firefox 56

Status

()

Toolkit
Application Update
RESOLVED FIXED
4 months ago
4 months ago

People

(Reporter: jaws, Assigned: rstrong)

Tracking

unspecified
mozilla56
Points:
---

Firefox Tracking Flags

(firefox56 fixed)

Details

Attachments

(1 attachment, 1 obsolete attachment)

I got this JavaScript error when running a debug build,
http://searchfox.org/mozilla-central/rev/a3a739de04ee6134c11546568a33dbb6a6a29907/toolkit/components/timermanager/nsUpdateTimerManager.js#311

>  /**
>   * See nsIUpdateTimerManager.idl
>   */
>  registerTimer: function TM_registerTimer(id, callback, interval) {
>    LOG("TimerManager:registerTimer - id: " + id);
>    if (id in this._timers && callback != this._timers[id].callback) { /* <-------- this line */
>      LOG("TimerManager:registerTimer - Ignoring second registration for " + id);
>      return;
>    }
>    let prefLastUpdate = PREF_APP_UPDATE_LASTUPDATETIME_FMT.replace(/%ID%/, id);
>    // Initialize the last update time to 0 when the preference isn't set so
>    // the timer will be notified soon after a new profile's first use.
>    let lastUpdateTime = getPref("getIntPref", prefLastUpdate, 0);
>    let now = Math.round(Date.now() / 1000);
>    if (lastUpdateTime > now) {
>      lastUpdateTime = 0;
>    }
>    if (lastUpdateTime == 0) {
>      Services.prefs.setIntPref(prefLastUpdate, lastUpdateTime);
>    }
>    this._timers[id] = {callback,
>                        interval,
>                        lastUpdateTime};
>
>    this._ensureTimer(interval * 1000);
>  },
>
>  unregisterTimer: function TM_unregisterTimer(id) {
>    LOG(`TimerManager:unregisterTimer - id: ${id}`);
>    if (id in this._timers) {
>      delete this._timers[id];
>    } else {
>      LOG(`TimerManager:registerTimer - Ignoring unregistration request for unknown id: ${id}`);
>    }
>  },
>
>  classID: Components.ID("{B322A5C0-A419-484E-96BA-D7182163899F}"),
>  QueryInterface: XPCOMUtils.generateQI([Ci.nsIUpdateTimerManager,
>                                         Ci.nsITimerCallback,
>                                         Ci.nsIObserver])
>};
(Reporter)

Updated

4 months ago
Blocks: 1160263
I see this too, on opt builds. It looks from the code like something is calling registerTimer after profile-before-change has already fired. I guess ideally we should both (a) fix the consumer not to do that (ie this might be a bigger bug than just the logspam, if whatever it's trying to schedule is actually important or if it's still trying to do initialization even though the process is dying) and (b) fix registerTimer to throw a more descriptive error if it gets called when _timers is already null.
This is likely due to in part bug 1375077 which shuts nsUpdatetimerManager down earlier than we used to and it appears that when running tests profile-before-change is sent before the application is shutting down. Option b is a no brainer and I don't think option a will provide any value in the non test world where all notifications are sent... at worst the component fails after it has already shut down.
Note: the registration id is telemetry_modules_ping
This delayed task is the likely culprit
http://searchfox.org/mozilla-central/source/toolkit/components/telemetry/TelemetryController.jsm#717
which then calls
http://searchfox.org/mozilla-central/source/toolkit/components/telemetry/TelemetryController.jsm#748
and here is the function that registers the timer
http://searchfox.org/mozilla-central/source/toolkit/components/telemetry/TelemetryModules.jsm#41
Created attachment 8883757 [details] [diff] [review]
patch rev1
Assignee: nobody → robert.strong.bugs
Status: NEW → ASSIGNED
Attachment #8883757 - Flags: review?(mhowell)
chutten, just an fyi that telemetry's registerTimer call is reporting an error in tests due to it delaying until after profile-before-change is called. See comment #4 for more details.
Flags: needinfo?(chutten)
Created attachment 8883762 [details] [diff] [review]
patch rev2

While I'm here I switched the inconsistent though valid logging style that was recently added as well as fixed a typo in the log message.
Attachment #8883757 - Attachment is obsolete: true
Attachment #8883757 - Flags: review?(mhowell)
Attachment #8883762 - Flags: review?(mhowell)

Updated

4 months ago
Attachment #8883762 - Flags: review?(mhowell) → review+

Comment 8

4 months ago
Pushed by rstrong@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/39e61f5e8fc5
Don't try to register timers during shutdown in nsUpdateTimerManager.js. r=mhowell

Comment 9

4 months ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/39e61f5e8fc5
Status: ASSIGNED → RESOLVED
Last Resolved: 4 months ago
status-firefox56: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla56

Comment 10

4 months ago
Good to know. +ni Dexter, gfritzsche for visibility.
Flags: needinfo?(gfritzsche)
Flags: needinfo?(chutten)
Flags: needinfo?(alessio.placitelli)
Thanks.
For this specific call, this seems non-critical.
Unless there is specific impact this seems fine to leave as is (with the error being handled in the update timer manager now).
Flags: needinfo?(gfritzsche)
+ Marco (FYI)
Flags: needinfo?(alessio.placitelli)
You need to log in before you can comment on or make changes to this bug.