Debugging Wallpanel terminating

WallPanel
#1

Hey folks,

Firstly, thanks for the work to keep WallPanel going!

I’ve got a Home Assistant setup for which I’m using WallPanel as an alarm/status panel. I’ve been using it on a 5th gen Kindle Fire (old kids’ tablet no longer in use). I’ve been finding that after a while (12-36 hours) it seems to exit out and I have to hit the power button to wake the tablet back up/get back into WallPanel.

I’d assumed that was due to the dusty FireOS and relatively low memory available of such a vintage tablet, or perhaps the random Amazon notifications I’d still get through it. I actually picked up another Fire of the same vintage (to fit my wall mount), rooted, and installed a Fire Nexus rom build for something a little leaner. I got WallPanel going on it, and…I still have a similar problem with it dropping out.

I’m configuring it to monitor my hadashboard, sign on to MQTT for audio alerts (Door chime, voice notifications, etc), and have the clock screensaver active. I do have the camera enabled - motion detection to turn off the screensaver works great when it’s still running.

Is there any log information I can get at to tell why it’s crashing or exiting out? If not, any ideas how to debug such a thing? I guess getting set up for a local build & just running it with ADB attached to see if it reproduces – just thought I’d check if there was a better route before going there.

Thanks,

- Joe
1 Like
#2

I have a similar behavior on my Fire OS 7, it seems to happen because the OS is cleaning up long running applications, so its either putting the app in the background or closing them.

I have no way to address this since Fire OS is a custom OS and I am doubtful Amazon cares to fix this behavior. Just check to be sure you have full charge and that the WiFi connection is not getting killed by the OS.

There is no log information in the app, but I do log crashes in Firebase, but this is not a crash issue, so nothing gets reported. This is garbage collection by the OS, that is my assessment.

#3

Thanks for the reply…Some sort of garbage collection would make a lot of sense.

Do you see this on non-FireOS tablets too? I’d grabbed both LineageOS and Nexus OS builds for my Fire, likewise thinking it good to get the Amazon cruft out of the way. The build on there now is pretty light – no play store, no amazon apps, etc. That said, I misspoke about it running Nexus – it was running LineageOS. Seems worth reimaging to Nexus anyway to see if it’s still an issue there. This is all I want the tablet to do, so bare OS + WallPanel is ultimately the desired state…

Thanks and regards,

- Joe
#4

Mister,

Have you considered restarting the app periodically, to avoid the OS thinking you are such a long running program. A daily scheduled restart say at 1am would scarcely be noticed.

I’ve not used it, but this library by Jake Wharton whose other stuff I have used, should help:

#5

Some progress…I’m up ~36 hrs after reimaging to LineageOS 14.1 from a 12 build. The latest Nexus build is apparently stripped down to the point of not having a web browser (or any app besides clock) in the image itself. For some reason I was not able to use adb to load on Wallpanel there – gave up after a few attempts.

One other change I realized is I hadn’t turned the video camera back on. Once I’m satisfied the current configuration is stable I’ll turn that and motion detection back on. Maybe the fire tablets just don’t agree with the camera being on 24x7. If that gets restart-y again maybe I’ll stick a ssh server on there and see if there’s anything I can monitor remotely. (Temperatures? Memory usage?) If it remains stable, apparently something in the other OS image was still getting in the way.

I’ll update with more data either way. Older Kindles are pretty cheap and easy to come by, so they’re very tempting for applications like this.

#6

And just updating for posterity…things are still working fine. Turned back on video for motion detection, and that’s been going more than a day.

So, FireOS and Lineage 12.1 ran into the returning-to-lock-screen behavior after some number of hours running. Lineage 14.1 seems to be working great.

Glad to be able to successfully reuse an older cheapie kids Fire tablet – thanks again!

#7

Could just do this with something like term for Android or tasker?

#8

