Open GoogleCodeExporter opened 9 years ago
[deleted comment]
I've managed to Log an example of Low Memory service death. This happened while
launching a link to a wired article from a tweet.
04-26 11:49:06.889 I/ActivityManager( 1111): Starting activity: Intent {
act=android.intent.action.VIEW cat=[android.intent.category.BROWSABLE]
dat=http://www.droid-life.com/2010/04/26/nexus-one-nixed-by-verizon/
cmp=com.android.browser/.BrowserActivity }
04-26 11:49:07.530 I/ActivityManager( 1111): Process com.handcent.nextsms (pid
20584) has died.
04-26 11:49:09.272 I/ActivityManager( 1111): Process com.facebook.katana (pid
20552) has died.
04-26 11:49:10.335 D/dalvikvm(20603): GREF has increased to 201
04-26 11:49:10.616 W/webcore (20603): Can't get the viewWidth after the first
layout
04-26 11:49:12.092 D/dalvikvm(20603): GC freed 6499 objects / 777688 bytes in
78ms
04-26 11:49:20.811 D/dalvikvm(20603): threadid=25: bogus mon 1+0>0; adjusting
04-26 11:49:24.178 D/dalvikvm(20603): GC freed 11712 objects / 920968 bytes in
88ms
04-26 11:49:29.655 D/dalvikvm(20603): GC freed 5882 objects / 558792 bytes in
123ms
04-26 11:49:33.944 D/dalvikvm(20603): GC freed 7924 objects / 921648 bytes in
129ms
04-26 11:49:34.514 I/ActivityManager( 1111): Process android.process.acore (pid
18761) has died.
04-26 11:49:34.522 I/ActivityThread(18734): Removing dead content provider:
contacts
04-26 11:49:34.522 I/ActivityThread(18734): Removing dead content provider:
com.android.contacts
04-26 11:49:34.522 I/ActivityManager( 1111): Killing app
com.google.android.apps.googlevoice (pid 18734) because provider
com.android.providers.contacts.ContactsProvider2 is in dying process
android.process.acore
04-26 11:49:34.522 I/Process ( 1111): Sending signal. PID: 18734 SIG: 9
04-26 11:49:34.538 I/ActivityManager( 1111): Process
com.google.android.apps.googlevoice (pid 18734) has died.
04-26 11:49:34.546 W/ActivityManager( 1111): Scheduling restart of crashed
service com.google.android.apps.googlevoice/.CallLogService in 5000ms
04-26 11:49:34.546 W/ActivityManager( 1111): Scheduling restart of crashed
service com.google.android.apps.googlevoice/.UpdateService in 15000ms
04-26 11:49:36.874 D/dalvikvm(20603): GC freed 4908 objects / 725096 bytes in
73ms
04-26 11:49:39.585 I/ActivityManager( 1111): Start proc
com.google.android.apps.googlevoice for service
com.google.android.apps.googlevoice/.CallLogService: pid=20754 uid=10008
gids={3003}
04-26 11:49:39.741 D/dalvikvm(20603): GC freed 3108 objects / 579904 bytes in
171ms
04-26 11:49:41.639 D/dalvikvm(20603): GC freed 3390 objects / 703936 bytes in
138ms
As you can see, the system is systematically killing things off to get memory
for the operation.
Now it's our turn. Our whole process gets completely shut down, same as a task
killer might.
04-26 11:49:48.444 I/ActivityManager( 1111): Process i4nc4mp.myLock (pid 18186)
has died.
04-26 11:49:48.444 W/ActivityManager( 1111): Scheduling restart of crashed
service i4nc4mp.myLock/.AutoDismiss in 31102ms
04-26 11:49:50.085 I/ActivityManager( 1111): Start proc android.process.acore
for content provider
com.android.providers.contacts/.ContactsProvider2: pid=20880 uid=10018
gids={3003, 1015}
04-26 11:49:50.296 I/ActivityManager( 1111): Process com.seesmic (pid 20453)
has died.
=====Official low memory event============
04-26 11:49:50.296 I/ActivityManager( 1111): Low Memory: No more background
processes.
04-26 11:49:50.296 I/WindowManager( 1111): WIN DEATH: Window{4520c3e8
com.seesmic/com.seesmic.ui.Welcome paused=false}
04-26 11:49:50.303 I/WindowManager( 1111): WIN DEATH: Window{44e5d690
com.seesmic/com.seesmic.ui.Tweet paused=false}
04-26 11:49:50.303 I/WindowManager( 1111): WIN DEATH: Window{45345180
com.seesmic/com.seesmic.ui.Space paused=false}
04-26 11:49:50.483 I/ActivityThread(20880): Publishing provider
com.android.globalsearch.SuggestionProvider:
com.android.globalsearch.SuggestionProvider
04-26 11:49:52.178 I/ActivityThread(20880): Publishing provider
user_dictionary: com.android.providers.userdictionary.UserDictionaryProvider
04-26 11:49:52.210 I/ActivityThread(20880): Publishing provider
com.android.globalsearch.stats: com.android.globalsearch.StatsProvider
04-26 11:49:52.210 I/ActivityThread(20880): Publishing provider
com.android.social: com.android.providers.contacts.SocialProvider
04-26 11:49:53.014 I/ActivityThread(20880): Publishing provider applications:
com.android.providers.applications.ApplicationsProvider
04-26 11:49:53.124 I/ActivityThread(20880): Publishing provider
contacts;com.android.contacts: com.android.providers.contacts.ContactsProvider2
04-26 11:49:54.085 W/ContactAggregator(20880): No more aggregation requests
04-26 11:49:54.264 I/ActivityThread(20880): Publishing provider call_log:
com.android.providers.contacts.CallLogProvider
04-26 11:49:54.710 D/dalvikvm(20754): GC freed 4988 objects / 368864 bytes in
291ms
04-26 11:49:55.108 D/dalvikvm(20880): GC freed 3584 objects / 262680 bytes in
307ms
04-26 11:49:55.639 D/dalvikvm(20880): GREF has increased to 201
04-26 11:49:56.546 D/dalvikvm(20754): GC freed 12098 objects / 485336 bytes in
210ms
04-26 11:49:57.803 D/dalvikvm(20754): GC freed 13277 objects / 507160 bytes in
145ms
04-26 11:49:59.780 D/dalvikvm(20603): GC freed 5675 objects / 1002872 bytes in
182ms
04-26 11:50:01.264 W/browser (20603): Console: Unsafe JavaScript attempt to
access frame with URL
http://droidlife.disqus.com/nexus_one_nixed_by_verizon/reply.html?
1272304177987&f=droidlife&t=nexus_one_nixed_by_verizon&ff=Helvetica&default_text
=Type%20your%20comment%20here.&ifrs= from frame with URL
http://www.droid-life.com/2010/04/26/nexus-one-nixed-by-verizon/. Domains,
protocols and ports must match.
04-26 11:50:01.264 W/browser (20603): :1
04-26 11:50:08.553 W/browser (20603): Console: Unsafe JavaScript attempt to
access frame with URL http://www.droid-life.com/2010/04/26/nexus-one-
nixed-by-verizon/ from frame with URL
http://www.facebook.com/extern/login_status.php?
api_key=a104ebc21b105a7dbf083ef6b7df2d9e&extern=0&channel=http%3A%2F%2Fwww.droid
-life.com%2Fwp-content%2Fplugins%2Fdisqus-comment-
system%2Fxd_receiver.htm&public_session_data=1&locale=en_US. Domains, protocols
and ports must match.
04-26 11:50:08.553 W/browser (20603): :1
Here the system feels it's time to restart the background processes
04-26 11:50:19.757 I/ActivityManager( 1111): Start proc i4nc4mp.myLock for
service i4nc4mp.myLock/.AutoDismiss: pid=20942 uid=10056 gids={}
04-26 11:50:23.210 D/webviewglue(20603): nativeDestroy view: 0x433c38
04-26 11:50:23.249 I/ActivityManager( 1111): moveTaskToBack: 69
04-26 11:50:23.538 I/ActivityManager( 1111): Start proc com.seesmic for
activity com.seesmic/.ui.Tweet: pid=20950 uid=10049 gids={3003, 1015}
04-26 11:50:23.553 D/AutoDismiss(20942): onCreate()
04-26 11:50:23.553 V/init shake(20942): connecting to sensor service and accel
sensor
04-26 11:50:23.702 I/ActivityManager( 1111): Process com.helixproject.launcher
(pid 16224) has died.
04-26 11:50:23.717 I/WindowManager( 1111): WIN DEATH: Window{4537fbf8
com.helixproject.launcher/com.helixproject.launcher.Launcher paused=false}
===========Hmm, hit low mem again, but we don't get killed this time as we are
in the middle of being restarted
04-26 11:50:23.717 I/ActivityManager( 1111): Low Memory: No more background
processes.
04-26 11:50:23.897 D/dalvikvm( 1072): GC freed 295 objects / 11288 bytes in
356ms
04-26 11:50:24.022 V/first-start(20942): boot handler & rcvrs
04-26 11:50:24.100 I/ActivityThread(20950): Publishing provider
com.seesmic.twitter: com.seesmic.data.TwitterProvider
04-26 11:50:24.116 D/dalvikvm( 1072): GC freed 52 objects / 2304 bytes in 202ms
04-26 11:50:24.288 D/dalvikvm( 1072): GC freed 2 objects / 48 bytes in 176ms
04-26 11:50:24.428 W/BackupManagerService( 1111): dataChanged but no
participant pkg='com.android.providers.settings' uid=10056
04-26 11:50:24.803 D/dalvikvm( 1111): GC freed 22549 objects / 1059616 bytes in
296ms
04-26 11:50:25.257 V/pref change(20942): the changed key is BattLevel
04-26 11:50:25.257 V/ListenInit(20942): first phone listener init
===Now we are started up again
04-26 11:50:25.913 D/dalvikvm(20950): GC freed 3453 objects / 267784 bytes in
103ms
04-26 11:50:26.241 I/ActivityManager( 1111): Displayed activity
com.seesmic/.ui.Tweet: 2749 ms (total 2749 ms)
04-26 11:50:27.999 D/dalvikvm(20603): GC freed 11516 objects / 1081800 bytes in
68ms
04-26 11:50:29.194 W/PhoneWindow(20950): Previously focused view reported id
16908298 during save, but can't be found during restore.
04-26 11:50:29.319 D/dalvikvm(20950): GC freed 2803 objects / 169064 bytes in
54ms
04-26 11:50:29.655 I/ActivityManager( 1111): Process com.android.browser (pid
20603) has died.
==Still low mem
04-26 11:50:29.655 I/ActivityManager( 1111): Low Memory: No more background
processes.
04-26 11:50:29.663 I/WindowManager( 1111): WIN DEATH: Window{44f5bb38
com.android.browser/com.android.browser.BrowserActivity paused=false}
04-26 11:50:29.710 I/ActivityManager( 1111): Displayed activity
com.seesmic/.ui.Space: 941 ms (total 941 ms)
04-26 11:50:30.538 D/dalvikvm(20950): GC freed 2316 objects / 355744 bytes in
59ms
04-26 11:50:30.671 D/dalvikvm(20950): GC freed 1204 objects / 72888 bytes in
57ms
===========
Here i click on the widget to test binding. If i hadnt done this and gotten a
start reaction, i would not have known issue happened
************
04-26 11:53:13.983 V/Toggler (20942): Starting
04-26 11:53:13.983 V/bind attempt(20942): initializing connection
04-26 11:53:14.007 V/bind result(20942): exists: false
04-26 11:53:14.007 V/toggling(20942): target is true and current state is false
04-26 11:53:14.014 V/bind result(20942): exists: false
04-26 11:53:14.030 D/manage mediator(20942): start call
04-26 11:53:14.038 V/pref change(20942): the changed key is enabled
04-26 11:53:14.077 I/NotificationService( 1111): enqueueToast
pkg=i4nc4mp.myLock
callback=android.app.ITransientNotification$Stub$Proxy@44ef4758
duration=0
04-26 11:53:14.085 D/AutoDismiss(20942): onBind()
04-26 11:53:14.100 V/service connected(20942): bind to existent service
===========Because of the service death, the widget click thought we were not
running, so it called a duplicate start
===========That's no problem since it repairs the damage the low mem shutdown
caused.
04-26 11:53:31.608 I/ActivityManager( 1111): Starting activity: Intent {
act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER]
flg=0x10200000 cmp=com.xtralogic.android.logcollector/.SendLogActivity }
04-26 11:53:31.647 I/ActivityManager( 1111): Start proc
com.xtralogic.android.logcollector for activity
com.xtralogic.android.logcollector/.SendLogActivity: pid=20993 uid=10054
gids={1007, 1015}
04-26 11:53:31.803 D/dalvikvm( 1111): GREF has increased to 801
04-26 11:53:32.467 I/ActivityManager( 1111): Displayed activity
com.xtralogic.android.logcollector/.SendLogActivity: 854 ms (total 854 ms)
04-26 11:53:35.163 D/dalvikvm( 1111): GC freed 10688 objects / 495000 bytes in
202ms
04-26 11:53:35.350 I/global (20993): Default buffer size used in
BufferedReader constructor. It would be better to be explicit if an 8k-char
buffer is required.
04-26 11:53:35.608 D/dalvikvm(20993): GC freed 1770 objects / 285720 bytes in
112ms
So now you know the benefit of running the status icon. You'll never get shut
down in low memory situations, causing unexpected start/stop
behavior
This might be critical for anyone using idle lock or toggle plug-in to ensure
the right state is known.
Original comment by myLockan...@gmail.com
on 27 Apr 2010 at 9:27
Original issue reported on code.google.com by
myLockan...@gmail.com
on 11 Jan 2010 at 7:47