Apps can keep screen lit permanently

[Andrea Bernabei]

rc-proposed, r140, krillin

There are times when it seems the display blanking policy stops working and the display stays on until I press the power button.

Steps to reproduce:
* install and start Siete
* put it in background

Expected outcome:
* the display is switched off after a predetermined amount of time

Actual outcome:
* the display stays on forever

======

Now that apps can request the screen to stay on, they can do so regardless of whether they're focused/visible or not.

[Andrea Bernabei (faenil)]

phablet@ubuntu-phablet:~$ sudo powerd-cli list
[sudo] password for phablet:
System State Requests:
  Name: com.canonical.Unity.Screen, Owner: :1.13, State: 1
  Name: active, Owner: :1.75, State: 1

[Andrea Bernabei (faenil)]

backtrace of all threads
http://pastebin.ubuntu.com/12638455/

[Andrea Bernabei (faenil)]

phablet@ubuntu-phablet:~$ dpkg -s unity-system-compositor
Package: unity-system-compositor
Status: install ok installed
Priority: optional
Section: x11
Installed-Size: 8595
Maintainer: Ubuntu Developers <email address hidden>
Architecture: armhf
Version: 0.1.3+15.04.20150925.1-0ubuntu1
Depends: libandroid-properties1, libboost-system1.55.0, libc6 (>= 2.12), libdbus-1-3 (>= 1.1.1), libegl1-mesa (>= 7.8.1) | libegl1-x11, libgcc1 (>= 1:4.4.0), libgles2-mesa (>= 7.8.1) | libgles2, libglib2.0-0 (>= 2.12.0), libmirclient9 (>= 0.16.0+15.04.20150921.1), libmircommon5 (>= 0.16.0+15.04.20150921.1), libmirserver34 (>= 0.16.0+15.04.20150921.1), libstdc++6 (>= 4.8.1)
Suggests: powerd
Conffiles:
 /etc/dbus-1/system.d/com.canonical.Unity.conf 9e9079b711245540b60169ad6769fa41
Description: System compositor for Ubuntu
 System compositor used by the Mir display server in Ubuntu. If the Unity
 System Compositor can't start, LightDM will fallback to plain Xorg display
 server.
Homepage: https://launchpad.net/unity-system-compositor

[Andrea Bernabei (faenil)]

I think this happens when I receive Text messages notifications (SMS)

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Pat McGowan (pat-mcgowan)]

Last time we saw somethign similar was bug #1391230 in case it helps

[kevin gunn (kgunn72)]

ok, i've been running a script to text, blank at various intervals (including various power button & manual app sessions) for the last 24+hrs on krillin - it's still blanking fine on it's own.

mzanetti reported he no longer sees this after his update this morning.
Would like to know if anyone is experiencing this on the ota7 candidate.

[Pat McGowan (pat-mcgowan)]

I just got this on an MX4 running proposed 136
Browser messaging and settings are running
Phone has not been rebooted for several days

powerd-cli list
System State Requests:
  Name: active, Owner: :1.42, State: 1
  Name: com.canonical.Unity.Screen, Owner: :1.14, State: 1

[Pat McGowan (pat-mcgowan)]

Mapping the dbus name on :1.42 with
sudo dbus-send --print-reply=literal --system --dest=org.freedesktop.DBus /org/freedesktop/DBus org.freedesktop.DBus.GetConnectionUnixProcessID string:":1.42"
shows it is unity8

[Pat McGowan (pat-mcgowan)]

sudo powerd-cli stats
System Request Statistics:
                                        Active Max Active
  Owner Name Count Active Time Time Active Since
  :1.23 usensord 61 150.659522 25.733926 0.000000
  :1.42 active 14 5436.939907 3336.396409 69890.487776
  :1.14 com.canonical.Unity. 25 5938.348581 3675.032031 69887.448441
  :1.90 ubuntu push client 256 1697.831991 60.090916 0.000000
  :1.60 media-hub-playback_l 2 8.897788 4.466588 0.000000

[Pat McGowan (pat-mcgowan)]

after gdb to usc we found the culprit is the webbrowser-app, suspecting the new feature to play in the background added to oxide

[Michał Sawicz (saviq)]

We need unity8 to proxy the screen request to u-s-c on behalf of the app, clearing it when the requesting app goes out of focus/view.

Webbrowser app still needs investigation as it should behave correctly here, but it might not get enough time to release the screen lock.

[Olivier Tilloy (osomon)]

Oxide (the web engine under webbrowser-app) is the one that issues a request to prevent screen blanking when playing a video.
It has code to handle releasing the lock when the app goes into the background, so unless the signal doesn’t reach oxide in time before the process is stopped, the lock should be released as expected.

See oxide::PowerSaveBlocker::ApplicationStateChanged() in http://bazaar.launchpad.net/~oxide-developers/oxide/oxide.trunk/view/head:/shared/browser/oxide_power_save_blocker.cc#L238.

[Alexandros Frantzis (afrantzis)]

I have found a way to deterministically reproduce the issue with webbrowser-app. Perhaps there are other scenarios that are problematic, but hopefully this will at least provide some hints. Below are the steps and between them the USC logs I get for each step, which give some insight into what is going wrong.