I also see this effect. On some days of the week (not all) at around 6:35am Wallpanel gets killed on my Fire HD8 (8th gen).
I have the Homeassistant browser_mod extension running so at least I get a nice log:

December 22, 2020

[browser mod e6374c4f f08d8333] changed to 1
9:33:42 AM - 38 minutes ago

[browser mod e6374c4f f08d8333] became unavailable
6:45:17 AM - 3 hours ago

December 21, 2020

[browser mod e6374c4f f08d8333] changed to 1
8:35:30 AM - 1 day ago

[browser mod e6374c4f f08d8333] became unavailable
6:35:14 AM - 1 day ago

December 20, 2020

[browser mod e6374c4f f08d8333] changed to 1
11:25:34 AM - 2 days ago

[browser mod e6374c4f f08d8333] became unavailable
6:35:48 AM - 2 days ago

Has anyone tried restarting the app with tasker? Doesn’t Tasker get killed too?
Will try and report back.

#9

Are you still running FireOS on your Kindle? Reimagine to latest LineageOS gets me to a month or more of uptime before things need to be rebooted. I think it’s generally losing WiFi from power glitches that starts it down that path these days.

#10

Yes it’s still FireOS. Wanted to try it first before flashing Lineage etc and it has been stable for months now until recently the Wallpanel kills started.

I have a tasker task now that kills and restarts Wallpanel every day at 5am. Let’s see how that goes.

#11

Reporting back:

  • I have installed a tasker-job to restart wallpanel once per day. This works but as before I am greeted by the tablet home screen at 6:35am an some days
  • I have rebooted to tablet to see if it changes the time of occurance (6:35am) but no, it doesnt

Sigh. I guess it’s some kind of Amazon maintenance-job then so I guess I have to go flash lineage or something.

#12

Ok, trying some more debugging:

The state of browser_mod reports the tablet as offline here in home-assistant.log:

2021-01-11 06:36:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.browser_mod_e6374c4f_f08d8xxx …

I have a matching entry in the home-assistant.log showing the disconnection of the websocket connection, so the problem must have happened already by then:

2021-01-11 06:36:09 INFO (MainThread) [homeassistant.components.websocket_api.http.connection] [140216985801920] Connection closed by client

I downloaded the debug-report from the tablet. In the log is the “Recent wakeup history”:

2021-01-11 06:35:52.338|1|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:52.900|562|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:52.933|33|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:53.287|354|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:53.329|42|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:53.331|2|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:53.333|2|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:56.575|3242|10170|0|MqttService.pingSender.tab1
2021-01-11 06:35:56.602|27|10170|0|MqttService.pingSender.tab1
2021-01-11 06:36:01.575|4973|10170|0|MqttService.pingSender.tab1
2021-01-11 06:36:01.600|25|10168|2|com.google.android.gms.gcm.ACTION_CHECK_QUEUE
2021-01-11 06:36:03.330|1730|1000|2|<listener>:*job.delay*
2021-01-11 06:36:03.388|58|10170|0|MqttService.pingSender.tab1
2021-01-11 06:36:06.578|3190|10170|0|MqttService.pingSender.tab1
2021-01-11 06:36:18.739|12161|10168|2|com.google.android.intent.action.GCM_RECONNECT
2021-01-11 06:36:24.180|5441|1000|2|<listener>:*job.delay*
2021-01-11 06:36:24.180|0|10168|3|null
2021-01-11 06:36:27.022|2842|10168|2|com.google.android.gms.gcm.ACTION_CHECK_QUEUE
2021-01-11 06:37:04.680|37658|1000|2|<listener>:*job.delay*
2021-01-11 06:37:04.680|0|10168|3|null
2021-01-11 06:37:12.942|8262|10170|0|MqttService.pingSender.tab1
2021-01-11 06:37:15.796|2854|10042|2|com.android.internal.policy.impl.PhoneWindowManager.DELAYED_KEYGUARD
2021-01-11 06:37:17.948|2152|10170|0|MqttService.pingSender.tab1
2021-01-11 06:37:22.954|5006|10170|0|MqttService.pingSender.tab1
2021-01-11 06:37:27.961|5007|10170|0|MqttService.pingSender.tab1
2021-01-11 06:37:32.965|5004|10170|0|MqttService.pingSender.tab1

