ubuntu-push-client is writing frequent debug messages to logs

Bug #1376282 reported by Colin Ian King on 2014-10-01
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical System Image
High
Unassigned
Ubuntu Push Notifications
Fix Released
High
John Lenton
ubuntu-push (Ubuntu RTM)
High
John Lenton

Bug Description

I was trying to figure out where excessive file system writes were coming from (to try to reduce flash writes and hence reduce power consumption) and I spotted that /home/phablet/.cache/upstart/ubuntu-push-client.logis getting DEBUG messages written to it quite frequently. In a period of a couple of hours I see I have > 420 DEBUG messages written to the log, ~18K per hour, or about 430K over 24 hours.

Example:

2014/10/01 13:40:20.041291 DEBUG polld Done.
2014/10/01 13:40:25.049221 DEBUG requested wakeup at 2014-10-01 13:45:25 +0000 UTC
2014/10/01 13:40:25.059697 DEBUG cleared wakelock cookie 9138b63f-a9b9-4413-81a6-11fac559e2f3.
2014/10/01 13:44:27.637939 DEBUG May be connected; checking...
2014/10/01 13:44:27.710221 DEBUG Connection check says: true
2014/10/01 13:44:29.850224 DEBUG ping.
2014/10/01 13:45:25.004012 DEBUG got woken up; time is 2014-10-01 13:45:25.00389046 +0000 UTC
2014/10/01 13:45:25.014506 DEBUG got wakelock cookie of fdb062ee-80a7-43e7-a88c-59bae8af1b5e
2014/10/01 13:45:25.035442 DEBUG poking polld.
2014/10/01 13:45:25.039985 DEBUG waiting for polld to signal Done.
2014/10/01 13:45:25.040297 DEBUG polld Done.
2014/10/01 13:45:30.047281 DEBUG requested wakeup at 2014-10-01 13:50:30 +0000 UTC
2014/10/01 13:45:30.056927 DEBUG cleared wakelock cookie fdb062ee-80a7-43e7-a88c-59bae8af1b5e.
2014/10/01 13:49:29.872030 DEBUG ping.
2014/10/01 13:50:30.004014 DEBUG got woken up; time is 2014-10-01 13:50:30.003893093 +0000 UTC
2014/10/01 13:50:30.014151 DEBUG got wakelock cookie of d249f247-a9da-4893-beae-6db3d6146cd3
2014/10/01 13:50:30.035255 DEBUG poking polld.
2014/10/01 13:50:30.040046 DEBUG waiting for polld to signal Done.
2014/10/01 13:50:30.040348 DEBUG polld Done.
2014/10/01 13:50:35.047158 DEBUG requested wakeup at 2014-10-01 13:55:35 +0000 UTC
2014/10/01 13:50:35.058081 DEBUG cleared wakelock cookie d249f247-a9da-4893-beae-6db3d6146cd3.
2014/10/01 13:54:27.710627 DEBUG May be connected; checking...
2014/10/01 13:54:27.800558 DEBUG Connection check says: true
2014/10/01 13:54:29.898814 DEBUG ping.
2014/10/01 13:55:35.002961 DEBUG got woken up; time is 2014-10-01 13:55:35.002834341 +0000 UTC
2014/10/01 13:55:35.008301 DEBUG got wakelock cookie of b4e43b6f-53eb-405b-b743-e6c20b45e51c
2014/10/01 13:55:35.028824 DEBUG poking polld.
2014/10/01 13:55:35.030867 DEBUG waiting for polld to signal Done.
2014/10/01 13:55:35.031011 DEBUG polld Done.
2014/10/01 13:55:40.038362 DEBUG requested wakeup at 2014-10-01 14:00:40 +0000 UTC
2014/10/01 13:55:40.046331 DEBUG cleared wakelock cookie b4e43b6f-53eb-405b-b743-e6c20b45e51c.
2014/10/01 13:59:29.926215 DEBUG ping.

Seems a bit too chatty IMHO

Are the DEBUG messages necessary? Each write will cause flash writes and this uses up space and consumes power.

Related branches

Lucio Torre (lucio.torre) wrote :

We will move out of DEBUG and ensure we have enough logs in INFO.

Changed in ubuntu-push:
importance: Undecided → High
status: New → Triaged
assignee: nobody → John Lenton (chipaca)
tags: added: rtm14
tags: added: touch-2014-10-09
John Lenton (chipaca) on 2014-11-04
Changed in ubuntu-push (Ubuntu RTM):
importance: Undecided → High
assignee: nobody → John Lenton (chipaca)
Changed in ubuntu-push:
status: Triaged → In Progress
Changed in ubuntu-push (Ubuntu RTM):
status: New → In Progress
Pat McGowan (pat-mcgowan) wrote :

battery life fix and dont fill the disk

Changed in canonical-devices-system-image:
importance: Undecided → High
milestone: none → ww03-2015
status: New → Confirmed
Changed in canonical-devices-system-image:
milestone: ww03-2015 → ww05-2015
John Lenton (chipaca) on 2015-01-16
Changed in ubuntu-push:
status: In Progress → Fix Committed
Changed in canonical-devices-system-image:
status: Confirmed → Fix Released
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package ubuntu-push - 0.64.1+15.04.20150116.2~rtm-0ubuntu1

---------------
ubuntu-push (0.64.1+15.04.20150116.2~rtm-0ubuntu1) 14.09; urgency=low

  [ John R. Lenton ]
  * Cherrypick r350 from automatic/ to turn down logs to info. (LP:
    #1376282, #1380662)
  * Cherrypick r342 from automatic/ to fix the click hook wrt legacy
    apps. (LP: #1380662)
 -- Ubuntu daily release <email address hidden> Fri, 16 Jan 2015 17:57:04 +0000

Changed in ubuntu-push (Ubuntu RTM):
status: In Progress → Fix Released
Changed in ubuntu-push:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers