battery life time

[pagism]

Not systematically measured, I had overnight battery level drop from 89% to 60%, on stock OEM ROM the drop was below 5% as far as I remember. I will add new measurements over the next days.

[rinigus]

Its related to #27

Checked today and on 3.2.1.20

State right now:

• flight mode is fine, suspend times are exactly as they should be.
• without network but calls allowed, during night, I've got discharge for about 4% with sleep times on average ~12s (from 10-30s typical, max 70s).
• with network (cellular) and sometimes use (day), we are talking about 7s suspend times (below 15s all).

I do wonder whether AOSP has longer suspend times with SIM card active and network used.

[pagism]

not sure about suspend time, I guess you're referring to mobile network connection, in my case I had no sim card in, only wifi.

[rinigus]

WiFi is difficult to debug, usually its worse than on cellular data.

Was stock with WIFI as well? Do you have some network accounts configured? Are they pulling with some time interval or set to 'always on'? Were the account settings the same for AOSP and SFOS?

Realistically, we can work on getting parity without network. With network, you get too many variables and SFOS doesn't have push data support from Google servers, as Android has. Assuming that you used Android with Google apps installed

[pagism]

Same conditions, Android had a basic google account no other installations, wifi was on, no sim card. On SFOS X I had a "mixed" upgrade to 3.2.1.20, wifi on, jolla account enabled, weather app, and telegrame which was not running. I had also installed collectd/RRDtool but I could not make it running, so it might had be running in background? I've removed them now. I need to be more systematic tho, I will try to measure things with both wifi/wlan off, just the SFOS idling.

[rinigus]

Do you have any email/calendar accounts enabled?

Let's see if you have anomalies without WIFI or other connections. That's something which should be easy to check.

As for collectd/rrdtool: you have to install https://openrepos.net/content/rinigus/systemdatascope and go through its config (see very short version and just follow that in its start screen). Without that config, it will not run by itself. I, obviously, use that for monitoring the system and that's why I could pull out the stats. Quite handy for such debugging

[pagism]

no email/calendar accounts enabled yet, developer mode is on, but I will turn off ssh and lets see what we get.

I am a bit suspicious of system monitoring tools overhead, we can start with an empty system, then I can add monitoring tools and find their overhead, then services.

[rinigus]

@pagism: sure, you could start without system monitoring. collectd is rather gentle usually, unless system config is wrong (as it was before I updated it to take into account differences in storage of XZ2 when compared to older models).

My data is acquired with collectd running on each boot

[rinigus]

To get some stats, unless you want to use collectd, you could use the following:

Recordings have to be done before and after the interval. These are:

cat /sys/kernel/debug/suspend_stats
mcetool --get-suspend-stats

The first one will give you number of suspend attempts: success and fail. The second one will tell you how much uptime (wall clock) and out of it time in suspend. We will need increase in suspend_time divided by increase in success. That way you can get average time of a single suspend.

Try to find that out together with battery % drop per hour with and without WIFI.

[pagism]

46% in 4hours (64-18), wifi off, no sim, it's too high by any means. Unless i did something horribly wrong.

Anyway, i need to be more systematic, it's charging now, i will use the stats you suggested tomorrow.

[rinigus]

This is VERY bad. Sometimes, trackers go on after updates, but probably you don't have too many files over there.

Check if you get suspended at all (mcetools) and which processes are high in top. Try to reboot as well. Without network, I have very low consumption, as described above.

[pagism]

no chance to get stats overnight, battery depleted from 55% to ~0 in 4h 41m, no low battery sound notification either (unless i missed it)

[pagism]

After some charging I managed to get some stats over a 2 hour period: initial conditions, booting after charging, wifi off, no sim, no email or calendar accounts yet initial charge 83% dropped to 79% after 1st hour, and after 2nd hour at 78%

success: 0
fail: 0
failed_freeze: 0
failed_prepare: 0
failed_suspend: 0
failed_suspend_late: 0
failed_suspend_noirq: 0
failed_resume: 0
failed_resume_early: 0
failed_resume_noirq: 0
failures:
  last_failed_dev:  

  last_failed_errno:    0
            0
  last_failed_step: 

