SMS notifications are received only when the phone is unlocked

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

Please add info as to which device and os version
also if you can add the logs /var/log/sysslog and .cache/upstart/unity8.log when this occurs.

Two fixes in ota 7 were made to address similar issues bug #1491566 and bug #1495871

My phone is bq Aquaris E5 HD with the latest version which is the OTA-7.
I'll attach here the logs when I encounter it again.

I attached the log file when it occurred.
Almost 30 mins after the message was received based on the notification's time.

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

Any news on this? Will this be fixed on OTA 9?
It's still affecting my phone. If it won't be fixed in the next OTA, I might just try to reflash since it seems that only few experience this.

@Kugi no work has been done for this as it has not been reproduced

From the unity8 log the only thing that looks suspect is a number of reports like
qtmir.surfaces: MirSurfaceItem::dropPendingBuffer() surface = qtmir::MirSurface(0x1411348) buffer dropped. 0 left.

Were you playing a lot of music perhaps in the background before this occurs?
Were you testing the app you were developing at the time?
Can you enable crash reporting and then check in /var/crash if it recurs
Also please grab the logs from /var/log/lightdm

I have experienced the same for Telegram and gmail notifications too. No sound alert and screen doesn't turn on, but as soon as I press the power button to turn the screen on, message tone is heard and all the notifications bubbles keep popping up one after another.

but the LED notification light blinks all right

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

I am not sure if it's the same bug, but for me (E5, OTA-12), I do not get sound notification at all (sometimes I do though), even if device is unlocked.

I do hear vibrator, see green blinking light, but no sound. I am quite sure that Sound options are set OK.

I've attached tailed syslog.log and unity8.log.

@Vincas that's probably bug #1544477

Yep, thanks Anupam!

@anupam or michal do you have a syslog for when this occurs?

This is a syslog where this occured... a whole 10MBs of it. There's three texts within the last 5 minutes, the first one only "arrived" straight after I woke the phone up, the next two arrived fine despite the phone being, afaict, asleep.

couple of observations which may or may not turn out to be relevant

This was reported with systems running powerd and repowerd so seemingly not an issue at that level.

Both logs show that at some point prior to the undelivered message the modem connection was lost and reconnected. I was looking for some evidence that the modem stopped being a wakeup source. Grep for "active wakeup source" shows radio-interface when the last two texts work and not when the third to last did not. Nothing solid here though.

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

Can you guys please pop this job into ~/.config/upstart/ and go:

$ start msg-monitor

When you notice the problem again, please attach ~/.cache/upstart/msg-monitor.log - make sure to strip it of any sensitive data (phone numbers, message contents)

In the case I had just now, it took 20s for the message to go from Telepathy to the notification: http://pastebin.ubuntu.com/23211882/

The flow is ofono -> telepathy-ofono -> telephony-service-indicator -> Notification

My guess is that telephony-service-indicator could be stuck for some reason (waiting on some dbus call to finish or something like that).

@michal

Wed Sep 21 17:38:20 CEST 2016 signal sender=:1.23 -> dest=(null destination) serial=367 path=/org/freedesktop/Telepathy/Connection/ofono/ofono/connection_7c44ac9b07d50cda2984b65f48bc8c5f/TextChannel2; interface=org.freedesktop.Telepathy.Channel.Interface.Messages; member=MessageReceived

Wed Sep 21 17:39:41 CEST 2016 method call sender=:1.40 -> dest=:1.58 serial=30 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=Notify

Thats 1 min and 20 secs!

As the default activity timeout is 1 min, that would cause the symptom as the phone would suspend before delivering the message. It would then show up on power on.

@Pat sorry, I didn't understand the technical details. My question: is this applicable for SMS notifications only, or Telegram notifications can also be delayed (till the next screen wake up) for the same/similar reason? I sometimes have this problem with Telegram notifications, so wondering whether the same issue or a different bug.

@anupam we still need to root cause this. The telegram code path is quite different since it uses a push-helper, but lets see but I suspect different issues

lp:1588526 is a very similar symptom

So, while debugging this issue I found the following:

The delay seems to be bigger if wifi is disabled. If wifi is enabled, after 1:30 at most the device wakes up, and if no wifi, device seems to remain off indefinitely (I waited only for 10 minutes then gave up). In my case, it's krillin and I have only one sim in the second slot. At first I thought that could be lack of entropy and the system would be stuck trying to read from /dev/urandom, but turns out this is what I found:

1) oFono delivers the message to telepathy-ofono right away.
2) telepathy-ofono informs telepathy about the new message.
3) telephony-service-indicator gets the message, sets a timer (QTimer::singleShot()) of 1.5 seconds before displaying the message (that's to avoid displaying notifications for messages that were already displayed in messaging-app.

4) Then I noticed that the triggered() signal is never emitted, until I manually force the device to wake up.

5) running an strace on telephony-service-indicator and (leaving the device stuck for about 1 minute) I get this:

[pid 2231] 1474573884.069934 clock_gettime(CLOCK_MONOTONIC, {1265, 272122461}) = 0
[pid 2231] 1474573884.070193 clock_gettime(CLOCK_MONOTONIC, {1265, 272383307}) = 0
[pid 2231] 1474573884.070407 poll([{fd=3, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLIN}], 5, 1571) = 0 (Timeout)
[pid 2231] 1474573951.500698 read(3, 0xbed2817c, 16) = -1 EAGAIN (Resource temporarily unavailable)
[pid 2231] 1474573951.500977 clock_gettime(CLOCK_MONOTONIC, {1266, 845932613}) = 0
[pid 2231] 1474573951.501380 clock_gettime(CLOCK_MONOTONIC, {1266, 846369074}) = 0

Someone please correct me if I am missing something, but from my understanding qt is stuck in the event loop waiting for the timer event, which only happens after I press the power button.

What worries me here is that the call to poll() explicitly sets the timeout for 1571 (1.5 seconds), and -apparently- it only timed out after 67 seconds, which is when the next call to read() is executed.

An additional information is that on dbus I always see indicator-datetime emitting a signal (Changed()) as soon as telephony-service-indicator also gets unblocked, which is a strong indication that indicator-datetime is also getting affected by this.

rild holds a wakelock for only 200ms so its quite possible the phone suspends while we are waiting on that timer. Also, QTimer must not use hardware wakeup events or things would work. We need to figure out where to put a wakelock request, repowerd provides an interface for this. It wold also be good to remove that timer and find a better way to handle when messaging app is open.

See comment #25 which is a similar issue with clock alarms in indicator-datetime, although it has logic to keep the device awake which is clearly not working.

Not sure if that be of any use as I don't have any logs but I'll add it anyway :)
Yesterday I had a phone on my desk, I wasn't doing anything with it. At some point I got notification about new SMS. I've checked immediately and noticed that in the notification "bubble" it said "8 minutes ago". Later the same day I had similar situation but this time the "bubble" said "13 minutes ago" when the SMS notification arrived.
For a change today I had the problem exactly as described in the bug report: when I pressed the power button, the notification showed up.
bq e4.5 OTA-13

After update phone(Meizu pro 5) to OTA-14, still not receiving sms,when phone locked.