Comment 26 for bug 1516696

Revision history for this message
Tiago Salem Herrmann (tiagosh) wrote :

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.