I see nonstop log messages about Fennec's IdleService rescheduling a "daily" timer. Note that the timers seem to be scheduled *earlier* every time! I am running Fennec Beta 34. A few weeks ago, my phone started running out of battery every night or automatically resetting. Maybe this constant logging is related? 10-20 11:54:09.937: I/IdleService(500): DailyCallback running 10-20 11:54:09.937: I/IdleService(500): DailyCallback resetting timer to 5044805 msec 10-20 11:54:09.967: I/IdleService(500): DailyCallback running 10-20 11:54:09.967: I/IdleService(500): DailyCallback resetting timer to 5044776 msec 10-20 11:54:09.997: I/IdleService(500): DailyCallback running 10-20 11:54:09.997: I/IdleService(500): DailyCallback resetting timer to 5044752 msec 10-20 11:54:10.027: I/IdleService(500): DailyCallback running 10-20 11:54:10.027: I/IdleService(500): DailyCallback resetting timer to 5044716 msec 10-20 11:54:10.037: I/IdleService(500): DailyCallback running 10-20 11:54:10.037: I/IdleService(500): DailyCallback resetting timer to 5044698 msec 10-20 11:54:10.067: I/IdleService(500): DailyCallback running 10-20 11:54:10.067: I/IdleService(500): DailyCallback resetting timer to 5044663 msec 10-20 11:54:10.097: I/IdleService(500): DailyCallback running 10-20 11:54:10.097: I/IdleService(500): DailyCallback resetting timer to 5044638 msec 10-20 11:54:10.147: I/IdleService(500): DailyCallback running 10-20 11:54:10.147: I/IdleService(500): DailyCallback resetting timer to 5044591 msec 10-20 11:54:10.157: I/IdleService(500): DailyCallback running 10-20 11:54:10.157: I/IdleService(500): DailyCallback resetting timer to 5044574 msec 10-20 11:54:10.197: I/IdleService(500): DailyCallback running 10-20 11:54:10.197: I/IdleService(500): DailyCallback resetting timer to 5044540 msec 10-20 11:54:10.217: I/IdleService(500): DailyCallback running 10-20 11:54:10.217: I/IdleService(500): DailyCallback resetting timer to 5044515 msec 10-20 11:54:10.277: I/IdleService(500): DailyCallback running 10-20 11:54:10.277: I/IdleService(500): DailyCallback resetting timer to 5044454 msec 10-20 11:54:10.308: I/IdleService(500): DailyCallback running 10-20 11:54:10.308: I/IdleService(500): DailyCallback resetting timer to 5044426 msec 10-20 11:54:10.388: I/IdleService(500): DailyCallback running 10-20 11:54:10.388: I/IdleService(500): DailyCallback resetting timer to 5044344 msec 10-20 11:54:10.408: I/IdleService(500): DailyCallback running 10-20 11:54:10.408: I/IdleService(500): DailyCallback resetting timer to 5044326 msec 10-20 11:54:10.428: I/IdleService(500): DailyCallback running 10-20 11:54:10.428: I/IdleService(500): DailyCallback resetting timer to 5044302 msec 10-20 11:54:10.448: I/IdleService(500): DailyCallback running 10-20 11:54:10.448: I/IdleService(500): DailyCallback resetting timer to 5044283 msec 10-20 11:54:10.488: I/IdleService(500): DailyCallback running 10-20 11:54:10.488: I/IdleService(500): DailyCallback resetting timer to 5044250 msec 10-20 11:54:10.508: I/IdleService(500): DailyCallback running 10-20 11:54:10.508: I/IdleService(500): DailyCallback resetting timer to 5044228 msec 10-20 11:54:10.538: I/IdleService(500): DailyCallback running 10-20 11:54:10.538: I/IdleService(500): DailyCallback resetting timer to 5044199 msec 10-20 11:54:10.558: I/IdleService(500): DailyCallback running 10-20 11:54:10.558: I/IdleService(500): DailyCallback resetting timer to 5044173 msec 10-20 11:54:10.588: I/IdleService(500): DailyCallback running 10-20 11:54:10.588: I/IdleService(500): DailyCallback resetting timer to 5044149 msec 10-20 11:54:10.608: I/IdleService(500): DailyCallback running 10-20 11:54:10.608: I/IdleService(500): DailyCallback resetting timer to 5044131 msec 10-20 11:54:10.628: I/IdleService(500): DailyCallback running 10-20 11:54:10.628: I/IdleService(500): DailyCallback resetting timer to 5044103 msec 10-20 11:54:10.658: I/IdleService(500): DailyCallback running 10-20 11:54:10.658: I/IdleService(500): DailyCallback resetting timer to 5044077 msec