uptime:       276.904 
suspend_time: 0.000 
[nemo@Sailfish ~]$ more 2.log
success: 77
fail: 9
failed_freeze: 9
failed_prepare: 0
failed_suspend: 0
failed_suspend_late: 0
failed_suspend_noirq: 0
failed_resume: 0
failed_resume_early: 0
failed_resume_noirq: 0
failures:
  last_failed_dev:  

  last_failed_errno:    -16
            -16
  last_failed_step: freeze
            freeze
uptime:       3832.032 
suspend_time: 3210.793 
[nemo@Sailfish ~]$ more 3.log 
success: 99
fail: 11
failed_freeze: 11
failed_prepare: 0
failed_suspend: 0
failed_suspend_late: 0
failed_suspend_noirq: 0
failed_resume: 0
failed_resume_early: 0
failed_resume_noirq: 0
failures:
  last_failed_dev:  

  last_failed_errno:    -16
            -16
  last_failed_step: freeze
            freeze
uptime:       7487.509 
suspend_time: 6697.179

[rinigus]

Changes between 2 and 3 look perfect:

>>> dtw = 7487.509-3832.032
>>> dts = 6697.179-3210.793
>>> dts/dtw
0.9537431093124099
>>> dts/(99-77)
158.4720909090909

So, we have 95% in suspend (dts/dtw) and average suspend time is 158 seconds. You maybe have hit some anomaly with trackers or such. Let's wait a bit and see if it will normalize now on low battery consumption without WIFI

[pagism]

agrr, I turned on wifi, I can run the tests again tho, I have current charge ~80%, I will reboot the device, turn wifi off and keep monitoring every hour, how long do you want me to run the tests?

[rinigus]

no worries, use it as usual with WIFI and then check it for use with WIFI. During a night, let's switch off WIFI and test it in these conditions.

[ApostolosB]

I'll just chine in and say that everything seems to behave normal regarding battery life (wifi on, always up to date account).

[pagism]

in my case the phone has an oled screen and it's not easy to identify whether battery consumption is from the screen itself or a rogue service, besides I would like to have wake up on proximity/double tap, and maybe enable notifications. however, I suspect higher battery consumption on xz3 due to its screen technology as current SFOS ambiences are not tuned for such screens. unless you want me to test something else I plan to monitor core activity for idling wifi on/off wan on/off.

[rinigus]

My previous SFOS phone had OLED as well (OnePlus X) and everything was fine with it. So, it shouldn't be an issue. I would more suspect 'rogue service' as a culprit. Let's see if you keep getting such high consumption without net first.

Re double tap and proximity: should be possible to enable using mcetools (proximity), double tap would require something on kernel side. I presume it is there for XZ3, but I am not 100% sure - you will have to see if there are some settings on AOSP.

However, let's get battery consumption under control first.

[ApostolosB]

Regarding double tap (you cant imagine how many times i double tapped the screen on the xperia :smile: :) i filed this > https://github.com/sonyxperiadev/bug_tracker/issues/511

No answers yet.

[pagism]

in stock Sony ROM the screen on idle was switched off, approaching a hand above the screen was turning a minimum set of notifications on screen and a double tap or a swipe was unlocking or something like that. I think such behaviour should be possible regardless screen technology, providing certain sensors are on? it's not urgent, maybe we need a new issue for this.

[pagism]

@ApostolosB I still double tap on every black screen i have, bad habit from N9 days

[rinigus]

Let's keep double tap, wake on lift, to separate issue(s). Its something that we should add, but I am not sure its supported on AOSP.

[pagism]

I will soon have idling stats for 7 hours, do we need more of those before moving to wifi tests?

[rinigus]

should be fine. So, what are the results?

[pagism]

battery logs battery.log

[pagism]

on idle test run for 7.5h battery level dropped from 80% to 66%

[rinigus]

During those 7 hours, was it just laying still and nobody using it? If all radios are off, I would expect it to behave better. Right now we have only 60% of suspend, that's rather little.

If the phone is without radios (wifi, no sim, no nfc, no bt), I would be targeting something like 5% decrease during that time. And suspend should be > 90%, probably ~95%. So, I suggest to test during a night again. Maybe enable flight mode to be sure.

[pagism]

exactly, no wifi, no sim, no nfc, no bt, so I think consumption is a bit high

[pagism]

