[3.4.0.22] Voicecall-ui uses CPU on the background

[Manatus]

REPRODUCIBILITY: 3 tests out of 3
BUILD ID = OS VERSION (Settings > About product): 3.4.0.22
HARDWARE (Jolla1, Tablet, XA2,…): Xperia X Compact
UI LANGUAGE: Finnish
REGRESSION: (compared to previous public release: Yes, No, ?): Yes

DESCRIPTION:

Voicecall-ui stays constanly at 1.2 to 2.2 % CPU usage on the background.
This type of issue has happened with some earlier releases when something has been changed in the phone UI.

PRECONDITIONS:

No preconditions (any will do)

STEPS TO REPRODUCE:

1. Put the Sailfish device on the table, screen off.
2. Call to SailfishOS device using other phone.
3. Pick up the phone and answer to call.
4. After the call has been ended make sure the phone app is closed in UX and check the CPU usage using top command.

EXPECTED RESULT:

Voicecall-ui process is present but dormant.

ACTUAL RESULT:

Voicecall-ui is not dormant and uses 1.2 to 2.2 percent CPU constantly.

ADDITIONAL INFORMATION:

Previous similar bug happened with prefetch process of voicecall-ui after reboots, but you only needed to open up the phone app and then close it again, and that would fix assumed race condition.

This time only way to make voicecall-ui dormant again is to kill it from the command line and then open up the phone app once (to make it resident in the memory and operate faster in case of incoming calls).

[Fuzzillogic]

Same still happens on 4.3.0.12 on my XA2. It has a noticeable impact on battery life. I’m not sure if it always happens after having done a voice call. Restarting lipstick via the SFOS Utilities brings things back to normal.

I ran an strace, wrapped in time, for about 2 minutes when it happened. The phone was idle, display off, connected via SSH. The PID of offending voicecall-ui process was 20171 at that time.

[root@XperiaXA2 defaultuser]# time strace -p 20171 -c
strace: Process 20171 attached
^Cstrace: Process 20171 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 45.74    0.145000         103      1399         7 poll
 31.55    0.100000          17      5600           clock_gettime
 22.71    0.072000          25      2800      2800 recvmsg
  0.00    0.000000           0         8           restart_syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.317000          32      9807      2807 total
Command terminated by signal 2
real    1m 49.97s
user    0m 0.21s
sys     0m 1.02s

That are quite a lot syscall for an idle process, which, I guess, keeps at least one CPU constantly awake. After restarting the homescreen using Utilities, none of the voicecall-ui processes had a CPU usage of more than 0.0% according to htop.

[Fuzzillogic]

And to follow up on this, lipstick itself also suffers this problem from time to time. The trigger is unknown. Result of strace -c for lipstick:

[root@XperiaXA2 defaultuser]# time strace -p 20613 -c
strace: Process 20613 attached
^Cstrace: Process 20613 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 78.88    0.351000         206      1702         7 poll
 16.18    0.072000          10      6789           clock_gettime
  4.72    0.021000          12      1703           epoll_wait
  0.22    0.001000         125         8           restart_syscall
  0.00    0.000000           0         6           read
------ ----------- ----------- --------- --------- ----------------
100.00    0.445000          43     10208         7 total
Command terminated by signal 2
real    1m 58.88s
user    0m 0.18s
sys     0m 1.15s

Is this method useless, or does lipstick (and voicecall-ui) indeed do a lot of clock_gettime for some reason? Can anyone confirm? Something else I can try?

Again, a few percent cpu usage on one core might not seem a lot, but it amounts to (I guestimate) 1%-2% battery usage per hour.

[Fuzzillogic]

I can locally reproduce it on incoming calls. After the call, even when rejecting, a voicecall-ui process consumes CPU for no apparent reason. Only restarting home screen (or rebooting) fixes it. The number I’ve used for testing is present in Contacts, if that matters.

I now really wonder if this problem isn’t much more prevalent, as in, how many people have or complain about bad battery life, which might be caused by these problems? Only now that I actively monitor for it, I can link the cause and effect. I now know that I have to restart home screen after each (incoming) call.

[Steve_Everett]

Interesting … I have an XA2 on 4.3 and have often wondered why sometimes, with very similar usage, and at home on stable wifi, why I end some days on 25% or so battery and on others it is well over 50%.

[nephros]

There used to be a problem with dismissed notifications eating CPU. Reason there was a QML Animation that kept running in the background or some such [1].

Now, /usr/share/voicecall-ui-jolla/calling/IncomingCallViewBase.qml has something like this:

 38
 39     enabled: active || !readyForStateChange
 40     swipeEnabled: active && readyForStateChange
 41     opacity: (incomingCallView.active || incomingCallControlFadeoutTimer.running) ? 1.0 : 0.0
 42     Behavior on opacity { FadeAnimator { duration: 200 } }
 43

which is a very similar “Design Pattern”, and Use Case, to the one from the mentioned problem.

I wonder if commenting out line 42, and maybe even binding a visible property to active can solve the OP issue?

Oh, and should someone look into this, there’s a couple more to look at, and possibly some opportunities to go from a FadeAnimation to a FadeAnimator as recommended in [2]

rpm -ql voicecall-ui-jolla | grep qml  | xargs grep Behavi -C 1

[1] Screenshot leads to lipstick high CPU and battery drain
[2] Silica Reference Documentation - Sailfish OS

[direc85]

That sounds similar indeed… I’ll give it a try.

[nephros]

@direc85

That sounds similar indeed… I’ll give it a try

If it turns out that is indeed a problem that’s quite the can of worms. Applications are full of those opacity: maybe ? 1 : 0; Behavior on opacity { FadeAnimator{} } patterns.

[direc85]

But only few of them are problematic. What’s the culprit here…

[Fuzzillogic]

I’m on 4.4.0 now, and the problem still persists. And it’s getting annoying, tbh. And, I wonder if this is what makes people complain about bad battery life, like this thread.

[Manatus]

I got my Xperia 10 iii and flashed it to SFOS 4.4. I could not reproduce this as easily as it did by the time of creation of the original issue.

EDIT:
Oh well, I only had to make few calls in both directions and end calls, and the issue is back. I think it might depend on who makes and who ends the call.

[flypig]

Thanks for the bug report and for all the additional helpful info. This is now logged in our internal bug tracker too, so I’ve tagged it as “tracked”.

[KuroNeko]

Can reproduce this on an Xperia X Compact too with 4.4.0.

[andreyv]

As a workaround, one can configure systemd to restart the service every hour or so. Run systemctl --user edit voicecall-ui-prestart.service and enter

[Service]
RuntimeMaxSec=3600

then run systemctl --user daemon-reload. After this systemctl --user cat voicecall-ui-prestart.service should show both the original unit file and your override.

Of course, if you are on a call at the moment it gets restarted…