This is an nsIdleService bug, not a Fennec bug. To Core::Widget it goes!

Those log messages were hard forced on in Fennec 2 years ago to detect when the behavior talked about in Bug 762620 happened. Back then some phones were effectively DDOSing our Telemetry services because of this misfiring. Chris, I'd be very interested what phone and Android version you are running, and if you notice anything odd about the phone's clock etc!

I'm not sure you'll be able to get a regression window for this, it's quite possible this bug might have been there forever. Please confirm it's actually a regression first. Chris, are you able to produce the bug in a build with all logging on? Look in Bug 762620 to see what to turn on etc.

(In reply to Chris Peterson (:cpeterson) from comment #0) > I see nonstop log messages about Fennec's IdleService rescheduling a "daily" > timer. Note that the timers seem to be scheduled *earlier* every time! That's expected, see the logic here: https://bugzilla.mozilla.org/attachment.cgi?id=639402&action=diff We're trying to set a timer for the next IdleDaily event, which we calculate as being 1.4 hours in the future. Yet, when we set that timer, it returns nearly instantly! Before, we'd run IdleDaily (and DDOS the Telemetry servers trying to submit telemetry each time. The fixes in bug 762620 changed the logic to calculate the remaining time and reschedule the timer. Because it returns instantly each time (way before the programmer interval), we keep rescheduling with a slightly reduced duration. The question is why the timer stops early.

I am running Firefox Beta 34 on a Nexus 4 running JB 4.3.1 (CyanogenMod 10.2.1). I don't see anything unusual about my phone's clock; the time is correct and it's set automatically by the network. I will see if I can reproduce this again with logging.

I'll see if I can reproduce this on my stock N4

I haven't had time to debug this problem yet, but the "good news" is that I can still reproduce the problem.

A possible dupe with bug 1092623, where the user noticed Firefox would hang loading pages and start running hot.

The dupe was also on CyanogenMod, but we shouldn't jump to conclusions because the kind of people who can obtain the relevant log are probably correlated to the kind of users that runs Cyanogen.

I'm running a debug build of Fennec now, but I have not been able to reproduce the problem again yet.

Chris, we have STR in bug 1092623 comment 6 - can you repro with these steps?

I can't reproduce the IdleService messages with those STR.

Chris, the following steps are reproducible on my device. Could you try? 1. Insert charging cable into device and plug it in. 2. Load news.google.com (other pages seem to do the same) into Android Firefox 3. Use power button to switch off screen Result: Phone runs hot after 30-60 minutes, GeckoIdleService messages appear in logs. With a different browser of without the charging cable, there are no problems. (Samsung Galaxy S2, Cyanogenmod 10.1, Android 4.2.2, Firefox 36.0a1 nightly 2014-11-05)

Thanks, Alex. Indeed, in comment 13, I had tested without the charging cable. I just tried with the charging cable and I was able to repro with a debug build. I will email my debug log to gcp.

Incorrect wakelock assumptions, maybe?

Rule out a CM only problem?

rnewman said the following on the dev-power list. > There's some history there that implies this being seen in the wild (Bug 762620). It's also possible > that this'll either (a) stop your device from charging because it's drawing too much current (which > I've seen!), or (b) cause the horrific data usage that we've seen in Bug 1022569, if that IdleService > callback ends up touching the network. > > This seems like the loose end of a fairly serious thread, so I think this is important enough to at > least move towards a diagnosis before retriaging. P1, IMO.