I hope I did the maths right, I used a quick awk script to parse log file Date, Battery level, success, uptime, suspend, dtw, dts, dtw/dts, dts/dtsuccess Mon 23 Dec 10:14:59 GMT 2019 80% 0 48.845 0.000 48.845 0 48845 0 Mon 23 Dec 11:16:27 GMT 2019 80% 343 3736.602 2254.657 3687.76 2254.66 1.63562 6.57332 Mon 23 Dec 12:15:49 GMT 2019 78% 674 7298.157 4455.129 3561.56 2200.47 1.61854 6.64793 Mon 23 Dec 13:15:22 GMT 2019 76% 1070 10871.349 6452.901 3573.19 1997.77 1.78859 5.04487 Mon 23 Dec 14:15:23 GMT 2019 74% 1483 14472.132 8371.804 3600.78 1918.9 1.87648 4.64624 Mon 23 Dec 15:15:09 GMT 2019 73% 1512 18058.153 11803.986 3586.02 3432.18 1.04482 118.347 Mon 23 Dec 16:35:49 GMT 2019 69% 2083 22898.344 14377.113 4840.19 2573.13 1.88105 4.50634 Mon 23 Dec 17:38:02 GMT 2019 67% 2541 26631.608 16250.206 3733.26 1873.09 1.9931 4.08971 Mon 23 Dec 17:53:15 GMT 2019 66% 2652 27544.212 16663.675 912.604 413.469 2.20718 3.72491

[pagism]

I have not done anything else but using a rolling alarm every hour, from another device, to unlock screen, open the terminal app and invoke the log script. There is a strange result tho at 15:15.