[TL;DR]

The problem seems to be that, for some reason, if after the screen is turned on and logging in the webbrowser is in focus and playing a video (which means that the user previously turned off the screen with the power button while playing a video in the browser) the webbrowser app leaks (doesn't eventually release) two keepDisplayOn requests ids. This causes the screen to stay on even when focusing away from it.

[Detailed analysis]

1. Start browser, start watching a youtube video. The browser requests keepDisplayOn twice from two different dbus connections, which is strange, but OK.

[1444841076.023016] usc::UnityScreenService: Received request with serial 3 from :1.300 : keepDisplayOn
[1444841076.023390] usc::UnityScreenService: Sending reply for serial 3 to :1.300 id: 9
[1444841077.052913] usc::UnityScreenService: Received request with serial 3 from :1.301 : keepDisplayOn
[1444841077.053164] usc::UnityScreenService: Sending reply for serial 3 to :1.301 id: 10

2. Turn off screen with power key. Everything is normal the keepDisplayOn requests are released.

[1444841087.268477] usc::UnityScreenService: Received request with serial 4 from :1.300 : removeDisplayOnRequest id: 9
[1444841087.274530] usc::UnityScreenService: Received request with serial 4 from :1.301 : removeDisplayOnRequest id: 10

3. Turn on screen with power key, log in, video should resume. Strange things happen here, note the extra keepDisplayOn requests this time (4 vs 2 before, and they are all from webbrowser-app)

[1444841106.885474] usc::UnityScreenService: Received request with serial 3 from :1.302 : keepDisplayOn
[1444841106.885997] usc::UnityScreenService: Sending reply for serial 3 to :1.302 id: 11
[1444841106.889124] usc::UnityScreenService: Received request with serial 3 from :1.303 : keepDisplayOn
[1444841106.889333] usc::UnityScreenService: Sending reply for serial 3 to :1.303 id: 12
[1444841106.895151] usc::UnityScreenService: Received request with serial 3 from :1.304 : keepDisplayOn
[1444841106.895258] usc::UnityScreenService: Sending reply for serial 3 to :1.304 id: 13
[1444841106.900406] usc::UnityScreenService: Received request with serial 3 from :1.305 : keepDisplayOn
[1444841106.900471] usc::UnityScreenService: Sending reply for serial 3 to :1.305 id: 14

4. Focus away from webbrowser (e.g. go to scopes). webbrowser-app requested 4 keepDisplayOn ids but releases only 2, which causes the screen to stay on.

[1444841117.298103] usc::UnityScreenService: Received request with serial 4 from :1.304 : removeDisplayOnRequest id: 13
[1444841117.307436] usc::UnityScreenService: Received request with serial 4 from :1.305 : removeDisplayOnRequest id: 14

[Olivier Tilloy (osomon)]

Thanks for the detailed analysis Alexandros. I am able to reproduce the issue reliably on my arale, looking into it.

Note that the fact that keepDisplayOn is requested twice is expected: chromium instantiates one PowerSaveBlocker per stream, so for a video with audio, that’s two streams, hence two requests. Perhaps not the most efficient thing to do, but it should be okay as long as the corresponding removeDisplayOnRequest requests are emitted where relevant.

[Olivier Tilloy (osomon)]

I have instrumented oxide, and I’m seeing the following:

Start playback of video, two instances of PowerSaveBlocker (one for video, one for audio) are created and request a lock:

[1015/201111:INFO:oxide_power_save_blocker.cc(260)] PowerSaveBlocker::PowerSaveBlocker() 0xb8d11938 : Playing video
[1015/201111:INFO:oxide_power_save_blocker.cc(88)] PowerSaveBlocker::Init() 0xb8d11938 : -1
[1015/201111:INFO:oxide_power_save_blocker.cc(107)] PowerSaveBlocker::ApplyBlock() 0xb8d11938 : -1
[1015/201111:INFO:oxide_power_save_blocker.cc(157)] PowerSaveBlocker::ApplyBlockUnityScreenService() 0xb8d11938 : 3

[1015/201111:INFO:oxide_power_save_blocker.cc(260)] PowerSaveBlocker::PowerSaveBlocker() 0xb8a15ad0 : Playing audio
[1015/201111:INFO:oxide_power_save_blocker.cc(88)] PowerSaveBlocker::Init() 0xb8a15ad0 : -1
[1015/201111:INFO:oxide_power_save_blocker.cc(107)] PowerSaveBlocker::ApplyBlock() 0xb8a15ad0 : -1
[1015/201111:INFO:oxide_power_save_blocker.cc(157)] PowerSaveBlocker::ApplyBlockUnityScreenService() 0xb8a15ad0 : 4

Press power button, the two PowerSaveBlocker instances correctly release their locks, as expected:

[1015/201117:INFO:oxide_power_save_blocker.cc(99)] PowerSaveBlocker::CleanUp() 0xb8d11938 : 3
[1015/201117:INFO:oxide_power_save_blocker.cc(99)] PowerSaveBlocker::CleanUp() 0xb8a15ad0 : 4
[1015/201117:INFO:oxide_power_save_blocker.cc(119)] PowerSaveBlocker::RemoveBlock() 0xb8d11938 : 3
[1015/201117:INFO:oxide_power_save_blocker.cc(119)] PowerSaveBlocker::RemoveBlock() 0xb8a15ad0 : 4

Press power button again to wake screen, unlock screen, playback resumes but Init() appears to be called twice on each instance:

[1015/201130:INFO:oxide_power_save_blocker.cc(88)] PowerSaveBlocker::Init() 0xb8d11938 : -1
[1015/201130:INFO:oxide_power_save_blocker.cc(88)] PowerSaveBlocker::Init() 0xb8a15ad0 : -1
[1015/201130:INFO:oxide_power_save_blocker.cc(107)] PowerSaveBlocker::ApplyBlock() 0xb8d11938 : -1
[1015/201130:INFO:oxide_power_save_blocker.cc(88)] PowerSaveBlocker::Init() 0xb8d11938 : -1
[1015/201130:INFO:oxide_power_save_blocker.cc(88)] PowerSaveBlocker::Init() 0xb8a15ad0 : -1
[1015/201130:INFO:oxide_power_save_blocker.cc(157)] PowerSaveBlocker::ApplyBlockUnityScreenService() 0xb8d11938 : 5
[1015/201130:INFO:oxide_power_save_blocker.cc(107)] PowerSaveBlocker::ApplyBlock() 0xb8a15ad0 : -1
[1015/201131:INFO:oxide_power_save_blocker.cc(157)] PowerSaveBlocker::ApplyBlockUnityScreenService() 0xb8a15ad0 : 6
[1015/201131:INFO:oxide_power_save_blocker.cc(107)] PowerSaveBlocker::ApplyBlock() 0xb8d11938 : 5
[1015/201131:INFO:oxide_power_save_blocker.cc(157)] PowerSaveBlocker::ApplyBlockUnityScreenService() 0xb8d11938 : 7
[1015/201131:INFO:oxide_power_save_blocker.cc(107)] PowerSaveBlocker::ApplyBlock() 0xb8a15ad0 : 6
[1015/201131:INFO:oxide_power_save_blocker.cc(157)] PowerSaveBlocker::ApplyBlockUnityScreenService() 0xb8a15ad0 : 8

I’m suspecting that Init() is called once by chromium itself when it resumes the paused playback, and a second time in the meantime by the code that handles application state changes, when oxide detects that the application got focused.

This is a bug in oxide: a call to Init() should bail out if another Init() has alrea...

[Michał Sawicz (saviq)]

I'm reopening the unity-system-compositor task, because the bug still exists there. Even if oxide will lift the screen lock when unfocused, who's to say other apps will behave well, too?

We need to make sure that only the foreground app can request a screen lock, which means we need to refactor how it works and have the shell proxy the requests to u-s-c.

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

I have seen this (screen lit and never goes blank) in OTA-7, bq aquaris 4.5. I simply cancelled an alarm, and it happened. syslog attached,

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Andrea Bernabei (faenil)]

