ubuntu-phone team mailing list archive

[Colin Ian King <colin.king@xxxxxxxxxxxxx>]

On 17/03/15 14:50, Ricardo Salveti de Araujo wrote:
> On Sun, Mar 15, 2015 at 12:21 PM, Michael Zanetti
> <michael.zanetti@xxxxxxxxxxxxx> wrote:
>> -----BEGIN PGP SIGNED MESSAGE-----
>> Hash: SHA1
>>
>> Hi,
>>
>> since a week or two I notice increased instability of connectivity on
>> my krillin device during daily usage.
>>
>> The symptoms are visible in that networking starts failing to connect.
>> Mostly when switching from WiFi to 3G or back. At some point it just
>> stops connecting to 3G or WiFi and it stops listing wireless networks
>> at all. Making phone calls doesn't work any more either although the
>> indicator suggests it would be registered to GSM.
>>
>> I just started to examine the logs and found something suspicious in
>> syslog. It seems that the device was stuck in a wakeup-suspend loop
>> for the whole night, producing dozens of messages in syslog every
>> second. Interestingly the battery still survived throughout the night.
> 
> Looking at your syslog it seems that the device was trying to deep
> suspend during the entire night, but then the CONN interrupt was
> aborting the suspend after a few seconds.
> 
> I don't yet know what CONN means, but I'd suspend something with the modem.

CONN is indeed the modem. It produces the CONN events.

> 
> Below the output from suspend-blocker:
> 
> rsalveti@evasys:/tmp$ suspend-blocker -b -r -H < syslog.wakeuploop
> stdin:
> Suspend blocking wakelocks:
>   None
> 
> Resume wakeup causes:
>   CONN                             3286  90.52%
	Modem
>   EINT                              224   6.17%
	Extern events
>   CCIF_MD                           120   3.31%
	Can't recall what this is.
> 
> Suspend failure causes:
>   tasks freezer abort               291  99.66%
>   devices failed to suspend           1   0.34%

Task freezer abort with such a high level of CONN events basically means
that the kernel can't freeze the system because due to the CONN event
activity.

> 
> Time between successful suspends:
>    Interval (seconds)          Frequency    Cumulative Time (Seconds)
>      0.000 -    0.124       2991  82.49%     287.18   1.19%
>      0.125 -    0.249        214   5.90%      33.27   0.14%
>      0.250 -    0.499        108   2.98%      50.10   0.21%
>      0.500 -    0.999         72   1.99%      52.45   0.22%
>      1.000 -    1.999         43   1.19%      52.10   0.22%
>      2.000 -    3.999         14   0.39%      33.49   0.14%
>      4.000 -    7.999         13   0.36%      75.89   0.31%

The above stats show that the system is working hard to deep suspend...

>      8.000 -   15.999          8   0.22%      85.57   0.35%
>     16.000 -   31.999          5   0.14%     126.70   0.52%
>     32.000 -   63.999         39   1.08%    1870.25   7.72%
>     64.000 -  127.999         54   1.49%    4605.34  19.00%
>    128.000 -  255.999         64   1.77%   10879.89  44.90%
>    256.000 -  511.999          0   0.00%       0.00   0.00%
>    512.000 - 1023.999          0   0.00%       0.00   0.00%
>   1024.000 - 2047.999          0   0.00%       0.00   0.00%
>   2048.000 - 4095.999          0   0.00%       0.00   0.00%
>   4096.000 - 8191.999          1   0.03%    6080.75  25.09%
> 
> Duration of successful suspends:
>    Interval (seconds)          Frequency    Cumulative Time (Seconds)
>      0.000 -    0.124        198   5.46%      19.21   0.04%
>      0.125 -    0.249         30   0.83%       4.36   0.01%
>      0.250 -    0.499         14   0.39%       5.26   0.01%
>      0.500 -    0.999        503  13.86%     454.64   0.90%
>      1.000 -    1.999        162   4.46%     270.18   0.53%
>      2.000 -    3.999       1059  29.18%    3803.47   7.49%

The above stats show that the kernel has spent some effort into getting
into deep sleep, only to be woken up very soon after deep suspend. This
sucks power.

>      4.000 -    7.999        566  15.60%    3534.36   6.96%
>      8.000 -   15.999        497  13.70%    5717.27  11.26%
>     16.000 -   31.999        272   7.50%    6316.36  12.44%
>     32.000 -   63.999        173   4.77%    7892.30  15.54%
>     64.000 -  127.999         83   2.29%    7437.48  14.64%
>    128.000 -  255.999         56   1.54%   10779.37  21.22%
>    256.000 -  511.999         16   0.44%    4554.50   8.97%
> NOTE:  0.03% of the samples were inaccurate estimates.
> 
> Suspends:
>   378 suspends aborted (9.43%).
>   3629 suspends succeeded (90.57%).
>   total time: 50788.777898 seconds (67.70%).
>   minimum: 0.000000 seconds.
>   maximum: 300.341932 seconds.
>   mean: 13.995254 seconds.
>   mode: 4.000000 seconds.
>   median: 3.894680 seconds.
> 
> Time between successful suspends:
>   total time: 24232.978656 seconds (32.30%).
>   minimum: 0.000032 seconds.
>   maximum: 6080.750517 seconds.
>   mean: 6.683116 seconds.

A low mean indicates the phone is spending a lot of time dipping into
and coming out of deep suspend, primarily because of the CONN wakeup events.

>   mode: 0.000000 seconds.
>   median: 0.109807 seconds.
> 
> Cheers,
>