At that time. I left work and I was walking to car park. when I unlocked the screen the terminal app failed to start, (similar to the issue #51) on second time terminal started without issues.

[rinigus]

We are looking at dts/dtw - time in suspend / real time (wall time). in your script you don't show number of success wakeups (dtsuccess in your notation, if I understood correctly).

That result at 15:15 is something we are targeting - about 95% of time is spent in suspended state.

When I get to working on suspend issue, I will refresh my memory on how to track it. If you wish, you could read up on Android wakelocks, suspend and how to debug it. We will have to figure out what's causing it.

[pagism]

I messed up dtw/dts, it had to be the otherway around, OK, I will have a look success is the column after battery level %

[pagism]

cat /sys/kernel/debug/wakeup_sources might give more info, i will include that info next to logs file too

[rinigus]

That's a good idea. Please also check out what does each column show specifically. I was reading on it a while ago and have forgotten most of it...

[pagism]

here are the stats from last 12h+ with flight mode on:

Date, Duration, Battery level, success, uptime, suspend, dtw, dts, dtw/dts, dts/(dt success)
2019-12-23T21:16:25 0 97% 277 1590.480 760.369 1590.48 760.369 0.478075 2.745
2019-12-23T22:15:45 3560 97% 288 5150.782 4240.790 3560.3 3480.42 0.977563 316.373
2019-12-23T23:15:49 3604 96% 302 8754.525 7777.414 3603.74 3536.62 0.981375 252.598
2019-12-24T00:21:06 3917 96% 312 12672.071 11623.134 3917.55 3845.72 0.981665 384.534
2019-12-24T02:46:20 8714 96% 332 21385.300 20230.582 8713.23 8607.45 0.98786 430.351
2019-12-24T06:33:43 13643 95% 361 35028.126 33662.047 13642.8 13431.5 0.984507 463.138
2019-12-24T08:30:00 6977 94% 377 42005.462 40517.122 6977.34 6855.08 0.982477 428.415
2019-12-24T10:29:29 7169 93% 397 49174.495 47560.137 7169.03 7043.01 0.982422 352.133

It looks ok, I will continue testing with wifi on now. for reference log files added flight_mode.zip

[rinigus]

Excellent! I think we can conclude that in this mode all is OK now.

[pagism]

wakeup_sources columns

name: 
The tag specified for the wakeup source. Usually the name of a driver. 
For wakelocks, this is the tag provided by the framework

active_count Counts:
how many times the wake lock has been active

event_count: 
Counts how many times the wakeup source event was triggered

wakeup_count: 
Counts how many times the wakeup source has forced a device wakeup. For  wakelocks: 0

expire_count: 
Counts how many times the wakeup source has expired. For wakelocks: 0

active_since: 
Count in jiffies (timer ticks) specifying since when source was active

total_time: 
Count in jiffies specifying total time source was active

max_time: 
Max time this source has been continuously active

last_change: 
Timestamp of when source activity was last changed

prevent_suspend_time: 
How much time could have been saved in suspension if not for this source.
This is especially useful for figuring out the impact on battery life

[pagism]

wifi_on.zip stats with wifi on, no apps running, peridically (~1h) device wake up manually, open terminal and run stats script. Over a period of 9h battery level dropped by 2% per hour.

Date, Duration, Battary level, success, uptime, suspend, dtw, dts, dtw/dts, dts_avg
2019-12-24T10:48:26, 0, 93%, 517, 50311.966, 48209.363, 50312, 48209.4, 0.958209, 93.2481
2019-12-24T11:48:31, 3605, 91%, 968, 53916.163, 50115.225, 3604.2, 1905.86, 0.528789, 4.22585
2019-12-24T12:54:02, 3931, 88%, 1486, 57847.141, 52205.560, 3930.98, 2090.33, 0.531759, 4.03539
2019-12-24T13:55:40, 3698, 86%, 1938, 61545.855, 54230.256, 3698.71, 2024.7, 0.547405, 4.47941
2019-12-24T14:57:26, 3706, 84%, 2411, 65251.576, 56320.833, 3705.72, 2090.58, 0.564148, 4.41982
2019-12-24T15:51:09, 3223, 83%, 2777, 68474.430, 58307.165, 3222.85, 1986.33, 0.616327, 5.42712
2019-12-24T17:01:12, 4203, 80%, 3330, 72677.107, 60504.212, 4202.68, 2197.05, 0.522773, 3.97295
2019-12-24T17:54:54, 3222, 78%, 3691, 75899.258, 62397.664, 3222.15, 1893.45, 0.587636, 5.245
2019-12-24T19:09:23, 4469, 76%, 4242, 80368.475, 64946.886, 4469.22, 2549.22, 0.570396, 4.62653
2019-12-24T19:56:04, 2801, 74%, 4633, 83169.506, 66477.484, 2801.03, 1530.6, 0.546441, 3.91456

wakeup_sources data for those timestamps are also collected.

[pagism]

I do not know how to analyse logs yet, but a rough estimation between flight vs wifi mode form battery level and prevent_suspend_time numbers shows a ratio of 5:1

agrr! I have done a mistake, wifi measures followed flight mode ones without reboot ;( that means counters on wakeup_sensor log files are started with an "offset"

[rinigus]

@pagism : I think those are expected values, more or less OK. So, it looks like that drain you experienced earlier was not reproduced in the last tests. Your values are also similar to what was reported by ljo at TMO, with WIFI. Its OK to have offset, we can correct for it.

Thanks for collecting logs, those will be useful for later tuning, I think.

[pagism]

there is nothing outstanding, compared to XA2 or stock rom consumption is higher, it's good to have the logs tho. I will also try to get another set of logs with wan only on, and wan+wifi on.

[rinigus]

Can toy provide a guess when comparing with stock how much larger is the consumption by SFOS? That way we will have a target...

[pagism]

unfortunately I have not recorded that, I had the phone for a couple of days before flashing, just basic registration and wifi enabled. Overnight consumption was 3-5% if I remember correctly. there are several ways we can test things, e.g. reinstall stock rom, vs aosp_9, vs XA2 SFOS?

[rinigus]

No problem, I can ask at XDA. There is a hope for new SFOS users who may tell us what was battery consumption on stock/AOSP vs SFOS.

[pagism]

I was thinking of that, if you put a note in flashing instructions for ppl to monitor and record consumption before flashing?

[rinigus]

Relevant report: https://forum.xda-developers.com/showpost.php?p=81414901&postcount=33

[pagism]

I think this is a relevant TJC issue to watch: xperia-10-battery-consumption/. Hopefully next update will bring some improvements.

[rinigus]

Probably. But those popup quite frequently, unfortunately. And its hard to debug those. Although, looks like they have similar short-sleep issues as we have. I'll keep an eye and start looking into our port

[pagism]

Indeed it's hard, my feeling is that XZ3 consumption is above normal levels. I get the feeling that xperia 10 from those reports has a similar issue. At the same time XA2 has an excellent battery life (larger battery tho). XA2 is baseport-8 the other ones baseport-9.

[pagism]

There is an answer in xperia-10-battery-consumption which claims the fingerprint as cause of increased battery consumption.

/vendor/etc/init/android.hardware.biometrics.fingerprint\@2.1-service.sony.rc in xz3 is not disabled, but equally so there there is no sailfish-fpd.service service running.