692225 - nsIIdleService sends spurious 'back' and 'idle' notifications

Status: NEW

(Core :: Widget: Cocoa, defect)

Description

[Philipp von Weitershausen [:philikon]]

Sync registers an idle observer with the nsIIdleService with an idle time of 5 minutes, to find out whether a machine is idle or the user has just come back to a machine. These events are used to adjust the sync interval and to trigger a sync.

On my MacBook Pro running OS X 10.6.8, I'm seeing the events like the following in the middle of the night (when nobody's using the machine) every 10 to 20 minutes:

1317730539006	Sync.SyncScheduler	TRACE	We're no longer idle.
1317730539010	Sync.SyncScheduler	TRACE	We're idle.

The first line gets printed on 'back', the second line gets printed on 'idle'. Notice they're only 4 milliseconds apart! It almost looks like we're notifying 'back' and then 'idle' within the same event loop tick.

(In bug 691988 we are now working around the issue by debouncing the 'back' notification by 100ms.)

Comment 1

[Steven Michaud [:smichaud] (Retired)]

Are you able to test on other platforms?

If so, do you see it there, too?

Comment 2

[Philipp von Weitershausen [:philikon]]

As far as I can tell, my Windows 7 desktop is not getting those spurious idle events. At night it happily syncs only once per hour as it should, without ever waking up from idle on its own. It seems that this is an OS X only bug, though I haven't tested on Linux.

If you want to reproduce it with Sync, here's how:

* Procure an OS X machine running Firefox 7 or later that doesn't have bug 691988 in it. (It hasn't landed anywhere yet, but I imagine it will soon.)
* Connect to a Sync account that has at least one other device connected, so that with the OS X machine there are at least 2 devices in total.
* In about:config, set 'services.sync.log.logger.service.main' to 'Trace' (without the quotes; note the capital T) and flip 'services.sync.log.appender.file.logOnSuccess' to true.
* Restart the browser.
* Walk away from the machine and don't touch it for a few hours.
* Go to about:sync-log.

Expected results:

You should see a success-NNN.txt log dump in an hourly interval.

Observed results:

Syncs occur every 10 to 20 minutes (irregular intervals) and the logfiles contain the output shown in comment 0.

Comment 3

[Philipp von Weitershausen [:philikon]]

FWIW, QA tested our wallpaper fix in bug 691988 on their Mac and the logs clearly show the spurious 'back' and 'idle' notifications, while a WinXP machine did not. So this isn't something that's just happening on my Mac but it's actually reproducible.

Comment 4

[Philipp von Weitershausen [:philikon]]

(In reply to Philipp von Weitershausen [:philikon] from comment #3)
> FWIW, QA tested our wallpaper fix in bug 691988 on their Mac and the logs
> clearly show the spurious 'back' and 'idle' notifications,

(See attachment 565044 [details] in bug 691988 for those logs.)

Comment 5

[Silmar]

I use XP and have this problem for plugin:

I create the class observer:

...
IdleService  = Components.classes["@mozilla.org/widget/idleservice;1"].getService(Components.interfaces.nsIIdleService);
...
observe: function(subject, topic, data) {
		switch (topic) {
			case 'idle': 
				[1]
				break;
			case 'back':
				break;
		}
}

if in 'idle [1]' put a simple commands gBrowser.loadURI, the observe return 'back' witch IdleService.idleTime = 0.
If not, the 'back' occurs only if keypress or mousemove/mouseclick.
The bug ocurs in firefox 7.x;

Comment 6

[:Gijs (he/him)]

Looks like this happens on Windows, too (see: bug 670551). Comment #5 might provide a clue to what's going on here?