stanvn / mylockforandroid

Automatically exported from code.google.com/p/mylockforandroid
0 stars 0 forks source link

Occasional loss of functionality when not using foreground mode #6

Open GoogleCodeExporter opened 8 years ago

GoogleCodeExporter commented 8 years ago
What steps will reproduce the problem?
1. Using myLock complete 2c, toggle off persistent settings notification 
icon (foreground mode)
2. Use the device for a while

Users have reported that rarely, myLock appears to be getting destroyed by 
the OS, resulting in random unexpected appearance of the lockscreen.

I believe this is due to memory management that occurs automatically. It 
may also be influenced by any task killer apps (which are largely 
unnecessary on android). The settings launcher in notifications also keeps 
the service running in foreground mode, protecting it from being shut off 
in low memory scenarios -it uses an extremely minimal CPU resource as it 
is. 

Original issue reported on code.google.com by myLockan...@gmail.com on 11 Jan 2010 at 7:47

GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
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