clock app on galaxy nexus generates ~2500 context switches a second

[Colin Ian King]

I started up the clock app on a samsung galaxy nexus and I'm seeing:

vmstat 10
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
 r b swpd free buff cache si so bi bo in cs us sy id wa
 0 0 0 102692 24996 193240 0 0 103 4 628 1324 16 9 75 0
 0 0 0 102708 24996 193240 0 0 0 0 1092 2915 17 11 72 0
 0 0 0 102708 24996 193240 0 0 0 0 1059 2850 15 11 73 0
 2 0 0 102708 24996 193240 0 0 0 0 1069 2848 16 11 74 0
 0 0 0 104284 24996 193240 0 0 0 0 1046 2935 16 11 73 0
 2 0 0 104256 25012 193240 0 0 0 6 1019 2812 16 10 74 0

so that's ~2500 context switches/sec above the normal "idle" rate and I'm seeing ~25% of available CPU being burnt just to display a clock. That's really power hungry.

[Colin Ian King (colin-king)]

Same kind of overhead on a Nexus4. I quick measurement shows this is ~0.33 Watts of power on the Nexus 4

[David Planella (dpm)]

Colin, do you have any suggestions on how to reduce the overhead?

[David Planella (dpm)]

bug 1200920 might be a duplicate of this one.

[Colin Ian King (colin-king)]

I guess running heath-check from my PPA lp:colin-king/white may show what's going on.

[Colin Ian King (colin-king)]

Update:

sudo health-check -p 2232 -d 60

CPU usage:
  PID Process USR% SYS% TOTAL%
  2232 qmlscene 3.05 1.57 4.62 (light load)

[ only 4.62% CPU used ]

Wakeups:
  PID Process Wake/Sec Kernel Functions
  2232 qmlscene 1.02 (hrtimer_start_range_ns, hrtimer_wakeup) (moderate)

File I/O operations:
 No file I/O operations detected

System calls traced:
  PID Process Syscall Count Rate/Sec
  2232 qmlscene futex 5936 98.9332
  2232 qmlscene clock_gettime 5331 88.8499

[ seems busy on a futex, poll and getting time though ]

  2232 qmlscene poll 3175 52.9166
  2232 qmlscene read 3108 51.7999
  2232 qmlscene write 2009 33.4833
  2232 qmlscene gettimeofday 66 1.1000
  2232 qmlscene stat64 62 1.0333
  2232 qmlscene recvmsg 15 0.2500
  2232 qmlscene fork 5 0.0833
  2232 qmlscene restart_syscall 1 0.0167
 Total 19708 328.4662

Top polling system calls:
  PID Process Syscall Rate/Sec Infinite Zero Minimum Maximum Average
                                                           Timeouts Timeouts Timeout Timeout Timeout
  2232 qmlscene poll 52.9166 1260 1042 0.0 sec 999.0 msec 125.2 msec

Distribution of poll timeout times:
                                                            10.0 100.0 1.0 10.0 100.0 1.0 10.0 100.0
                                                    up to to to to to to to to or more
                                              Zero 9.9 99.9 999.9 9.9 99.9 999.9 9.9 99.9 Infinite
  PID Process Syscall sec usec usec usec msec msec msec sec sec sec Wait
  2232 qmlscene poll 1042 - - - 8 85 780 - - - 1260

Polling system call analysis:
 No bad polling discovered.

Per Process Memory (K):
  PID Process Type Size RSS PSS
  2232 qmlscene Stack 136 72 72
  2232 qmlscene Heap 140752 5184 5184
  2232 qmlscene Mapped 89668 46964 25495

Change in memory (K/second):
  PID Process Type Size RSS PSS
  2232 qmlscene Heap 0.00 1.13 1.13 (growing)
  2232 qmlscene Mapped 0.00 0.93 0.23 (growing)

[.. and some heap growth. maybe leaky? ]

Open Network Connections:
 None.

[Ubuntu Phone Apps Jenkins Bot (ubuntu-phone-apps-jenkins-bot)]

Fix committed into lp:ubuntu-clock-app at revision None, scheduled for release in ubuntu-clock-app, milestone 1.6