this just happened again to my krillin, rc-proposed, r181

sudo dbus-send --print-reply=literal --system --dest=org.freedesktop.DBus /org/freedesktop/DBus org.freedesktop.DBus.GetConnectionUnixProcessID string:":1.77"
reports unity8

[Pat McGowan (pat-mcgowan)]

Per comment #17 this is not fully fixed

[Bill Filler (bfiller)]

still seeing this issue on krillin, and it's very easy to reproduce:

1) launch a few apps, system-settings, messaging-app, address book
2) put phone to sleep
3) send a text message to the phone or recv some other kind of notification (gmail, telegram, etc)

Expected Results:
- phone screen turns on for notification and then goes back sleep in some seconds

Actual Results:
- phone screen turns on for notification and never goes back to sleep

[Bill Filler (bfiller)]

It's very easy to reproduce now. Just run an app that requests the screen to stay on, in my case ubuntu-silo-installer (click package attached).

Steps to reproduce:
- launch the app
- press the power button to lock the phone/dim the screen
- now send a text message to the phone

Expected results
- screen turns on for notification, then goes black after timeout

Actual results:
- screen turns on for notification then stays on

Seems to happen even if you move the app to the background before turning off the screen.
Whenever the screen is locked or hte app is moved to the background we should remove the lock that is causing the screen to stay on.

[Bob Harvey (bobharvey)]

M10 tablet, OTA13

I had not seen this problem until I installed OTA13.

Now my screen never blanks.

I pretty much only use the web browser app.

[Alexandros Frantzis (afrantzis)]

Bob, could you please attach /var/log/repowerd.log and /var/log/syslog to this bug. It could help us debug this issue.

[Pat McGowan (pat-mcgowan)]

The original report for the browser was closed some time ago so I suggest we need a new bug.

Per comment #27 this may be a new behavior with the new repowered in ota13. (I added lp:1630986)

Per comment #25 I think this is actually functioning as intended, if an app sets display on and is an active app we honor it. What is missing IMO is any indication that this is the state of the display. Also would be nice to add display on to the app permissions controlled via settings.(lp:1630989)