Foreground app consuming lots of memory

[Alan Pope 🍺🐧🐱 🦄]

Started music app and other apps about 20 hours ago. Phone has been sat on my desk, locked, not used for that time. Now I find it's sluggish and seems lots of RAM/SWAP has been consumed:-

top - 15:49:44 up 22:55, 1 user, load average: 5.10, 2.41, 2.73
Tasks: 234 total, 1 running, 233 sleeping, 0 stopped, 0 zombie
%Cpu(s): 3.7 us, 7.1 sy, 0.0 ni, 87.9 id, 1.2 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 1878632 total, 1834880 used, 43752 free, 384 buffers
KiB Swap: 524284 total, 524284 used, 0 free. 22260 cached Mem

  PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
   65 root 20 0 0 0 0 D 37.4 0.0 4:08.99 kswapd0
24543 root 20 0 2548 1100 712 R 10.7 0.1 0:00.06 top
  969 9999 20 0 10904 284 144 S 5.3 0.0 121:04.11 sensors.qc+
  981 root 20 0 10360 268 40 S 5.3 0.0 102:52.46 Binder_2
 6834 phablet 20 0 2047948 1.266g 6848 S 5.3 70.6 137:51.83 qmlscene
16085 root 20 0 0 0 0 S 5.3 0.0 0:26.14 kworker/0:4
24298 message+ 20 0 2976 1144 708 S 5.3 0.1 0:00.15 dbus-daemon
    1 root 20 0 4060 1880 576 S 0.0 0.1 1:23.34 init
    2 root -2 0 0 0 0 S 0.0 0.0 0:04.24 kthreadd
    3 root 20 0 0 0 0 S 0.0 0.0 0:01.33 ksoftirqd/0
    6 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
   16 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 khelper
   17 root 20 0 0 0 0 S 0.0 0.0 0:00.03 kdevtmpfs
   18 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns
   19 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 suspend_sy+
   20 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 suspend
   22 root -51 0 0 0 0 S 0.0 0.0 0:00.00 irq/203-ms+

phablet 6834 10.1 70.7 2003920 1329976 ? Ssl Mar07 138:04 /usr/lib/arm-linux-gnueabihf/qt5/bin/qmlscene music-app.qml --file= -I ./plugins

[Victor Thompson (vthompson)]

I wonder if this is partially due to the app not suspending like the others due to it's lifecycle exception.

[Andrew Hayzen (ahayzen)]

How many songs are in your library and which tabs had you opened (eg the songs tab)?

[Andrew Hayzen (ahayzen)]

Oh you attached the log :-) I'll have a look through that...

[Andrew Hayzen (ahayzen)]

So what I have found so far and the steps I have performed.
1) Start the music app
2) Switch back to the dash and lock the phone
3) run the following command
$ watch grep -e VmSize: -e VmRSS: /proc/`pidof qmlscene`/status

4) After observing the VmRSS over a period of time I have noticed that every ~5 minutes the memory increases in size by around 260 kB. Below is two outputs to show the difference.

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/2508/status Sat Mar 8 19:11:37 2014

VmSize: 281240 kB
VmRSS: 65720 kB

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/2508/status Sat Mar 8 19:44:06 2014

VmSize: 282264 kB
VmRSS: 66736 kB

Note that I have a small library of only 11 songs and that I haven't opened any other tabs. I'll see if having a higher starting memory changes the value of the memory increments, which could then explain how yours has become so high.

[Alan Pope 🍺🐧🐱 🦄 (popey)]

I have around 200 songs on my device. When I started testing this image at ~17:00 UTC yesterday I had opened around 12 apps. This was certainly dialer, messages, browser, settings, bbc news webapp, media player with a video open, and others I don't recall.

Unfortunately my phone is now running red hot and I can't adb shell in to get the full process list. I will restart it and try and reproduce the same state - not hard because I tend to run the same bunch of apps as part of testing.

[Alan Pope 🍺🐧🐱 🦄 (popey)]

Just tried to reproduce with Andrew's help.