Nothing very suspicious but the GCM_RECONNECT is the only occurence in the log so I assume it’s reconnecting after the connection was somehow broken.

Further down the debug is this, nicely matching the timeframe:

DUMP OF SERVICE dropbox:
...
2021-01-11 06:35:06 Log.main (contents lost)
2021-01-11 06:35:06 Log.main (contents lost)
2021-01-11 06:35:52 event_data (text, 39 bytes)
    start=1610341522537/end=1610343352520
2021-01-11 06:36:08 system_app_crash (text, 2493 bytes)
    Process: com.google.android.gms.persistent/Package: com.google.android ...
2021-01-11 06:40:06 Log.main (contents lost)
2021-01-11 06:40:06 Log.main (contents lost)
2021-01-11 06:40:06 Log.main (contents lost)

Indeed, looking for : “system_app_crash” in the log reveals:

========================================
2021-01-11 06:36:08 system_app_crash (text, 2493 bytes)
Process: com.google.android.gms.persistent
Package: com.google.android.gms v204714024 (20.47.14 (100300-349456378))
Build: Amazon/karnak/karnak:7.0/PS7315/1961N:user/amz-p,release-keys

java.lang.RuntimeException: Unable to stop service com.google.android.gms.magictether.host.TetherListenerService@b662e46: java.lang.SecurityException: App not allowed to read or update stored WiFi Ap config (uid = 10168)
	at android.app.ActivityThread.handleStopService(ActivityThread.java:3738)
	at android.app.ActivityThread.access$1700(ActivityThread.java:207)
	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1696)
	at android.os.Handler.dispatchMessage(Handler.java:106)
	at android.os.Looper.loop(Looper.java:193)
	at android.app.ActivityThread.main(ActivityThread.java:6734)
	at java.lang.reflect.Method.invoke(Native Method)
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
Caused by: java.lang.SecurityException: App not allowed to read or update stored WiFi Ap config (uid = 10168)
	at android.os.Parcel.createException(Parcel.java:1950)
	at android.os.Parcel.readException(Parcel.java:1918)
	at android.os.Parcel.readException(Parcel.java:1868)
	at android.net.wifi.IWifiManager$Stub$Proxy.getWifiApConfiguration(IWifiManager.java:1731)
	at android.net.wifi.WifiManager.getWifiApConfiguration(WifiManager.java:2155)
	at agrp.a(:com.google.android.gms@204714024@20.47.14 (100300-349456378):0)
	at agrr.a(:com.google.android.gms@204714024@20.47.14 (100300-349456378):1)
	at agqi.a(:com.google.android.gms@204714024@20.47.14 (100300-349456378):1)
	at agpt.d(:com.google.android.gms@204714024@20.47.14 (100300-349456378):2)
	at com.google.android.gms.magictether.host.TetherListenerChimeraService.b(:com.google.android.gms@204714024@20.47.14 (100300-349456378):4)
	at com.google.android.gms.magictether.host.TetherListenerChimeraService.onDestroy(:com.google.android.gms@204714024@20.47.14 (100300-349456378):2)
	at rch.onDestroy(:com.google.android.gms@204714024@20.47.14 (100300-349456378):3)
	at android.app.ActivityThread.handleStopService(ActivityThread.java:3718)
	... 8 more
...

Ah and here is the part where Wallpanel dies (as a consequence of the above?):

