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

Status: RESOLVED FIXED

(Toolkit :: Application Update, defect)

Description

[Jared Wein [:jaws] (please needinfo? me)]

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])
>};

Comment 1

[:Gijs (he/him)]

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.

Comment 2

[Robert Strong (they/them - no direct email)]

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.

Comment 3

[Robert Strong (they/them - no direct email)]

Note: the registration id is telemetry_modules_ping

Comment 4

[Robert Strong (they/them - no direct email)]

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

Comment 5

[Robert Strong (they/them - no direct email)]

Attachment: patch rev1

Comment 6

[Robert Strong (they/them - no direct email)]

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.

Comment 7

[Robert Strong (they/them - no direct email)]

Attachment: 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.

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/39e61f5e8fc5
Don't try to register timers during shutdown in nsUpdateTimerManager.js. r=mhowell

Comment 9

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/39e61f5e8fc5

Comment 10

[Chris H-C :chutten]

Good to know. +ni Dexter, gfritzsche for visibility.

Comment 11

[Georg Fritzsche [:gfritzsche]]

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).

Comment 12

[Alessio Placitelli [:Dexter]]

+ Marco (FYI)