Attached process list after starting a bunch of apps and music player. Music player is currently paused mid-track, so no audio playing, nothing much happening.

In 10 mins it's gone from:-

20:18:42 < popey> VmSize: 392432 kB
20:18:42 < popey> VmRSS: 78788 kB

to

20:28:11 < popey> VmSize: 403696 kB
20:28:11 < popey> VmRSS: 88024 kB

vmstat 5 looks like this:-

 2 0 0 187772 51548 807600 0 0 0 5 387 2904 11 19 69 1 0
 3 0 0 187624 51548 807600 0 0 0 0 406 2884 11 23 66 0 0
 1 0 0 187524 51556 807600 0 0 0 5 397 2901 9 19 71 1 0
 1 0 0 187164 51556 807600 0 0 0 0 524 3072 0 1 99 0 0
 0 0 0 187356 51564 807600 0 0 0 5 398 2910 10 21 68 1 0
 0 0 0 187084 51564 807600 0 0 0 0 404 2936 11 20 68 0 0
 1 0 0 185816 51572 807600 0 0 0 5 451 3039 242 492 0 3634202462 0
 1 0 0 186700 51572 807600 0 0 0 0 524 2494 1 2 94 3 0
 2 0 0 186504 51580 807600 0 0 0 5 390 2342 11 21 66 1 0
 0 0 0 186624 51580 807600 0 0 0 0 421 2366 14 22 64 0 0
 1 0 0 186520 51588 807600 0 0 0 5 392 2344 11 22 66 0 0
 3 0 0 186564 51588 807600 0 0 0 0 421 2376 13 21 65 0 0
 1 0 0 186528 51596 807600 0 0 0 5 407 2374 12 22 65 1 0
 4 0 0 194440 51596 807588 0 0 0 0 469 2664 2 3 95 0 0
 2 0 0 194304 51604 807588 0 0 0 6 395 2879 8 19 72 1 0
 0 0 0 194468 51604 807588 0 0 0 1 525 2877 1 1 98 0 0
 0 0 0 193688 51612 807588 0 0 0 5 392 2526 13 22 65 0 0
 3 0 0 193412 51612 807588 0 0 0 0 421 2545 10 24 66 0 0
 0 0 0 192816 51620 807588 0 0 0 7 465 2729 208 280 0 1717986531 0
 0 0 0 193084 51620 807588 0 0 0 1 460 2820 1 2 93 4 0
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r b swpd free buff cache si so bi bo in cs us sy id wa st
 2 0 0 193132 51628 807588 0 0 0 5 382 2884 10 24 66 0 0
 5 0 0 192944 51628 807588 0 0 0 0 408 2819 15 20 64 0 0
 0 0 0 193024 51636 807584 0 0 0 5 389 2881 11 25 64 0 0
 2 0 0 192760 51636 807592 0 0 0 0 402 2858 12 23 65 0 0
 2 0 0 192784 51644 807584 0 0 0 6 389 2825 10 21 68 1 0
 2 0 0 192512 51644 807592 0 0 0 0 402 2871 9 23 68 0 0
 0 0 0 192536 51652 807592 0 0 0 11 388 2876 10 21 68 1 0
 2 0 0 192252 51652 807592 0 0 0 0 491 2930 0 1 99 0 0
 2 0 0 192124 51660 807592 0 0 0 5 405 2729 12 23 64 0 0
 3 0 0 192012 51660 807592 0 0 0 0 421 2609 15 18 67 0 0
 0 0 0 191956 51668 807592 0 0 0 5 397 2648 10 22 67 1 0
 0 0 0 191740 51668 807596 0 0 0 1 470 2564 13 23 64 0 0
 2 ...

[Andrew Hayzen (ahayzen)]

Ok I reflashed to image 227 and followed the steps I provided in comment #5 (note there are +80 songs than the previous test but the rest of the environment and steps are the same other than the image)

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/3092/status Sat Mar 8 20:53:56 2014

VmSize: 276600 kB
VmRSS: 66640 kB

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/3092/status Sat Mar 8 20:58:36 2014