01-11 06:36:09.009  1000   544  1421 I am_proc_died: [0,7731,com.google.android.gms.persistent,0,95604]
01-11 06:36:09.018  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/.instantapps.service.InstantAppsService,1000]
01-11 06:36:09.018  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/com.google.android.location.internal.server.GoogleLocationService,11000]
01-11 06:36:09.018  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/.gcm.GcmService,21000]
01-11 06:36:09.018  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/com.google.android.location.internal.GoogleLocationManagerService,30999]
01-11 06:36:09.018  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/com.google.android.contextmanager.service.ContextManagerService,40999]
01-11 06:36:09.018  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/.tron.CollectionService,50999]
01-11 06:36:09.019  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/.nearby.sharing.ReceiveSurfaceService,60999]
01-11 06:36:09.019  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/com.google.android.location.reporting.service.DispatchingService,70999]
01-11 06:36:09.020  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/.chimera.PersistentDirectBootAwareApiService,70998]
01-11 06:36:09.020  1000   544  1421 I am_schedule_service_restart: [0,com.google.android.gms/.chimera.PersistentIntentOperationService,80998]
01-11 06:36:09.021  1000   544  1421 I am_kill : [0,23871,com.thanksmister.iot.wallpanel,200,depends on provider com.google.android.gms/.chimera.container.GmsModuleProvider in dying proc com.google.android.gms.persistent (adj 0)]
01-11 06:36:09.023  1000   544  1421 I am_broadcast_discard_app: [0,154382097,com.google.android.gms.phenotype.COMMITTED,0,ResolveInfo{2f42f49 com.google.android.gms/.chimera.GmsIntentOperationService$PersistentInternalReceiver m=0x108000}]
01-11 06:36:09.038  wifi   366   366 I auditd  : type=1400 audit(0.0:1199390): avc: denied { read } for comm="wlan_assistant" name="nvdata" dev="tmpfs" ino=1315 scontext=u:r:wlan_assistant:s0 tcontext=u:object_r:nvdata_file:s0 tclass=lnk_file permissive=0
01-11 06:36:09.072  1000   544   564 I am_proc_start: [0,17575,10168,com.google.android.gms.persistent,broadcast,com.google.android.gms/.chimera.GmsIntentOperationService$PersistentInternalReceiver]
01-11 06:36:09.110  1000   544  2724 I am_proc_bound: [0,17575,com.google.android.gms.persistent]
01-11 06:36:09.214  1000   544  4963 I am_proc_died: [0,23871,com.thanksmister.iot.wallpanel,200,132314]
01-11 06:36:09.244  1047   323 24041 I liblog  : 214
01-11 06:36:09.244  1047   323 24041 I chatty  : uid=1047(cameraserver) /system/bin/cameraserver identical 1 line
01-11 06:36:09.244  1047   323 24041 I liblog  : 1
01-11 06:36:09.259  1000   544  4963 I am_schedule_service_restart: [0,com.thanksmister.iot.wallpanel/.network.WallPanelService,1000]
01-11 06:36:09.259  1000   544  4963 I am_schedule_service_restart: [0,com.thanksmister.iot.wallpanel/org.eclipse.paho.android.service.MqttService,11000]
01-11 06:36:09.259  1000   544  4963 I am_uid_stopped: 10170
01-11 06:36:09.260  1000   544   544 I sysui_multi_action: [757,128,758,5,759,8,793,201265036,794,0,795,201263833,796,1,806,com.thanksmister.iot.wallpanel,857,com.thanksmister.iot.wallpa-ded44f4d,858,2,947,0]
01-11 06:36:09.260  1000   544  4963 I am_finish_activity: [0,182098856,395,com.thanksmister.iot.wallpanel/.ui.activities.BrowserActivityNative,proc died without state saved]
01-11 06:36:09.260  1000   544   544 I notification_canceled: [0|com.thanksmister.iot.wallpanel|1|null|10170,8,201265036,201263833,0,-1,-1,NULL]
01-11 06:36:09.282  1000   544  4963 I wm_task_removed: [395,removeAppToken: last token]
01-11 06:36:09.283  1000   544  4963 I am_remove_task: [395,8]
01-11 06:36:09.283  1000   544  4963 I wm_task_removed: [395,removeTask]
01-11 06:36:09.293  1000   544  4963 I am_focused_stack: [0,0,8,appDied leftTaskHistoryEmpty]

