Flight mode problem with both Jolla 1 and Jolla C

That's a pretty neat app! And kudos to you for figuring this all out. I had been wondering about the fast discharge(7-9%) at night.

Thank you Sailor-John-Doe. You released us from confusion and suspect.

I believe that this is a bug in our suspend handling in msyncd, most prominently reproducible if you have an email account set up with different peak and off-peak (rush-switch) sync schedules. This should be fixed in 2.0.4.x - see https://git.merproject.org/mer-core/buteo-syncfw/merge_requests/8 for more information.

Probably handling of msyncd induces a wakelock that prevents a sleep. In addition, from these graphs, its clear that all CPU cores are working (idle and frequencies sum up to 100%). This is in contrast to normal operation when they don't. In addition, when just sleep is prevented but there is not much to do, all but one CPU core should be switched off. That happens on Nexus 4 during charging, for example. In N4 during charging 3 out of 4 CPU cores are off and, as a result, reported frequency and idle state distributions sum up towards 25%. So, there is a problem preventing switching off CPU cores in J1 & JC in these conditions.

In addition, I do wonder whether ondemand is any better than interactive CPU scheduler. Have you tried to see the differences in CPU frequencies when using that scheduler?

As I wrote in my 2nd answer, the problem persists even if sync schedules are disabled and set to "manual", respectively. But you guys can try it out, too. Just download the app SystemDataScope and run some tests. Together we will solve this problem!

Thanks for testing it! Yes, the scheduler would not have changed entering the sleep - that's controlled differently. As told by @chris.adams this is probably a bug in syncing daemon. I presume, it does not release wakelock when you cut off the net.

I am surprised to see that interactive scheduler keeps so high CPU frequencies even on idle. I haven't read into it, maybe minimal frequency can be changed in interactive, maybe not. But surely, when comparing these configurations, ondemand makes much more sense.

What concerns me is that all your CPU cores are active during the idle time. While absence of CPU sleep could be caused by wakelocks, I would expect that only one core would be active and others switched off. Maybe its a hardware limitation on your device, maybe its another bug. To check that you could see what was summed up CPU frequency distribution while you charged. During charging CPU is not entering sleep, but on my phone 3 out of 4 cores are switched off. So, the recorded data would sum up to 25%. If you have used collectd/systemdatascope for some time, you should have this data in your history and you could just move along time axis to earlier points to see it.

Whether cores are sleeping is clearly reported by Aida64. So, you could also use that app to see whether CPU cores get switched off individually. If they are, this flight mode bug could be combination of several bugs.

Thank you @rinigus for your informative comment. Seems that you are actually one of those linux experts! As you can see from the graphs above, I charged my Jolla C phone during 10p.m. and 11p.m. that day. So this data is already included in the graphs above.

I'm curious about your comment concerning the summed up CPU frequencies of all cores. Where can you see this information in the graphs above? In the graph "used idle states"? I don't understand this graph, there are only three cores mentioned in the legend (c0, c1, c2), but the Jolla C phone actually has 4cores... Can you please explain that to me?

Let me start with the background and then move towards what you see. Since I don't know your background, please bear with me if info seems to be too basic.

On phones, while running in your pockets, kernel takes care of keeping the phone in suspended state for as much as it can. Its as if your laptop is suspended when you don't use it. In laptop world its usually done by user, in the phone world its done automatically. While suspended, phone can wake up automatically to process cellular, WiFi, timer, or some other data/interrupt. As soon as required processing is done, it goes to sleep again. This cycle can happen many times and in systemdatascope/collectd (sds for short) the average suspend cycle is reported under CPU sleep graph. Depending on the conditions that could range from sub-second to few minutes. Overall fraction of time spent in suspended condition is reported as CPU sleep. So, indeed, when you don't do anything with your phone and there are no inputs (flight mode), you expect this fraction to be high. Something about 95+% would be common.

Sometimes, when apps need it, automatic suspend is stopped. For that, wakelock is created and it should be released when not needed anymore. If there is a bug in a software and wakelock is not released, your phone will not enter suspend => CPU sleep would be zero. Now, it is common not to let the phone go to sleep while charging and this is done usually by acquiring wakelock. To see wakelocks, you could checkout /proc/wakelocks.

Even when not on suspended state, CPU usage is monitored and, usually, if there is no load, CPU cores are switched off one by one and leaving the core 0 as active. This is done probably differently on different platforms. On Nexus 4 and many other phones there is an extra service that switches on/off CPU cores (all except core 0).