VmSize: 281720 kB
VmRSS: 72144 kB

[Andrew Hayzen (ahayzen)]

So I have now moved to the qt5.2 beta following the instructions here [1] and followed exactly the same steps.

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/2613/status Sat Mar 8 21:10:05 2014

VmSize: 266752 kB
VmRSS: 76764 kB

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/2613/status Sat Mar 8 21:15:04 2014

VmSize: 272896 kB
VmRSS: 82300 kB

https://launchpad.net/~canonical-qt5-edgers/+archive/qt5-beta2

[Alan Pope 🍺🐧🐱 🦄 (popey)]

Seems the issue has been around for some time, so shouldn't block #226, but still needs further investigation.

[Andrew Hayzen (ahayzen)]

OK so this is much worse than we thought.

I flashed my device to 227
# system-image-cli -i
current build number: 227
device name: mako
channel: devel-proposed
alias: trusty-proposed
last update: 2014-03-09 03:20:00
version version: 227
version ubuntu: 20140308
version device: 20140304

I then opened the clock app, kept it focused and ensured that the screen remained on by tapping the display at intervals. (So that the app isn't suspended).

This is then the memory stats of the clock app over a 5 minute duration.
Every 2.0s: grep -e VmSize: -e VmRSS: /proc/3823/status Sun Mar 9 03:25:35 2014

VmSize: 253496 kB
VmRSS: 42148 kB

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/3823/status Sun Mar 9 03:30:44 2014

VmSize: 259640 kB
VmRSS: 48724 kB

Note: The music-app is unconfined so this is likely what is making the issue more apparent.

[Victor Thompson (vthompson)]

Since this bug seems app agnostic, perhaps this is related to lp:1210124 and something has caused the problem to amplify in recent builds?

[Victor Thompson (vthompson)]

Running the music app on a updated 14.04 desktop doesn't seem to produce the same memory increase:

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/4356/s... Sun Mar 9 14:38:02 2014

VmSize: 2498416 kB
VmRSS: 127760 kB

ery 2.0s: grep -e VmSize: -e VmRSS: /proc/4356/s... Sun Mar 9 14:44:50 2014

VmSize: 2498416 kB
VmRSS: 128216 kB

[Victor Thompson (vthompson)]

And since the last output VmRSS has actually fallen on the desktop:

Every 2.0s: grep -e VmSize: -e VmRSS: /proc/4356/s... Sun Mar 9 14:46:48 2014

VmSize: 2498416 kB
VmRSS: 88152 kB

[Andrew Hayzen (ahayzen)]

Those are the sort of changes in memory usage I was seeing on image #194.

[Sergio Schvezov (sergiusens)]

Bug #1285646 may explain why it's visible on music

[Sergio Schvezov (sergiusens)]

Actually, scratch that; it's not related to this at all

[Gerry Boland (gerboland)]

Music app is excluded from lifecycle management. I notice while music is paused, app is continually using 10% of CPU on my Mako, and memory usage is creeping up continually.

Dialer app (as a lifecycled app) seems to behave correctly, as when unfocused or when display locked, it is suspended (after 3 seconds, by design) and uses zero CPU, so cannot increase in memory either. Clock app also does the same.

I do notice in general apps are using more CPU that I'd expect. For instance Clock uses 6+% when nothing is changing on screen, as does Dialer. Something is polling somewhere

[kevin gunn (kgunn72)]

just adding reference to the thread happening on ubuntu-phone
https://lists.launchpad.net/ubuntu-phone/msg08406.html

recommending use of smemstat, which according to subsequent mails is actually in utopic archive (so ignore the bit about using ppa)

[Launchpad Janitor (janitor)]

[Expired for unity8 (Ubuntu) because there has been no activity for 60 days.]

[Victor Thompson (vthompson)]

Should this bug be expired everywhere? Or is there anything left to be solved? The music app issues should be solved when it is made to suspend like other apps--but that's not to say that it is well behaved while in the foreground.

[Michi Henning (michihenning)]

Is the problem still present with the latest image?