My guess as a non-android-dev would be: the Google Play Services (com.google.android.gms.persistent) die (they are not supposed to run on a fire tablet anyway, I just installed them) when trying to modify the Wifi settings.
As a result Wallpanel also dies as it somehow depends on them.

Maybe @Mister can chime in if there is anything that could be done?

#13

I see this error on Google emulators as well, but it doesn’t cause the application to crash. The Paho library always will try to reconnect, its on an alarm in the background. I have a 7th Gen Fire OS and sometimes, but not always, it just gets closed. I think there is some issue with FireOS. It could be a compatibility issue with GMS, Amazon with its custom hardware and custom software. It might also be an issue with the Paho MQTT library. From your report, I see now app crash, so this is a probably a system crash or some memory issue that causes the tablet to garbage collect or restart.

#14

The thing I don’t like about FireOS, if you buy two of the same tablets, they could both be running different software. I have three and one is completely different version of Android, it makes no sense.

#15

Do you know which model number this is for the device? I can check Firebase for crashes specifically for this device, if the app is crashing.

#16

It says “LOT G945 MODEL: L5S83A” on the back if that’s what you mean.
The about-device screen just says Fire HD 8 (8th gen).

#17

I was thinking more about what it identifies itself as in crash reports. Usually this is in the settings under device information.

#18

I’m afraid that’s all it displays under Settings -> Device Information: “Fire HD 8 (8th gen)”

I have this on top of the crash-log if it helps (hardware=mt8163?):

Build: PS7315
Build fingerprint: 'Amazon/karnak/karnak:7.0/PS7315/1961N:user/amz-p,release-keys'
Bootloader: unknown
Radio: (unknown)
Network: (unknown)
Kernel: Linux version 4.9.117-g039ca999a0ec-dirty (build@i3-ri-14-use1a-b-13) (gcc version 6.3.1 20170109 (Linaro GCC 6.3-2017.02) ) #1 SMP PREEMPT Thu Sep 17 02:42:13 UTC 2020
Command line: console=tty0 console=ttyS0,921600n1 earlycon=uart8250,mmio32,0x11002000 vmalloc=496M androidboot.hardware=mt8163 firmware_class.path=/vendor/firmware androidboot.product=karnak androidboot.unlocked_kernel=false androidboot.verifiedbootstate=green androidboot.rpmb_state=1 androidboot.secure_cpu=1 androidboot.prod=1 androidboot.pl_version=0x0007 androidboot.tee_version=0x0105 androidboot.lk_version=0x0003 androidboot.pl_build_desc=151bfd2-20200616_041502 androidboot.lk_build_desc=cf889f2-20200616_041502 skip_initramfs rootwait ro init=/init root=/dev/dm-0 dm="system none ro,0 1 android-verity PARTUUID=e9f67a95-7a9b-4885-b6d6-dd88e5cb1c64 " bootopt=64S3,32N2,64N2 buildvariant=user veritykeyid=id:xxx lcm=1-jd9367_wxga_dsi_vdo_karnak_fiti_kd fps=5982 vram=16777216 androidboot.selinux=enforce androidboot.veritymode=eio bl_level=90 printk.disable_uart=1 bootprof.pl_t=892 bootprof.lk_t=2967 boot_reason=4 androidboot.serialno=xxx androidboot.bootreason=wdt_by_pass_pwk nt35521_id=224
Uptime: up 1 week, 6 days, 22 hours, 29 minutes
Bugreport format version: 2.0
Dumpstate info: id=1 pid=20719 dry_run=0 args=/system/bin/dumpstate -d -p -B -z -o /data/user_de/0/com.android.shell/files/bugreports/bugreport extra_options=bugreportplus
#19

Maybe this? It is a mystery, haha.