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

Bug #1376282 reported by Colin Ian King
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical System Image
Fix Released
High
Unassigned
Ubuntu Push Notifications
Fix Released
High
John Lenton
ubuntu-push (Ubuntu RTM)
Fix Released
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

Revision history for this message
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)
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
Revision history for this message
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)
Changed in ubuntu-push:
status: In Progress → Fix Committed
Changed in canonical-devices-system-image:
status: Confirmed → Fix Released
Revision history for this message
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  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.