/due to the char limitations, I'll continue in the next post/

/continued from prev post, part 2/

What you see in the graphs is calculated as follows. CPU frequency distribution is found using https://www.kernel.org/doc/Documentation/cpu-freq/cpufreq-stats.txt . In particular, file time_in_state is used. For each CPU core the distribution is reported separately. The reported times, for each frequency, are summed up and divided by number of CPUs. By repeating this measurement over period of time (2.5 minutes by default), its easy to see how much from the wall time (https://en.wikipedia.org/wiki/Wall-clock_time) CPU cores were in a particular frequency. SDS/collectd reports the time spent on any of the CPU frequencies as a fraction of the corresponding wall time. Now, if CPU was sleeping, the total time spent by CPU in all frequencies would be less than 100%. In addition, in the phone that does not sleep, if 3 out of 4 CPU cores would be switched off, again total CPU time spent in any of the frequencies would be 25%. This total is easy to see by following the upper edge in SDS frequency distribution graph. For example, while on flight mode, its about 100% (the imprecision maybe related to collectd plugin internals, working on it).

CPU idle is somewhat similar to CPU frequency, but reports CPU idle states. In ARM, they are frequently called as C0, C1, ... (don't confuse with core count). This seems to be some reasonable background info on CPU idle: http://www.hardwaresecrets.com/everything-you-need-to-know-about-the-cpu-c-states-power-saving-modes/ . Again, times are summed up among all cores and divided by number of cores. So, if phone is asleep, the total idle time would also go below 100%. If core is switched off, total idle should be reduced by corresponding fraction.

/ continued in the next part /

/continued from prev post, part 3/

Now looking on your graphs there are several strange things:

1. During charging you observe that phone is entering sleep. This is very unusual. So far, I have always seen that the phones do not enter sleep state during charging. I suspect its a bug in software that controls charging.

2. While doing nothing your phone is not entering the sleep. This maybe caused by wakelock, as I suspect what @chris.adams was suggesting in his reply. However, since there is no CPU activity (and the schedulers bring CPU frequency down), I would expect that 3 of 4 cores would be shut down. That's what I usually see on Nexus 4, even while the phone is in use. In your graphs, CPU frequency distribution totals to 100% - so, the cores are all on. From that I conclude that the service which is supposed to switch off cores is buggy OR your hardware does not support switching off cores one by one (doubt it though).

As to whether cores are switched on and off you could test it using aida64. Start that app, go to CPU section and follow the CPU core frequencies. If there is nothing running particularly intensively on the background, you should see cores going on and off. You could repeat the same while in flight mode or out of it. While aida64 does not make stats and record history as SDS, its an independent measurement.

So, if I am right, there maybe 3 bugs which are causing your problems (1 charging, 1 wakelock, 1 cpu core handling).

PS: Saw your graphs below and I think it covers them as well

That's interesting. I'll do this tonight.

The very first time I tried this my phone, Aqua Fish, lost about 3% charge in about 8 hours. Last night when I tried it again I had 100% charge on my phone. Got the phone in airplane mode, restarted it and battery showed 98%. I went to sleep, got up after 6.5 hours to find my phone at 89%. No apps running and android support switched off.

I can confirm, that following the described reboot-procedure results in a battery decharge of about 3% in 8 hours. The phone is actually entering sleep mode, the used frequencies sum up to 4%-5%, which means that 3 out of 4 cores are fully switched off and that the remaining core is in sleep mode most of the time (approx. 98%). Not too bad, maybe this is a starting point!

Thank you for this information. I have added it to internal bug JB#35984 and will ping Simo about the MCE stuff.

@chris.adams: I'd be happy to help you to debug the issue. Is it possible its fixed in some other buteo- packages, such as sync plugins? I have stock 2.0.2.48 buteo installed, with the exception of syncfw. Are there any ENV vars or some compile switches for buteo that I could enable to see on buteo side what's locking MCE wakelock? I don't mind to recompile all buteo packages and install upstream latest versions, if you think its fixed somewhere or if its easier to debug the issue that way.

if I set flight mode and reboot, the phone is back to 2% overnight draining.

@chris.adams: ping. I have updated other packages from buteo family to check if there is any additional update that could help with unlocking mce wakelock. The list of installed buteo packages is pasted below. Unfortunately, no change. As soon as the IP network is off, the wakelock is locked after a bit of time and sleep is prevented. On that setup, I have only gmail and jolla accounts. I presume that gmail sync starts up and locks the system.

Is there any buteo compile flag which could help to debug the issue? Some verbose log option?

List of installed buteo packages:

buteo-syncfw-qt5-msyncd-0.8.6-1.armv7hl buteo-mtp-qt5-0.4.16-1.armv7hl buteo-syncml-qt5-0.5.9-1.5.4.armv7hl buteo-sync-plugins-email-0.0.16-10.7.2.jolla.armv7hl buteo-sync-plugins-qt5-0.8.23-1.17.5.armv7hl buteo-syncfw-qt5-0.8.6-1.armv7hl buteo-sync-plugin-caldav-0.1.35-1.armv7hl buteo-mtp-qt5-sync-plugin-0.4.16-1.armv7hl buteo-sync-plugin-carddav-0.0.24-1.14.1.armv7hl

@rinigus thanks for your help tracking this issue down, it's greatly appreciated. Please enable extra logging with msyncd by setting the environment variable MSYNCD_LOGGING_LEVEL=8, perhaps by adding it to /var/lib/environment/nemo/50-jolla-ui.conf (and note that you may also need to set /etc/systemd/journald.conf values RateLimitBurst=5000 and RateLimitInterval=5s and then reboot if you had to change those).

The journal can then be inspected for instances of the string "BackgroundSync" - see e.g. https://git.merproject.org/mer-core/buteo-syncfw/blob/master/msyncd/BackgroundSync.cpp#L107

Great work! Thank you very much. Let's hope some progress in the near-future updates. Because I'm just a happy end user, could you estimate how all the four cores influnce in for this excess power consumption? Jolla-1 has "only" two ones, that results to only 2 % battery drain over night in the flight mode.

Hi, Sailor_John_Doe! One question, what does it mean ”SLEEP MODE” on the picture? MSM8909 doesn't support real-time managment of ”sleep mode”. The core sets on-line or off-line (sleep) when the phone boots on. Best regards!

@Sailor_John_Doe: It looks to me that you have an app that starts periodically waking up the phone from 01:00. This is visible from the drop of CPU sleep % and increase in a overall CPU usage (as shown by frequency distribution). There is one more stat that would confirm this suspicion: Go to CPU details/CPU sleep and take a look on number "of Suspend events per second" and "Duration of a single suspend, s". If my hypothesis is right, you should see dramatic increase in number of Suspend events and decrease in the duration from 01:00.

Notice that the used CPU frequency is low during the wakeups, so, its probably caused by some app or service that wakes the phone, sees that there is nothing to do, and lets it fall asleep again for a little bit. So, the question is now, which part of the system or app is doing it. Maybe journal can help and you could see some messages from some app there?

PS: Note that in the last version of SystemDataScope there is a new mode allowing you to generate reports for pasting them into web sites. To use it, select the time window that you want to be covered in report (Time in pulley menu) and then, when in the mode showing graphs, choose "Report" from pulley menu. That would generate all plots covered by the program and save them under Documents/SystemDataScope. You could choose plots in Gallery app (plots are shown as 'photos') or email them by selecting plots by name. As soon as you are done, go and delete the folder Documents/SystemDataScope to clean up your Gallery photos list and free the storage.

@N9Sailfish: I think that in this case, the multiple cores are switched on during wakeup. Used frequencies are reported by following amount of time spent in each state and dividing by number of cores. These numbers could be underestimated if CPU cores are switched off between the readings and Linux kernel resets the stats to zero (that's what it does on Nexus 4). In this case, sum is about 12% that looks to be very close to 100-CPUsleep(88%). This suggests that wakeup was short and during this time all CPU cores were 'boosted' to work.

@Asmir: sleep is a difference between two kernel clocks: https://github.com/rinigus/collectd/blob/sailfish/src/cpusleep.c#L53 . It should show amount of time the prone is in "suspended state".

I am also in the feeling that this same occurs without flight mode operation , too. Eg., when I left Jolla C in the operation mode of 2G + mobile connection off + A Dalvik support off: the battery drain gets 5 to10 % over night. (And also if I have 2G + internet connections on, the battery drain gets 10- 20 % over night). Thus, when I'm sleeping, my Jolla C doesn't sleep at all. :)

Why internet connection is on also with 2G on? I have read for few years ago that it usual with modern smart phones that internet connection is automatically cut off when you are moving to 2G. With especially Jolla C I have received e-mails at night if I have forgotton to cut off internet connection with 2G mobile net !