PW3 Freezes after sleep

dzervas · 12-14-2019, 09:05 PM

I have a PaperWhite 3 (Wi-Fi) for quite some time. It was sitting aside for a couple of months and when I got to use it again, it freezes when it tries to enter sleep. I tried restarting, hard restart (40s button), reset and now I jbed it through serial interface (as it's on version 5.12.2). I updated to 5.12.3. All of that led to no luck. showlog -f seems kinda interesting, a lot of errors going on:

Quote:

Code:

U-Boot 2009.08-lab126 (Nov 15 2019 - 00:11:26)

CPU: Freescale i.MX6 family TO0.0 at 996 MHz
Temperature:   41 C, calibration data 0x5905165f
mx6sl pll1: 996MHz
mx6sl pll2: 528MHz
mx6sl pll3: 480MHz
mx6sl pll8: 50MHz
ipg clock     : 66000000Hz
ipg per clock : 24000000Hz
uart clock    : 80000000Hz
cspi clock    : 60000000Hz
ahb clock     : 132000000Hz
axi clock   : 198000000Hz
emi_slow clock: 22000000Hz
ddr clock     : 396000000Hz
usdhc1 clock  : 198000000Hz
usdhc2 clock  : 198000000Hz
usdhc3 clock  : 198000000Hz
usdhc4 clock  : 198000000Hz
MMC:  FSL_ESDHC: 0,FSL_ESDHC: 1,FSL_ESDHC: 2
Board: Muscat WFO
Boot Reason: [ POR ]
Boot Device: NAND
Board Id: 0670709180260ZVV
S/N: G090G105804207M7
I2C:   ready
DRAM:  512 MB
Using default environment

In:    serial
Out:   serial
Err:   serial
Quick Memory Test 0x80000000, 0x1fff0000
POST done in 111 ms
Battery voltage: 3898 mV

Hit any key to stop autoboot:  0
## Booting kernel from Legacy Image at 80800000 ...
   Image Name:   Linux-3.0.35-lab126
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    3047788 Bytes =  2.9 MB
   Load Address: 80008000
   Entry Point:  80008000
   Verifying Checksum ... OK
   Loading Kernel Image ... OK
OK

Starting kernel ...

[    0.096468]
[    0.261625] pmic_soda_connects_notify_otg_out:423
[    0.277855] LPDDR2 MfgId: 0x3 [Elpida]
[    0.281795]
[    0.281798] just text: vaddr c014cffc, va 0xc014c200 pa 0x801000c3 attr 0x6
[    0.290079]
[    0.290082] nmx6sl_wfi_iram: vaddr e084e000, va 0xe084e200 pa 0x904043 attr 0x2
[    0.303130]
[    0.303133] mx6sl_ddr: vaddr e0856000, va 0xe0856200 pa 0x905043 attr 0x2
[    0.311450]
[    0.311452] mx6sl_iomux: vaddr f40e0000, va 0xf40e0200 pa 0x20110c3 attr 0x149
[    0.320186]
[    0.320188] ANATOP: vaddr f40c8000, va 0xf40c8200 pa 0x20110c3 attr 0x149
[    0.328574]
[    0.328576] CCM: vaddr f40c4000, va 0xf40c4200 pa 0x20110c3 attr 0x149
[    0.338652]
[    0.338654] MMDC_P0: vaddr f41b0000, va 0xf41b0200 pa 0x21110c3 attr 0x149
[    0.352085]
[    0.352088] L2: vaddr f2a02000, va 0xf2a02200 pa 0xa02043 attr 0x149
[    0.361039]
[    0.361042] arm perif: vaddr f2a00000, va 0xf2a00200 pa 0xa00043 attr 0x149
3.0.35-lab126 #2 PREEMPT Fri Nov 15 00:20:46 UTC 2019 armv7l
Press [ENTER] for recovery menu...       0 /BOOTING DEFAULT.
IP-Config: no devices to configure
kinit: Mounted root (ext3 filesystem) readonly.
info sytem:mounted_proc::
info system:mounted_sys::
info system:sy00::
info system:mounted_dev::
info milestone:6.70:49.1:49.1
info milestone:6.74:49.2:49.2
info milestone:6.77:49.3:49.3
info milestone:6.84:49.4:49.4
info milestone:6.87:49.5:49.5
info sytem:mounted_tmpfs::
info milestone:6.96:sy50:sy50
info system:start:time=6980:time=6980
info hardware:no_wan:: WiFi only device. No WAN found
info system:config:platform=wario,board=muscat,rev=07,proto=Y,wifi=Y,wan=N:platform=wario,board=muscat,rev=07,proto=Y,wifi=Y,wan=N
info milestone:7.14:sy51:sy51
lipc-send-event[835]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
lipc-send-event[836]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
lipc-send-event[836]: E lipc:con::Connection error(Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory)
lipc-send-event[836]: C def:dbusi::Failed to init dbus
lipc-send-event[836]: E def:open::Failed to open LIPC
lipc-send-event[836]: E def:fail:source=com.lab126.hal, event=usbPlugIn:Sending event failed
lipc-send-event[835]: E lipc:con::Connection error(Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory)
lipc-send-event[835]: C def:dbusi::Failed to init dbus
lipc-send-event[835]: E def:open::Failed to open LIPC
lipc-send-event[835]: E def:fail:source=com.lab126.hal, event=usbPlugIn:Sending event failed
info milestone:8.02:sy99:sy99
info system:done:time=8050:time=8050
crond[848]: crond (busybox 1.28.3) started, log level 8

init.exe: sshd main process (847) terminated with status 127
init.exe: sshd main process endedinit.exe: recevent pre-start process (851) terminated with status 1



Welcome to Kindle!

kindle login: info milestone:8.36:sc01:sc01
info system_fs_loopbacks:mountingfs:Mounting compressed directories filesystem images:Mounting compressed directories filesystem images
info milestone:8.39:sc02:sc02
info milestone:8.42:/usr/share/X11/xkb:/usr/share/X11/xkb
info system_fs_loopbacks:mounted:Image /usr/share/X11/xkb.sqsh mounted:Image /usr/share/X11/xkb.sqsh mounted
info milestone:8.46:3:3
info milestone:8.47:sc05:sc05
info milestone:8.49:/usr/java/lib/fonts:/usr/java/lib/fonts
info system_fs_loopbacks:mounted:Image /usr/java/lib/fonts.sqsh mounted:Image /usr/java/lib/fonts.sqsh mounted
info milestone:8.53:4:4
info milestone:8.53:sc05:sc05
info milestone:8.55:/etc/kdb.src:/etc/kdb.src
info system_fs_loopbacks:mounted:Image /etc/kdb.src.sqsh mounted:Image /etc/kdb.src.sqsh mounted
info milestone:8.58:5:5
info milestone:8.59:sc05:sc05
info milestone:8.61:/usr/lib/locale:/usr/lib/locale
info system_fs_loopbacks:mounted:Image /usr/lib/locale.sqsh mounted:Image /usr/lib/locale.sqsh mounted
info milestone:8.64:6:6
info milestone:8.65:sc05:sc05
info milestone:8.67:/usr/share/keyboard:/usr/share/keyboard
info system_fs_loopbacks:mounted:Image /usr/share/keyboard.sqsh mounted:Image /usr/share/keyboard.sqsh mounted
info milestone:8.79:7:7
info milestone:8.80:sc05:sc05
info milestone:8.82:/opt/var/local:/opt/var/local
info system_fs_loopbacks:mounted:Image /opt/var/local.sqsh mounted:Image /opt/var/local.sqsh mounted
info milestone:8.86:8:8
info milestone:8.86:sc05:sc05
info milestone:8.87:sc07:sc07
info system:emiting_event:mounted_fs_loopbacks:mounted_fs_loopbacks
debug sytem:event_emitted:mounted_fs_loopbacks:mounted_fs_loopbacks
info milestone:8.92:fs75:fs75
info system:emiting_event:loaded_modules_dependencies:loaded_modules_dependencies
debug sytem:event_emitted:loaded_modules_dependencies:loaded_modules_dependencies
info modules:modprobe:loading module fsl_otg_arc:loading module fsl_otg_arc
info system:emiting_event:loaded_fsl_otg_arc:loaded_fsl_otg_arc
debug sytem:event_emitted:loaded_fsl_otg_arc:loaded_fsl_otg_arc
info modules:modprobe:loading module ehci_hcd:loading module ehci_hcd
info system:emiting_event:loaded_ehci_hcd:loaded_ehci_hcd
debug sytem:event_emitted:loaded_ehci_hcd:loaded_ehci_hcd
info modules:modprobe:loading module fuse:loading module fuse
info system:emiting_event:loaded_fuse:loaded_fuse
debug sytem:event_emitted:loaded_fuse:loaded_fuse
info hardware:no_wan:: WiFi only device. No WAN found
info milestone:9.22:fs00:fs00
info system:emiting_event:loaded_ppp_async:loaded_ppp_async
debug sytem:event_emitted:loaded_ppp_async:loaded_ppp_async
info system:emiting_event:loaded_fakekey:loaded_fakekey
info filesystems_keys:not applicable for this device type::
debug sytem:event_emitted:loaded_fakekey:loaded_fakekey
info filesystems_var_local:DB PARAMS:FreePageSize:0 bytes. AvailableSpaceInVarLocal:41789 KB.:FreePageSize:0 bytes. AvailableSpaceInVarLocal:41789 KB.
info milestone:9.86:fs23:fs23
info system:emiting_event:mounted_varLocal:mounted_varLocal
debug sytem:event_emitted:mounted_varLocal:mounted_varLocal
info milestone:9.92:fs25:fs25
info milestone:9.96:vi00:vi00
info prereg:PRAGMA_QUICK_CHECK_PASSED:: sts=0
info userstore:run:time=10350,action=start:time=10350,action=start
info display:update:Checking '/opt/eink/images/R186_ED060KD1C3' for overrides:Checking '/opt/eink/images/R186_ED060KD1C3' for overrides
info userstore:start:found_shutdown_flag:found_shutdown_flag Found SHUTDOWN flag file
err mntus:loopback_not_mounted:: loopback device is not set-up
info system:emiting_event:loaded_touch:loaded_touch
debug sytem:event_emitted:loaded_touch:loaded_touch
info system:emiting_event:mounted_userstore:mounted_userstore
debug sytem:event_emitted:mounted_userstore:mounted_userstore
info milestone:11.68:fs50:fs50
info milestone:11.75:fs90:fs90
info milestone:11.82:fs99:fs99
info milestone:12.48:vi99:vi99
info display:started:time=12500:time=12500
info system:emiting_event:display_ready:display_ready
debug sytem:event_emitted:display_ready:display_ready
info battery:charged:cap=78,mV=3888,mAH=1074:cap=78,mV=3888,mAH=1074
info system:emiting_event:battery_ready:battery_ready
debug sytem:event_emitted:battery_ready:battery_ready
info milestone:12.80:sys99:sys99
info system_setup:system_setup_after_shpm done::
info system:emiting_event:dbus_ready:dbus_ready
debug sytem:event_emitted:dbus_ready:dbus_ready
info dbus:check-update:status=2:status=2 dbus_ready sent
info demd:starting...::
info perfd:starting...::
info hardware:no_wan:: WiFi only device. No WAN found
info milestone:14.25:dy01:dy01
info milestone:14.80:dy03:dy03
info milestone:14.78:dy02:dy02
info milestone:15.23:xx00:xx00
info X:load:time=15330:time=15330
info X:xorg.conf:Generating xorg.conf:Generating xorg.conf
info X:xorg.conf:xorg.conf generated:xorg.conf generated
info milestone:17.06:xx50:xx50
info X:starting:time=17100:time=17100
info milestone:20.00:xx99:xx99
info X:started:time=20050:time=20050
info system:emiting_event:x_setup_ready:x_setup_ready
debug sytem:event_emitted:x_setup_ready:x_setup_ready
info asr_setup:Not in asr mode::reason=flag file not present. shutting down asr_setup::
info locale:read:lang=en_US.utf8,lc_all=en_US.utf8:lang=en_US.utf8,lc_all=en_US.utf8 Retrieved Language
info system:emiting_event:langpicker_ready:langpicker_ready LANG_PICKER_SCREEN_SHOWN=0
debug sytem:event_emitted:langpicker_ready:langpicker_ready LANG_PICKER_SCREEN_SHOWN=0
info ffsd:not a first boot after shipmode::
info ffsd:stopped...::
info blanket_f:module already loaded:splash:splash
info system:emiting_event:start_splash:start_splash
debug sytem:event_emitted:start_splash:start_splash
info asr_bt_reboot:asr_bt_reboot begin on started winmgr_ready::
info milestone:22.04:pi00:pi00
info milestone:22.28:pi99:pi99
info system:emiting_event:contentpack_font_ready:contentpack_font_ready
debug sytem:event_emitted:contentpack_font_ready:contentpack_font_ready
info milestone:24.79:fr00:fr00
info milestone:24.93:fr50:fr50
info milestone:24.99:fr51:fr51
info framework:starting:time=26770:time=26770
info framework:commandLine:HEAP = -Xmx33m -Xms33m -XX:MaxNewSize=4m -XX:SurvivorRatio=3 -XX:TargetSurvivorRatio=80 -Xss100k -XX:ReservedCodeCacheSize=3m -XX:+InitialGenPreTouch -XX:CompileThreshold=5000 -XX:CodeCacheMinimumFreeSpace=100k -XX:NmethodSweepFraction=6 -XX:NmethodSweepActivity=2 -XX:NmethodSweepMaxWaitTime=8 -XX:NmethodHotnessCounterResetValue=64 -XX:MinHeapFreeRatio=5 -XX:MaxHeapFreeRatio=15 -XX:+UseAggressiveHeapShrink -XX:MaxInlineSize=16 -XX:MaxInlineLevel=2 -XX:-InlineSynchronizedMethods -minimal:HEAP = -Xmx33m -Xms33m -XX:MaxNewSize=4m -XX:SurvivorRatio=3 -XX:TargetSurvivorRatio=80 -Xss100k -XX:ReservedCodeCacheSize=3m -XX:+InitialGenPreTouch -XX:CompileThreshold=5000 -XX:CodeCacheMinimumFreeSpace=100k -XX:NmethodSweepFraction=6 -XX:NmethodSweepActivity=2 -XX:NmethodSweepMaxWaitTime=8 -XX:NmethodHotnessCounterResetValue=64 -XX:MinHeapFreeRatio=5 -XX:MaxHeapFreeRatio=15 -XX:+UseAggressiveHeapShrink -XX:MaxInlineSize=16 -XX:MaxInlineLevel=2 -XX:-InlineSynchronizedMethods -minimal
info hardware:no_wan:: WiFi only device. No WAN found
info framework:##### Starting Java SE8 VM ::
info milestone:56.93:fr99:fr99
info framework:started:time=57040,delta=32060:time=57040,delta=32060
warn framework_setup:cannot get ffsdStatus::
info framework_setup:ffs Status=::
info framework_setup:ffsd is not active or ffs is complete::
info blanket_f:loading blanket module:usb:usb
info blanket_f:unloading blanket module:splash:splash
info system:emiting_event:framework_ready:framework_ready
debug sytem:event_emitted:framework_ready:framework_ready
info stored:started::
info fastmetrics:starting...::
info clickstreamHeartbeatMetricsFramework:Skipping metrics recording, as it is the same day::
info stored:read_in_counters:REBOOTS=0, REBOOT_LIMIT=1, RESTARTS=0, RESTART_LIMIT=5:REBOOTS=0, REBOOT_LIMIT=1, RESTARTS=0, RESTART_LIMIT=5
info monitor:writing_file:file=/var/run/upstart/stored.restarts:file=/var/run/upstart/stored.restarts
Retrieved 394 keys for system/daemon/pmond/
root
#################################################
#  N O T I C E  *  N O T I C E  *  N O T I C E  #
#################################################
Rootfs is mounted read-only. Invoke mntroot rw to
switch back to a writable rootfs.
#################################################
[root@kindle root]# showlog -f
[!]191215:014405 cvm[4369]: 	at com.amazon.kindle.restricted.webservices.messaging.impl.AmazonMessagingServiceImpl.a(AmazonMessagingServiceImpl.java:34)
[!]191215:014405 cvm[4369]: 	at com.amazon.kindle.restricted.webservices.messaging.impl.AmazonMessagingServiceImpl$1.run(AmazonMessagingServiceImpl.java:60)
[!]191215:014405 cvm[4369]: 	at com.amazon.ebook.util.thread.ThreadPool$a.run(ThreadPool.java:613)
[!]191215:014405 cvm[4369]: 	at java.lang.Thread.run(Unknown Source)
   191215:014405 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=CampaignSync.Update:Requesting an alias
   191215:014405 cvm[4369]: W lipc:sun:serial=5:Reply for unknown serial
   191215:014405 cvm[4369]: W lipc:sfr::Failed to remove serial from hash
   191215:014405 cvm[4369]: W lipc:sun:serial=5:Reply for unknown serial
[!]191215:014407 pmond[5162]: W def:::Unable to fetch the proc
[!]191215:014407 login[857]: root login on 'ttymxc0'
   191215:014416 powerd[1989]: I def:pbpress:time=1576374256.269:Power button pressed
   191215:014416 [   96.283856] KERNEL: I pmic:onkey::wario button online event
   191215:014416 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=active_handle_power_button,name=GoingToScreensaverDueToPowerButtonPress,value=1
   191215:014416 powerd[1989]: I def:statech:prev=ACTIVE, next=SCREEN SAVER:State change: ACTIVE -> SCREEN SAVER
   191215:014416 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=state_active_exit,name=DeviceActiveDuration,value=81418
   191215:014416 powerd[1989]: I lipc:evts:name=goingToScreenSaver, origin=com.lab126.powerd, fparam=2:Event sent
[!]191215:014416 powerd[1989]: I def:powerd:low_temp_state:g_is_screensaver_drawn = (1)
[!]191215:014416 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[35.180712]:  on OnpowerdEventCallback goingToScreenSaver :
[!]191215:014416 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[35.180868]: Flush on OnpowerdEventCallback goingToScreenSaver :
   191215:014416 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374256331, End - 1576374256331
   191215:014416 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374256332, End - 1576374256332
   191215:014416 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374256336, End - 1576374256336
   191215:014416 powerd[1989]: I def:batmon:Charging state for PRIMARY battery = NOT CHARGING:
   191215:014416 cvm[4369]: I IndexerThread:CLEANUP:action=BEGIN_INDEXER_CLEANUP:
[!]191215:014416 winmgr[2818]: I winmgr:goingToScreenSaver:event received:
[!]191215:014416 powerd[1989]: I def:batmon:Charging Status,  is_usb_connected = 0, is_primary_batt_charging = 0:
[!]191215:014416 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=goingToScreenSaver
[!]191215:014416 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 1
   191215:014416 lipc-daemon[1954]: W def:cmd::Command [/usr/sbin/force_compaction] returned error (1)
[!]191215:014416 cvm[4369]: I certman_util:jWriteToKeyFile:Write hash to persistent storage:
[!]191215:014416 fastmetrics[5247]: I fastmetrics:emitPayload:[35.336629]: Payload key screensaver_event value goingToScreenSaver  :
[!]191215:014416 fastmetrics[5247]: I fastmetrics:emitPayload:[35.336747]: Payload key kso_status value NON-KSO  :
[!]191215:014416 fastmetrics[5247]: I fastmetrics:emitRecord:[35.336805]: Emitting via SDK now :
[!]191215:014416 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[35.349484]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014416 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014416 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374256337, End - 1576374256538
   191215:014416 cvm[4369]: E ReadingStreamODOTProcessor:Error::current profile id found null while going to enqueue message to odot db
   191215:014416 cvm[4369]: E ReadingStreamsServiceImpl:Error::unable to flush message, device is in unregistered state
[!]191215:014416 cvm[4369]: com.amazon.kindle.webservices.registration.CustomerNotFoundException: current profile id found null
[!]191215:014416 cvm[4369]: 	at com.amazon.kindle.readingstreams.processor.odot.ReadingStreamsODOTProcessor.G(ReadingStreamsODOTProcessor.java:84)
[!]191215:014416 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.G(ReadingStreamsServiceImpl.java:693)
[!]191215:014416 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.lf(ReadingStreamsServiceImpl.java:676)
[!]191215:014416 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.a(ReadingStreamsServiceImpl.java:54)
[!]191215:014416 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl$7.run(ReadingStreamsServiceImpl.java:646)
[!]191215:014416 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
[!]191215:014416 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
[!]191215:014416 cvm[4369]: 	at java.lang.Thread.run(Unknown Source)
   191215:014416 cvm[4369]: I IndexerThread:CLEANUP:action=DONE_INDEXER_CLEANUP:
   191215:014416 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374256901, End - 1576374256901
   191215:014416 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374256902, End - 1576374256902
   191215:014416 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=invisible:Event sent
   191215:014416 blanket[2819]: I x11Handler:X11_EVENT:win=400002,xev_type=12,module=screensaver:
   191215:014430 cvm[4369]: E lipc:name::Name error(Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the networkconnection was broken.)
   191215:014430 cvm[4369]: E AmazonMessagingServiceImpl:ExceptionCaught::Error requesting alias
[!]191215:014430 cvm[4369]: com.amazon.kindle.util.lipc.LipcException: Failed to get alias.  ErrCode=21
[!]191215:014430 cvm[4369]: 	at com.lab126.linux.arm.LipcImpl.requestAlias0(Native Method)
[!]191215:014430 cvm[4369]: 	at com.lab126.linux.arm.LipcImpl.requestAlias(LipcImpl.java:101)
[!]191215:014430 cvm[4369]: 	at com.amazon.kindle.util.lipc.impl.LipcSourceImpl.requestAlias(LipcSourceImpl.java:199)
[!]191215:014430 cvm[4369]: 	at com.amazon.kindle.restricted.webservices.messaging.impl.AmazonMessagingServiceImpl.cRL(AmazonMessagingServiceImpl.java:111)
[!]191215:014430 cvm[4369]: 	at com.amazon.kindle.restricted.webservices.messaging.impl.AmazonMessagingServiceImpl.init(AmazonMessagingServiceImpl.java:86)
[!]191215:014430 cvm[4369]: 	at com.amazon.kindle.restricted.webservices.messaging.impl.AmazonMessagingServiceImpl.a(AmazonMessagingServiceImpl.java:34)
[!]191215:014430 cvm[4369]: 	at com.amazon.kindle.restricted.webservices.messaging.impl.AmazonMessagingServiceImpl$1.run(AmazonMessagingServiceImpl.java:60)
[!]191215:014430 cvm[4369]: 	at com.amazon.ebook.util.thread.ThreadPool$a.run(ThreadPool.java:613)
[!]191215:014430 cvm[4369]: 	at java.lang.Thread.run(Unknown Source)
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=DPCService.SettingChanged:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=DeviceMessaging.LanguageLayer.MessageResponse:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=HouseholdMessage.Updates:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=KindleDemoCloudApproach.ActivateDemo:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=KindleDemoCloudApproach.GetAvailableDemos:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=KindleDemoCloudApproach.ResetDemo:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=dtcp.adpk.download:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=dtcp.adpk.remove:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=dtcp.set.adrs:Requesting an alias
   191215:014430 cvm[4369]: I LipcSourceImpl:RequestingAlias:name=whispersync.notification:Requesting an alias
   191215:014430 cvm[4369]: I lipc:evts:name=ADMMessageHandlerLoaded, origin=com.lab126.kaf:Event sent
   191215:014430 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.kaf , Event Name - ADMMessageHandlerLoaded : Time Start - 1576374270545, End - 1576374270545
   191215:014430 cvm[4369]: I ContentReadStateLifeCycleManager:Information::ADM message handler is loaded. Lets check to trigger the backfill
   191215:014430 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.kaf , Event Name - ADMMessageHandlerLoaded : Time Start - 1576374270546, End - 1576374270549
   191215:014441 powerd[1989]: I def:pbpress:time=1576374281.033:Power button pressed
   191215:014441 [  121.065819] KERNEL: I pmic:onkey::wario button online event
[!]191215:014441 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[59.911964]:  on OnpowerdEventCallback t1TimerReset :
   191215:014441 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - t1TimerReset : Time Start - 1576374281062, End - 1576374281062
   191215:014441 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - t1TimerReset : Time Start - 1576374281063, End - 1576374281063
   191215:014441 powerd[1989]: I def:statech:prev=SCREEN SAVER, next=ACTIVE:State change: SCREEN SAVER -> ACTIVE
   191215:014441 powerd[1989]: I lipc:evts:name=t1TimerReset, origin=com.lab126.powerd:Event sent
[!]191215:014441 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[59.956512]:  on OnpowerdEventCallback outOfScreenSaver :
   191215:014441 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374281108, End - 1576374281108
   191215:014441 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374281110, End - 1576374281111
   191215:014441 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374281112, End - 1576374281112
   191215:014441 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=visible:Event sent
   191215:014441 blanket[2819]: W def:lipc:method=LipcOpenEx service=com.lab126.screensaver:Method has been deprecated.
[!]191215:014441 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=outOfScreenSaver
   191215:014441 powerd[1989]: I lipc:evts:name=outOfScreenSaver, origin=com.lab126.powerd, fparam=1:Event sent
   191215:014441 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374281156, End - 1576374281157
[!]191215:014441 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 0
   191215:014441 blanket[2819]: I lipc:evts:name=unmap_screensaver, origin=com.lab126.screensaver:Event sent
   191215:014441 blanket[2819]: I lipc:evts:name=nonDtcpScreensaverOut, origin=com.lab126.screensaver:Event sent
   191215:014441 powerd[1989]: I lipc:evts:name=exitingScreenSaver, origin=com.lab126.powerd:Event sent
[!]191215:014441 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[60.037310]:  on OnpowerdEventCallback exitingScreenSaver :
   191215:014441 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - exitingScreenSaver : Time Start - 1576374281189, End - 1576374281189
[!]191215:014441 fastmetrics[5247]: I fastmetrics:emitPayload:[60.114898]: Payload key screensaver_event value outOfScreenSaver  :
[!]191215:014441 fastmetrics[5247]: I fastmetrics:emitPayload:[60.115016]: Payload key kso_status value NON-KSO  :
[!]191215:014441 fastmetrics[5247]: I fastmetrics:emitRecord:[60.115077]: Emitting via SDK now :
[!]191215:014441 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[60.124591]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014441 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014441 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374281112, End - 1576374281293
   191215:014441 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374281294, End - 1576374281294
[!]191215:014441 fastmetrics[5247]: I fastmetrics:emitPayload:[60.178921]: Payload key screensaver_event value exitingScreenSaver  :
[!]191215:014441 fastmetrics[5247]: I fastmetrics:emitPayload:[60.179094]: Payload key kso_status value NON-KSO  :
[!]191215:014441 fastmetrics[5247]: I fastmetrics:emitRecord:[60.179162]: Emitting via SDK now :
[!]191215:014441 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[60.188378]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014441 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014441 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - exitingScreenSaver : Time Start - 1576374281297, End - 1576374281357
   191215:014441 cvm[4369]: I StatusBarController:Information::Initiating Clock Timer
   191215:014445 powerd[1989]: I def:pbpress:time=1576374285.336:Power button pressed
   191215:014445 [  125.367816] KERNEL: I pmic:onkey::wario button online event
   191215:014445 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=active_handle_power_button,name=GoingToScreensaverDueToPowerButtonPress,value=1
   191215:014445 powerd[1989]: I def:statech:prev=ACTIVE, next=SCREEN SAVER:State change: ACTIVE -> SCREEN SAVER
   191215:014445 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=state_active_exit,name=DeviceActiveDuration,value=4398
   191215:014445 powerd[1989]: I lipc:evts:name=goingToScreenSaver, origin=com.lab126.powerd, fparam=2:Event sent
[!]191215:014445 powerd[1989]: I def:powerd:low_temp_state:g_is_screensaver_drawn = (1)
[!]191215:014445 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[64.324225]:  on OnpowerdEventCallback goingToScreenSaver :
[!]191215:014445 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[64.324305]: Flush on OnpowerdEventCallback goingToScreenSaver :
   191215:014445 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374285474, End - 1576374285474
   191215:014445 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374285475, End - 1576374285475
   191215:014445 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374285476, End - 1576374285476
[!]191215:014445 winmgr[2818]: I winmgr:goingToScreenSaver:event received:
[!]191215:014445 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=goingToScreenSaver
   191215:014445 cvm[4369]: I IndexerThread:CLEANUP:action=BEGIN_INDEXER_CLEANUP:
[!]191215:014445 cvm[4369]: I certman_util:jWriteToKeyFile:Write hash to persistent storage:
   191215:014445 powerd[1989]: I def:batmon:Charging state for PRIMARY battery = NOT CHARGING:
[!]191215:014445 powerd[1989]: I def:batmon:Charging Status,  is_usb_connected = 0, is_primary_batt_charging = 0:
[!]191215:014445 fastmetrics[5247]: I fastmetrics:emitPayload:[64.384018]: Payload key screensaver_event value goingToScreenSaver  :
[!]191215:014445 fastmetrics[5247]: I fastmetrics:emitPayload:[64.384138]: Payload key kso_status value NON-KSO  :
[!]191215:014445 fastmetrics[5247]: I fastmetrics:emitRecord:[64.384199]: Emitting via SDK now :
[!]191215:014445 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 1
[!]191215:014445 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[64.394445]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014445 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014445 cvm[4369]: E ReadingStreamODOTProcessor:Error::current profile id found null while going to enqueue message to odot db
   191215:014445 cvm[4369]: E ReadingStreamsServiceImpl:Error::unable to flush message, device is in unregistered state
[!]191215:014445 cvm[4369]: com.amazon.kindle.webservices.registration.CustomerNotFoundException: current profile id found null
[!]191215:014445 cvm[4369]: 	at com.amazon.kindle.readingstreams.processor.odot.ReadingStreamsODOTProcessor.G(ReadingStreamsODOTProcessor.java:84)
[!]191215:014445 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.G(ReadingStreamsServiceImpl.java:693)
[!]191215:014445 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.lf(ReadingStreamsServiceImpl.java:676)
[!]191215:014445 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.a(ReadingStreamsServiceImpl.java:54)
[!]191215:014445 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl$7.run(ReadingStreamsServiceImpl.java:646)
[!]191215:014445 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
[!]191215:014445 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
[!]191215:014445 cvm[4369]: 	at java.lang.Thread.run(Unknown Source)
   191215:014445 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374285476, End - 1576374285562
   191215:014445 lipc-daemon[1954]: W def:cmd::Command [/usr/sbin/force_compaction] returned error (1)
   191215:014445 cvm[4369]: I IndexerThread:CLEANUP:action=DONE_INDEXER_CLEANUP:
   191215:014445 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374285997, End - 1576374285997
   191215:014445 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374285998, End - 1576374285998
   191215:014445 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=invisible:Event sent
   191215:014446 blanket[2819]: I x11Handler:X11_EVENT:win=400002,xev_type=12,module=screensaver:



[!]191215:014500 crond[848]: USER root pid 5697 cmd /usr/sbin/tinyrot
[!]191215:014500 crond[848]: USER root pid 5698 cmd /usr/sbin/loginfo powerdcheck
   191215:014500 system: W tinyrot:def::Still booting - not doing anything until later
   191215:014515 powerd[1989]: I def:pbpress:time=1576374315.226:Power button pressed
   191215:014515 powerd[1989]: I def:statech:prev=SCREEN SAVER, next=ACTIVE:State change: SCREEN SAVER -> ACTIVE
   191215:014515 powerd[1989]: I lipc:evts:name=t1TimerReset, origin=com.lab126.powerd:Event sent
   191215:014515 [  155.252017] KERNEL: I pmic:onkey::wario button online event
[!]191215:014515 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[94.160068]:  on OnpowerdEventCallback t1TimerReset :
   191215:014515 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - t1TimerReset : Time Start - 1576374315332, End - 1576374315332
   191215:014515 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - t1TimerReset : Time Start - 1576374315338, End - 1576374315338
[!]191215:014515 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[94.202005]:  on OnpowerdEventCallback outOfScreenSaver :
   191215:014515 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374315351, End - 1576374315351
   191215:014515 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374315352, End - 1576374315352
[!]191215:014515 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=outOfScreenSaver
   191215:014515 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374315357, End - 1576374315357
   191215:014515 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=visible:Event sent
   191215:014515 blanket[2819]: W def:lipc:method=LipcOpenEx service=com.lab126.screensaver:Method has been deprecated.
   191215:014515 powerd[1989]: I lipc:evts:name=outOfScreenSaver, origin=com.lab126.powerd, fparam=1:Event sent
   191215:014515 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374315389, End - 1576374315389
   191215:014515 blanket[2819]: I lipc:evts:name=unmap_screensaver, origin=com.lab126.screensaver:Event sent
   191215:014515 blanket[2819]: I lipc:evts:name=nonDtcpScreensaverOut, origin=com.lab126.screensaver:Event sent
[!]191215:014515 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 0
   191215:014515 powerd[1989]: I lipc:evts:name=exitingScreenSaver, origin=com.lab126.powerd:Event sent
[!]191215:014515 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[94.273829]:  on OnpowerdEventCallback exitingScreenSaver :
   191215:014515 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - exitingScreenSaver : Time Start - 1576374315427, End - 1576374315427
[!]191215:014515 fastmetrics[5247]: I fastmetrics:emitPayload:[94.376656]: Payload key screensaver_event value outOfScreenSaver  :
[!]191215:014515 fastmetrics[5247]: I fastmetrics:emitPayload:[94.376791]: Payload key kso_status value NON-KSO  :
[!]191215:014515 fastmetrics[5247]: I fastmetrics:emitRecord:[94.376851]: Emitting via SDK now :
[!]191215:014515 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[94.386526]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014515 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014515 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374315357, End - 1576374315540
   191215:014515 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374315541, End - 1576374315542
[!]191215:014515 fastmetrics[5247]: I fastmetrics:emitPayload:[94.426437]: Payload key screensaver_event value exitingScreenSaver  :
[!]191215:014515 fastmetrics[5247]: I fastmetrics:emitPayload:[94.426558]: Payload key kso_status value NON-KSO  :
[!]191215:014515 fastmetrics[5247]: I fastmetrics:emitRecord:[94.426641]: Emitting via SDK now :
[!]191215:014515 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[94.435962]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014515 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014515 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - exitingScreenSaver : Time Start - 1576374315544, End - 1576374315604
   191215:014515 cvm[4369]: I StatusBarController:Information::Initiating Clock Timer
   191215:014517 powerd[1989]: I def:pbpress:time=1576374317.859:Power button pressed
   191215:014517 [  157.890038] KERNEL: I pmic:onkey::wario button online event
   191215:014517 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=active_handle_power_button,name=GoingToScreensaverDueToPowerButtonPress,value=1
   191215:014517 powerd[1989]: I def:statech:prev=ACTIVE, next=SCREEN SAVER:State change: ACTIVE -> SCREEN SAVER
   191215:014517 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=state_active_exit,name=DeviceActiveDuration,value=2697
   191215:014517 powerd[1989]: I lipc:evts:name=goingToScreenSaver, origin=com.lab126.powerd, fparam=2:Event sent
[!]191215:014517 powerd[1989]: I def:powerd:low_temp_state:g_is_screensaver_drawn = (1)
[!]191215:014517 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[96.834358]:  on OnpowerdEventCallback goingToScreenSaver :
[!]191215:014517 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[96.834438]: Flush on OnpowerdEventCallback goingToScreenSaver :
   191215:014517 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374317984, End - 1576374317984
   191215:014517 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374317985, End - 1576374317985
   191215:014517 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374317986, End - 1576374317986
[!]191215:014517 winmgr[2818]: I winmgr:goingToScreenSaver:event received:
[!]191215:014517 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=goingToScreenSaver
   191215:014518 cvm[4369]: I IndexerThread:CLEANUP:action=BEGIN_INDEXER_CLEANUP:
[!]191215:014518 cvm[4369]: I certman_util:jWriteToKeyFile:Write hash to persistent storage:
   191215:014518 powerd[1989]: I def:batmon:Charging state for PRIMARY battery = NOT CHARGING:
[!]191215:014518 powerd[1989]: I def:batmon:Charging Status,  is_usb_connected = 0, is_primary_batt_charging = 0:
[!]191215:014518 fastmetrics[5247]: I fastmetrics:emitPayload:[96.896950]: Payload key screensaver_event value goingToScreenSaver  :
[!]191215:014518 fastmetrics[5247]: I fastmetrics:emitPayload:[96.897069]: Payload key kso_status value NON-KSO  :
[!]191215:014518 fastmetrics[5247]: I fastmetrics:emitRecord:[96.897131]: Emitting via SDK now :
[!]191215:014518 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 1
[!]191215:014518 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[96.907637]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014518 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014518 cvm[4369]: E ReadingStreamODOTProcessor:Error::current profile id found null while going to enqueue message to odot db
   191215:014518 cvm[4369]: E ReadingStreamsServiceImpl:Error::unable to flush message, device is in unregistered state
[!]191215:014518 cvm[4369]: com.amazon.kindle.webservices.registration.CustomerNotFoundException: current profile id found null
[!]191215:014518 cvm[4369]: 	at com.amazon.kindle.readingstreams.processor.odot.ReadingStreamsODOTProcessor.G(ReadingStreamsODOTProcessor.java:84)
[!]191215:014518 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.G(ReadingStreamsServiceImpl.java:693)
[!]191215:014518 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.lf(ReadingStreamsServiceImpl.java:676)
[!]191215:014518 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.a(ReadingStreamsServiceImpl.java:54)
[!]191215:014518 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl$7.run(ReadingStreamsServiceImpl.java:646)
[!]191215:014518 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
[!]191215:014518 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
[!]191215:014518 cvm[4369]: 	at java.lang.Thread.run(Unknown Source)
   191215:014518 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374317986, End - 1576374318076
   191215:014518 lipc-daemon[1954]: W def:cmd::Command [/usr/sbin/force_compaction] returned error (1)
   191215:014518 cvm[4369]: I IndexerThread:CLEANUP:action=DONE_INDEXER_CLEANUP:
   191215:014518 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374318455, End - 1576374318455
   191215:014518 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374318456, End - 1576374318456
   191215:014518 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=invisible:Event sent
   191215:014518 blanket[2819]: I x11Handler:X11_EVENT:win=400002,xev_type=12,module=screensaver:



   191215:014559 powerd[1989]: I lipc:evts:name=battLevelChanged, origin=com.lab126.powerd, fparam=76:Event sent
[!]191215:014559 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[137.978628]:  on OnpowerdEventCallback battLevelChanged :
   191215:014559 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - battLevelChanged : Time Start - 1576374359151, End - 1576374359151
   191215:014559 cvm[4369]: I BatteryServiceImpl:Information::Battery Event = battLevelChanged, Started at = 1576374359151, Ended at = 1576374359152
   191215:014559 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - battLevelChanged : Time Start - 1576374359151, End - 1576374359152
   191215:014559 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - battLevelChanged : Time Start - 1576374359162, End - 1576374359162
   191215:014559 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - battLevelChanged : Time Start - 1576374359166, End - 1576374359166
   191215:014615 cvm[4369]: I TransferServiceImpl:Request:requestType=cleanupOrphanedTransfers,id=-1,key=null,status=success:Succesfully cleaned up orphan transfers
   191215:014618 powerd[1989]: I def:statech:prev=SCREEN SAVER, next=READY TO SUSPEND:State change: SCREEN SAVER -> READY TO SUSPEND
   191215:014618 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=10:Event sent
[!]191215:014618 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[156.907058]:  on OnpowerdEventCallback readyToSuspend :
   191215:014618 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014618 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=10,status=0:
   191215:014618 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 10:
   191215:014618 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374378086, End - 1576374378087
   191215:014618 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374378091, End - 1576374378095
   191215:014618 cvm[4369]: I IndexerThread:Information::allowed to index: ALL CONDITIONS MET
   191215:014618 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014618 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374378095, End - 1576374378099
   191215:014618 cvm[4369]: I MetadataStore:Information::campaignList size while validating0
   191215:014618 cvm[4369]: I MetadataStore:Information::Eligible card count0
   191215:014618 cvm[4369]: I MerchantManagerImpl:RefreshActiveCampaignList:ForceUpdate=true,IsFirstRefreshAfterSync=false,CardRotationStrategy=NEW_SESSION,IsCampaignListInvalid=true:
   191215:014618 cvm[4369]: I MetadataStore:Information::Eligible card count0
   191215:014618 cvm[4369]: I MetadataStore:Information::Eligible card count0
[!]191215:014618 fastmetrics[5247]: I fastmetrics:endReadingSession:[156.966239]: Ending reading session SDK :
[!]191215:014618 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[156.966366]: Successfully uploaded metric :readingSessionEndStatus with value :0 :
   191215:014618 cvm[4369]: I FMSessionController:Information::[FastMetrics] End reading session
   191215:014618 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374378099, End - 1576374378123

   191215:014623 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=8:Event sent
[!]191215:014623 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[161.918131]:  on OnpowerdEventCallback readyToSuspend :
   191215:014623 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 8:
   191215:014623 phd[2096]: I udp_tphv3:recevied wan will suspend event....::
   191215:014623 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014623 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=8,status=0:
   191215:014623 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374383097, End - 1576374383104
   191215:014623 cvm[4369]: I IndexerThread:Information::not allowed to index: GOING TO SUSPEND
   191215:014623 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014623 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374383105, End - 1576374383106
   191215:014623 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374383101, End - 1576374383106
   191215:014623 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374383106, End - 1576374383106

   191215:014628 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=7:Event sent
[!]191215:014628 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[166.927635]:  on OnpowerdEventCallback readyToSuspend :
   191215:014628 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374388113, End - 1576374388113
   191215:014628 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014628 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374388114, End - 1576374388114
   191215:014628 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374388115, End - 1576374388115
   191215:014628 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374388115, End - 1576374388116
   191215:014628 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014628 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=7,status=0:
   191215:014628 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 7:
   191215:014628 cmd[1964]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:

   191215:014633 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=6:Event sent
[!]191215:014633 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[171.930575]:  on OnpowerdEventCallback readyToSuspend :
   191215:014633 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374393128, End - 1576374393138
   191215:014633 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374393138, End - 1576374393139
   191215:014633 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374393118, End - 1576374393139
   191215:014633 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014633 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374393139, End - 1576374393139
   191215:014633 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014633 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=6,status=0:
   191215:014633 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 6:

   191215:014638 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=2:Event sent
[!]191215:014638 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[176.930953]:  on OnpowerdEventCallback readyToSuspend :
   191215:014638 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014638 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=2,status=0:
   191215:014638 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 2:
   191215:014638 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374398124, End - 1576374398124
   191215:014638 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374398124, End - 1576374398124
   191215:014638 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014638 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374398125, End - 1576374398125
   191215:014638 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374398125, End - 1576374398125
   191215:014640 powerd[1989]: I def:pbpress:time=1576374400.396:Power button pressed
   191215:014640 [  240.427523] KERNEL: I pmic:onkey::wario button online event
   191215:014640 powerd[1989]: I lipc:evts:name=notReadyToSuspend, origin=com.lab126.powerd:Event sent
   191215:014640 powerd[1989]: I def:statech:prev=READY TO SUSPEND, next=ACTIVE:State change: READY TO SUSPEND -> ACTIVE
   191215:014640 powerd[1989]: I def:r2stime:secs=22, next=ACTIVE:Time spent in ready to suspend
   191215:014640 powerd[1989]: I lipc:evts:name=t1TimerReset, origin=com.lab126.powerd:Event sent
[!]191215:014640 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[179.321399]:  on OnpowerdEventCallback notReadyToSuspend :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[179.361708]:  on OnpowerdEventCallback t1TimerReset :
   191215:014640 certmand[4727]: I certmand:handleTransferStatus:status = 6, response code = -1, id = 1:
   191215:014640 cvm[4369]: W ReadNowDownloadListener:Warning::client data is null hence not processing
   191215:014640 tmd[2008]: I defer_active:redeferring:id=1,was=WAITING,wasby=NOTHING,now=DEFERRED,defby=WIRELESS_DISABLED,qpos=0 of 5,pri=1100,toppri=1100:
   191215:014640 tmd[2008]: I defer_active:redeferring:id=3,was=WAITING,wasby=NOTHING,now=DEFERRED,defby=WIRELESS_DISABLED,qpos=1 of 5,pri=1600,toppri=1100:
   191215:014640 tmd[2008]: I defer_active:redeferring:id=4,was=WAITING,wasby=NOTHING,now=DEFERRED,defby=WIRELESS_DISABLED,qpos=2 of 5,pri=1600,toppri=1100:
   191215:014640 tmd[2008]: I defer_active:redeferring:id=5,was=WAITING,wasby=NOTHING,now=DEFERRED,defby=WIRELESS_DISABLED,qpos=3 of 5,pri=1600,toppri=1100:
   191215:014640 tmd[2008]: I defer_active:redeferring:id=2,was=WAITING,wasby=NOTHING,now=DEFERRED,defby=WIRELESS_DISABLED,qpos=4 of 5,pri=1700,toppri=1100:
   191215:014640 tmd[2008]: W get_resp_body:fopen_err:id=2,status=DEFERRED,resp=-1,errno=No such file or directory (2):
   191215:014640 tmd[2008]: I sendstatus:server_said:id=2,code=-1,status=DEFERRED,body="(nofile)":
   191215:014640 cvm[4369]: W ReadNowDownloadListener:Warning::client data is null hence not processing
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - notReadyToSuspend : Time Start - 1576374400487, End - 1576374400538
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - notReadyToSuspend : Time Start - 1576374400539, End - 1576374400539
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - notReadyToSuspend : Time Start - 1576374400517, End - 1576374400540
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - t1TimerReset : Time Start - 1576374400540, End - 1576374400540
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - notReadyToSuspend : Time Start - 1576374400541, End - 1576374400546
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - t1TimerReset : Time Start - 1576374400546, End - 1576374400546
   191215:014640 cvm[4369]: W ReadNowDownloadListener:Warning::client data is null hence not processing
[!]191215:014640 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[179.405846]:  on OnpowerdEventCallback outOfScreenSaver :
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374400556, End - 1576374400556
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374400557, End - 1576374400557
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374400558, End - 1576374400558
   191215:014640 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=visible:Event sent
   191215:014640 blanket[2819]: W def:lipc:method=LipcOpenEx service=com.lab126.screensaver:Method has been deprecated.
[!]191215:014640 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=outOfScreenSaver
   191215:014640 powerd[1989]: I lipc:evts:name=outOfScreenSaver, origin=com.lab126.powerd, fparam=1:Event sent
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374400595, End - 1576374400595
[!]191215:014640 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 0
   191215:014640 blanket[2819]: I lipc:evts:name=unmap_screensaver, origin=com.lab126.screensaver:Event sent
   191215:014640 blanket[2819]: I lipc:evts:name=nonDtcpScreensaverOut, origin=com.lab126.screensaver:Event sent
   191215:014640 powerd[1989]: I lipc:evts:name=exitingScreenSaver, origin=com.lab126.powerd:Event sent
[!]191215:014640 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[179.477649]:  on OnpowerdEventCallback exitingScreenSaver :
   191215:014640 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - exitingScreenSaver : Time Start - 1576374400629, End - 1576374400629
[!]191215:014640 fastmetrics[5247]: I fastmetrics:emitPayload:[179.575387]: Payload key screensaver_event value outOfScreenSaver  :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:emitPayload:[179.575509]: Payload key kso_status value NON-KSO  :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:emitRecord:[179.575569]: Emitting via SDK now :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[179.585081]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014640 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - outOfScreenSaver : Time Start - 1576374400559, End - 1576374400748
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374400749, End - 1576374400749
[!]191215:014640 fastmetrics[5247]: I fastmetrics:emitPayload:[179.642277]: Payload key screensaver_event value exitingScreenSaver  :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:emitPayload:[179.642398]: Payload key kso_status value NON-KSO  :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:emitRecord:[179.642460]: Emitting via SDK now :
[!]191215:014640 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[179.651672]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014640 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014640 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - exitingScreenSaver : Time Start - 1576374400750, End - 1576374400820
   191215:014640 cvm[4369]: I StatusBarController:Information::Initiating Clock Timer
   191215:014745 powerd[1989]: I def:pbpress:time=1576374465.342:Power button pressed
   191215:014745 [  305.360236] KERNEL: I pmic:onkey::wario button online event
   191215:014745 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=active_handle_power_button,name=GoingToScreensaverDueToPowerButtonPress,value=1
   191215:014745 powerd[1989]: I def:statech:prev=ACTIVE, next=SCREEN SAVER:State change: ACTIVE -> SCREEN SAVER
   191215:014745 powerd[1989]: I def:metrics::prg_name=powerd,prg_source=state_active_exit,name=DeviceActiveDuration,value=64991
   191215:014745 powerd[1989]: I lipc:evts:name=goingToScreenSaver, origin=com.lab126.powerd, fparam=2:Event sent
[!]191215:014745 powerd[1989]: I def:powerd:low_temp_state:g_is_screensaver_drawn = (1)
[!]191215:014745 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[244.295516]:  on OnpowerdEventCallback goingToScreenSaver :
[!]191215:014745 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[244.295595]: Flush on OnpowerdEventCallback goingToScreenSaver :
   191215:014745 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374465445, End - 1576374465445
   191215:014745 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374465446, End - 1576374465446
   191215:014745 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374465447, End - 1576374465447
[!]191215:014745 winmgr[2818]: I winmgr:goingToScreenSaver:event received:
[!]191215:014745 deviced[2010]: I def:ipc:Event recieved:source=com.lab126.powerd,eventName=goingToScreenSaver
   191215:014745 cvm[4369]: I IndexerThread:Information::allowed to index: ALL CONDITIONS MET
   191215:014745 cvm[4369]: I IndexerThread:CLEANUP:action=BEGIN_INDEXER_CLEANUP:
[!]191215:014745 cvm[4369]: I certman_util:jWriteToKeyFile:Write hash to persistent storage:
   191215:014745 powerd[1989]: I def:batmon:Charging state for PRIMARY battery = NOT CHARGING:
[!]191215:014745 powerd[1989]: I def:batmon:Charging Status,  is_usb_connected = 0, is_primary_batt_charging = 0:
[!]191215:014745 deviced[2010]: I def:module:touch:IOCTL succeeded - Lock state is set to : 1
[!]191215:014745 fastmetrics[5247]: I fastmetrics:emitPayload:[244.362624]: Payload key screensaver_event value goingToScreenSaver  :
[!]191215:014745 fastmetrics[5247]: I fastmetrics:emitPayload:[244.362744]: Payload key kso_status value NON-KSO  :
[!]191215:014745 fastmetrics[5247]: I fastmetrics:emitRecord:[244.362807]: Emitting via SDK now :
[!]191215:014745 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[244.372507]: Successfully uploaded metric :recordEmitStatus with value :0 :
   191215:014745 cvm[4369]: I KindleSystemServicesImpl:Information::[FastMetrics] Successfully emitted payload for PowerManagementStateChange event
   191215:014745 cvm[4369]: E ReadingStreamODOTProcessor:Error::current profile id found null while going to enqueue message to odot db
   191215:014745 cvm[4369]: E ReadingStreamsServiceImpl:Error::unable to flush message, device is in unregistered state
[!]191215:014745 cvm[4369]: com.amazon.kindle.webservices.registration.CustomerNotFoundException: current profile id found null
[!]191215:014745 cvm[4369]: 	at com.amazon.kindle.readingstreams.processor.odot.ReadingStreamsODOTProcessor.G(ReadingStreamsODOTProcessor.java:84)
[!]191215:014745 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.G(ReadingStreamsServiceImpl.java:693)
[!]191215:014745 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.lf(ReadingStreamsServiceImpl.java:676)
[!]191215:014745 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl.a(ReadingStreamsServiceImpl.java:54)
[!]191215:014745 cvm[4369]: 	at com.amazon.kindle.readingstreams.service.impl.ReadingStreamsServiceImpl$7.run(ReadingStreamsServiceImpl.java:646)
[!]191215:014745 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
[!]191215:014745 cvm[4369]: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
[!]191215:014745 cvm[4369]: 	at java.lang.Thread.run(Unknown Source)
   191215:014745 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - goingToScreenSaver : Time Start - 1576374465448, End - 1576374465536
   191215:014745 lipc-daemon[1954]: W def:cmd::Command [/usr/sbin/force_compaction] returned error (1)
   191215:014745 cvm[4369]: I IndexerThread:CLEANUP:action=DONE_INDEXER_CLEANUP:
   191215:014745 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374465934, End - 1576374465934
   191215:014745 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.winmgr , Event Name - titleBarVisiblityChange : Time Start - 1576374465934, End - 1576374465935
   191215:014745 winmgr[2818]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=invisible:Event sent
   191215:014745 blanket[2819]: I x11Handler:X11_EVENT:win=400002,xev_type=12,module=screensaver:



   191215:014845 powerd[1989]: I def:statech:prev=SCREEN SAVER, next=READY TO SUSPEND:State change: SCREEN SAVER -> READY TO SUSPEND
   191215:014845 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=10:Event sent
[!]191215:014845 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[304.352083]:  on OnpowerdEventCallback readyToSuspend :
[!]191215:014845 fastmetrics[5247]: I fastmetrics:endReadingSession:[304.366748]: Ending reading session SDK :
[!]191215:014845 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[304.366870]: Successfully uploaded metric :readingSessionEndStatus with value :0 :
   191215:014845 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374525502, End - 1576374525502
   191215:014845 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374525503, End - 1576374525503
   191215:014845 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014845 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374525502, End - 1576374525508
   191215:014845 cvm[4369]: I MetadataStore:Information::campaignList size while validating0
   191215:014845 cvm[4369]: I MetadataStore:Information::Eligible card count0
   191215:014845 cvm[4369]: I MerchantManagerImpl:RefreshActiveCampaignList:ForceUpdate=true,IsFirstRefreshAfterSync=false,CardRotationStrategy=NEW_SESSION,IsCampaignListInvalid=true:
   191215:014845 cvm[4369]: I MetadataStore:Information::Eligible card count0
   191215:014845 cvm[4369]: I MetadataStore:Information::Eligible card count0
   191215:014845 cvm[4369]: I FMSessionController:Information::[FastMetrics] End reading session
   191215:014845 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014845 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=10,status=0:
   191215:014845 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 10:
   191215:014845 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374525508, End - 1576374525526
   191215:014850 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=8:Event sent
[!]191215:014850 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[309.380368]:  on OnpowerdEventCallback readyToSuspend :
   191215:014850 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374530561, End - 1576374530561
   191215:014850 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374530561, End - 1576374530562
   191215:014850 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014850 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=8,status=0:
   191215:014850 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 8:
   191215:014850 phd[2096]: I udp_tphv3:recevied wan will suspend event....::
   191215:014850 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374530566, End - 1576374530566
   191215:014850 cvm[4369]: I IndexerThread:Information::not allowed to index: GOING TO SUSPEND
   191215:014850 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014850 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374530566, End - 1576374530567
   191215:014855 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=7:Event sent
[!]191215:014855 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[314.381010]:  on OnpowerdEventCallback readyToSuspend :
   191215:014855 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374535573, End - 1576374535573
   191215:014855 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374535574, End - 1576374535574
   191215:014855 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374535575, End - 1576374535575
   191215:014855 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014855 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374535575, End - 1576374535575
   191215:014855 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014855 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=7,status=0:
   191215:014855 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 7:
   191215:014855 cmd[1964]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   191215:014900 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=6:Event sent
[!]191215:014900 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[319.385894]:  on OnpowerdEventCallback readyToSuspend :
   191215:014900 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374540578, End - 1576374540578
   191215:014900 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014900 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374540579, End - 1576374540579
   191215:014900 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374540580, End - 1576374540580
   191215:014900 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374540580, End - 1576374540580
   191215:014900 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014900 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=6,status=0:
   191215:014900 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 6:
   191215:014905 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=2:Event sent
[!]191215:014905 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[324.405249]:  on OnpowerdEventCallback readyToSuspend :
   191215:014905 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374545583, End - 1576374545583
   191215:014905 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374545584, End - 1576374545584
   191215:014905 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374545587, End - 1576374545587
   191215:014905 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014905 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374545587, End - 1576374545587
   191215:014905 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014905 contentpackd[3207]: I contentpackd:readyToSuspendCallback:level=2,status=0:
   191215:014905 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 2:
   191215:014910 powerd[1989]: I lipc:evts:name=readyToSuspend, origin=com.lab126.powerd, fparam=1:Event sent
[!]191215:014910 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[329.406602]:  on OnpowerdEventCallback readyToSuspend :
   191215:014910 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374550590, End - 1576374550591
   191215:014910 cvm[4369]: W lipc:pnr:prop=demOsMetricsEmissionStatus:Property not registered
   191215:014910 cvm[4369]: I IndexerThread:INDEXER ALLOWED SUSPEND::
   191215:014910 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374550594, End - 1576374550595
   191215:014910 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374550602, End - 1576374550602
   191215:014910 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - readyToSuspend : Time Start - 1576374550602, End - 1576374550602
   191215:014910 contentpackd[3207]: I contentpackd:readyToSuspendCallback:restartPendingState=0:
   191215:014910 phd[2096]: I lipc_cb:SUSPEND_MESSAGE:Level = 1:
[!]191215:014910 powerd[1989]: E powerd_metrics:dem_check_and_set_rtc_wakeup:Failed to get DEM_OS_METRICS_EMISSION_STATUS property :
[!]191215:014910 powerd[1989]: I def:powerd_metrics:prvGetTimeInSecsForNextDEMWakeup:time difference between current time and next day is = 165360 s
   191215:014910 powerd[1989]: I def:rtcset:client=dem_heartbeat, delay=165360:Setting RTC wakeup to 165360s after suspend
[!]191215:014910 [  390.621937] max77696-rtc max77696-rtc.0: read time:
[!]191215:014910 [  390.621953] max77696-rtc max77696-rtc.0: YEAR 13 MONTH 0C DOM 0F DOW 01 HOUR 01 MIN 31 SEC 0B
[!]191215:014910 [  390.621965] max77696-rtc max77696-rtc.0: --> 2019-12-15 Sun 01:49:11
   191215:014910 contentpackd[3207]: I contentpackd:Number of font bins avail:Bin_Count=0:
tail: /var/log/messages has become inaccessible: No such file or directory
tail: /var/log/messages has appeared; following end of new file
[!]191215:014917 syslog-ng[865]: new configuration initialized
[!]191215:014918 system: I tinyrot:def:Removing /var/local/log/messages_00000033_*.gz to save storage space
   191215:014918 system: I tinyrot:def::Rotating file /var/log/netlog with max size 256
[!]191215:014918 syslog-ng[865]: SIGHUP received, restarting syslog-ng
   191215:014918 system: I tinyrot:def::Rotating file /var/log/odotlite with max size 2048
   191215:014918 system: I tinyrot:def::No file to rotate: /var/log/odotlite
   191215:014918 system: I tinyrot:def::Rotating file /var/log/wpa_supplicant with max size 128
   191215:014918 system: I tinyrot:def::No file to rotate: /var/log/wpa_supplicant
   191215:014918 system: I tinyrot:def::Rotating file /var/log/metrics_generic with max size 64
   191215:014918 system: I tinyrot:def::Rotating file /var/log/metrics_high_priority with max size 64
[!]191215:014919 syslog-ng[865]: new configuration initialized
   191215:014919 system: I tinyrot:def::No file to rotate: /var/log/metrics_high_priority
   191215:014919 system: I tinyrot:def::Rotating file /var/log/non_anonymous_clickstream_metrics with max size 64
   191215:014919 system: I tinyrot:def::No file to rotate: /var/log/non_anonymous_clickstream_metrics
   191215:014919 system: I tinyrot:def::Rotating file /var/log/anonymous_clickstream_metrics with max size 64
[!]191215:014919 syslog-ng[865]: SIGHUP received, restarting syslog-ng
   191215:014919 system: I tinyrot:def::Rotating file /var/log/bsa_server_log with max size 256
   191215:014919 system: I tinyrot:def::No file to rotate: /var/log/bsa_server_log
   191215:014919 system: I tinyrot:def::Rotating file /mnt/us/bsa_log with max size 8192
   191215:014919 system: I tinyrot:def::No file to rotate: /mnt/us/bsa_log
   191215:014919 system: I tinyrot:def::Rotating file /mnt/us/bt_snoop_log with max size 51200
   191215:014919 system: C tinyrot:def::destination file for rotate: /mnt/us/system/btlogs/bt_snoop_log
   191215:014919 system: I tinyrot:def::No file to rotate: /mnt/us/bt_snoop_log
[!]191215:014919 powerd[1989]: I def:sm:ABOUT TO SUSPEND:Reason : Hibernate not supported
   191215:014919 powerd[1989]: I def:statech:prev=READY TO SUSPEND, next=SUSPENDED:State change: READY TO SUSPEND -> SUSPENDED
   191215:014919 powerd[1989]: I def:r2stime:secs=34, next=SUSPENDED:Time spent in ready to suspend
[!]191215:014919 fastmetrics[5247]: I fastmetrics:endAppSession:[338.525184]: [FastMetrics]:Ending App session :
[!]191215:014919 fastmetrics[5247]: I fastmetrics:recordDeviceMetric:[338.564437]: Successfully uploaded metric :AppSessionEndStatus with value :0 :
[!]191215:014919 fastmetrics[5247]: I fastmetrics:OnpowerdEventCallback:[338.564597]:  on OnpowerdEventCallback suspending :
   191215:014919 certmand[4727]: I certmand:handleTransferStatus:status = 6, response code = -1, id = 1:
   191215:014919 cvm[4369]: I LipcImpl:Information::Added Event : Source - com.lab126.powerd , Event Name - suspending : Time Start - 1576374559677, End - 1576374559677
   191215:014919 tmd[2008]: I defer_active:redeferring:id=1,was=DEFERRED,wasby=WIRELESS_DISABLED,now=DEFERRED,defby=SUSPEND,qpos=0 of 5,pri=1100,toppri=1100:
   191215:014919 tmd[2008]: I defer_active:redeferring:id=3,was=DEFERRED,wasby=WIRELESS_DISABLED,now=DEFERRED,defby=SUSPEND,qpos=1 of 5,pri=1600,toppri=1100:
   191215:014919 tmd[2008]: I defer_active:redeferring:id=4,was=DEFERRED,wasby=WIRELESS_DISABLED,now=DEFERRED,defby=SUSPEND,qpos=2 of 5,pri=1600,toppri=1100:
   191215:014919 tmd[2008]: I defer_active:redeferring:id=5,was=DEFERRED,wasby=WIRELESS_DISABLED,now=DEFERRED,defby=SUSPEND,qpos=3 of 5,pri=1600,toppri=1100:
   191215:014919 tmd[2008]: I defer_active:redeferring:id=2,was=DEFERRED,wasby=WIRELESS_DISABLED,now=DEFERRED,defby=SUSPEND,qpos=4 of 5,pri=1700,toppri=1100:
   191215:014919 tmd[2008]: W get_resp_body:fopen_err:id=2,status=DEFERRED,resp=-1,errno=No such file or directory (2):
   191215:014919 tmd[2008]: I sendstatus:server_said:id=2,code=-1,status=DEFERRED,body="(nofile)":
   191215:014919 cmd[1964]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   191215:014919 powerd[1989]: I lipc:evts:name=suspending, origin=com.lab126.powerd, fparam=mem:Event sent
   191215:014919 cvm[4369]: W ReadNowDownloadListener:Warning::client data is null hence not processing
   191215:014919 cvm[4369]: I LipcImpl:Information::Fired Event : Source - com.lab126.powerd , Event Name - suspending : Time Start - 1576374559678, End - 1576374559727
   191215:014919 cvm[4369]: W ReadNowDownloadListener:Warning::client data is null hence not processing
   191215:014919 cvm[4369]: W ReadNowDownloadListener:Warning::client data is null hence not processing
[!]191215:014920 [  400.743528] max77696-rtc max77696-rtc.0: read time:
[!]191215:014920 [  400.743747] max77696-rtc max77696-rtc.0: YEAR 13 MONTH 0C DOM 0F DOW 01 HOUR 01 MIN 31 SEC 15
[!]191215:014920 [  400.743808] max77696-rtc max77696-rtc.0: --> 2019-12-15 Sun 01:49:21
[!]191215:014920 powerd[1989]: I def:handle_suspend:setting rtc wakeup time:secs = 165340, rtc epoch time = 1576539901

Can somebody help me? I've been banging my head against the wall...

dzervas · 12-15-2019, 08:09 AM

Update: I downgraded to 5.9.6.1 factory, problem remains. Should I try resetting again? I removed all of the books already. Should I reset through recovery? U-Boot? are these methods different than "reset" button or FACTORY_RESET file?

knc1 · 12-15-2019, 10:41 AM

Try registering the device with your Amazon account, then see if there is a change.

dzervas · 12-15-2019, 10:57 AM

Quote:

Originally Posted by knc1

Try registering the device with your Amazon account, then see if there is a change.

Unfortunately I can’t do that...
My journey begun when Amazon decided that my device is “lost or stolen”. The device is of course bought by me in a store in the UAE and it was in my account for about a year. They told me that my serial number is a device that was a gift and then returned (lost or stolen is the generic “your device is a brick” term), which is not true either.

I know that you have zero tolerance with actually stolen devices, but this is clearly a mess up from the amazon side (which I can’t prove to amazon as I don’t have the recipe from a random buy that I did a year ago from a country faaaar away).

Maybe I can trick the kindle to think it’s registered? (I think powerd binary messes up)

knc1 · 12-15-2019, 03:02 PM

Since you have serial port access, download an earlier firmware version from the Amazon server.
You might have more luck with older firmware that did not crater when the Amazon system finds it blacklisted. That feature is a fairly recent "improvement" to block Mobileread owners from modifying Jeff's device.

dzervas · 12-15-2019, 03:49 PM

I downgraded to factory and I still have the problem... 😢
I did get last “ps aux” (did a while true) and the problem is a zombie process (sh <defunct>).
I really can’t see what the problem could be... A flag in nvram (not affected by updates)

knc1 · 12-15-2019, 03:54 PM

Quote:

Originally Posted by dzervas

I downgraded to factory and I still have the problem... 😢
I did get last “ps aux” (did a while true) and the problem is a zombie process (sh <defunct>).
I really can’t see what the problem could be... A flag in nvram (not affected by updates)

That is all next to impossible (on the Kindle's SoC side of the fence).
What is your PC and PC-OS?
Mac or Windows or a virtual machine of something on something?

dzervas · 12-15-2019, 04:22 PM

I’m on an XPS 13 with Arch Linux. I have a Mac available too.
I know, maybe the fuses? too far fetched...

I dunno what I’m missing...

Maybe COMPLETELY reset it like it’s straight out of the factory? (dunno how can I do that)

knc1 · 12-15-2019, 04:48 PM

Quote:

Originally Posted by dzervas

I’m on an XPS 13 with Arch Linux. I have a Mac available too.
I know, maybe the fuses? too far fetched...

I dunno what I’m missing...

Maybe COMPLETELY reset it like it’s straight out of the factory? (dunno how can I do that)

You can't do that.
This isn't a system like Android that has a "virgin" copy of the original firmware on the device.

dzervas · 12-15-2019, 05:20 PM

Quote:

Originally Posted by knc1

You can't do that.
This isn't a system like Android that has a "virgin" copy of the original firmware on the device.

Oooh. Ok, didn’t know that. ugh, I guess I’ll have to find the process that spawns the process and then strace and reverse it 😢

knc1 · 12-15-2019, 06:29 PM

Quote:

Originally Posted by dzervas

Oooh. Ok, didn’t know that. ugh, I guess I’ll have to find the process that spawns the process and then strace and reverse it 😢

Hope you love long winter nights and lots of embedded, obfuscated, Java. If you get finished before the end of this century, let us know.

dzervas · 12-15-2019, 06:33 PM

Wow, for reals? I’m used to embedded systems running completely naive code (with symbols, debugging, not obfuscated, etc). Jeez why do they do that...

dzervas · 12-19-2019, 03:37 AM

For anyone having the same problem: I solved it (not really).
I was pretty discouraged by the previous comments and while being in factory fw I cleared all the storage from books and Calibre metadata (lots of em) and left the kindle for dead and started searching non-Amazon ebook readers (pretty meh if you ask me). 2 days later I just bump the button and *boom* backlight instantly turns on.

Calibre metadata? A specific book? Needed rest? Just wanted me to gut it for no reason? The JB? I (hope) will never know.

Good luck and thank you knc1! Keep it up!

knc1 · 12-19-2019, 08:14 AM

Quote:

Originally Posted by dzervas

For anyone having the same problem: I solved it (not really).
I was pretty discouraged by the previous comments and while being in factory fw I cleared all the storage from books and Calibre metadata (lots of em) and left the kindle for dead and started searching non-Amazon ebook readers (pretty meh if you ask me). 2 days later I just bump the button and *boom* backlight instantly turns on.

Calibre metadata? A specific book? Needed rest? Just wanted me to gut it for no reason? The JB? I (hope) will never know.

Good luck and thank you knc1! Keep it up!

Entirely normal.
Normal if it is doing a file system check with a large number of errors.

dzervas · 12-19-2019, 08:22 AM

but I had the same behavior even AFTER a reset. but who knows what nasty stuff remain in the FS even after the reset... Anyway, it’s from these devices that I don’t wanna fiddle till I’m dead, I just want it to work. I won’t even update it to a consumer fw until something goes wrong (unless you suggest otherwise, you won the place of “single point of truth” in my heart ❤️ )

Wish me luck and I hope nobody has such problems.

Also I wanna note that I changed the ID of the device. last 8 digits to 1111 2222.
I know that COULD be someone else’s ID, but come on... Also I don’t even care, amazon fuck you. Although I wont say how, could clearly help thieves. Maybe that helped (invalidated precious cache). I still can’t register the device but I don’t care.

Wish me luck.

Similar Threads
Thread	Thread Starter	Forum	Replies	Last Post
Get to Sleep! #2 (The Sleep Prompt Series: The Island)	Reading4Life	Self-Promotions by Authors and Publishers	1	11-23-2012 05:27 AM
Stylus not working after sleep; unwanted wakeup from sleep?	HerrB	Onyx Boox	6	09-28-2012 08:43 AM
Does Calibre server work when computer is in "Sleep"/can it prevent Sleep	Backdraft	Calibre	1	01-14-2011 07:47 PM
Troubleshooting Kindle 2 frequently freezes when waking from sleep	addictedtoblue	Amazon Kindle	1	07-18-2010 04:26 PM

12-15-2019, 08:09 AM	#2
dzervas Junior Member Posts: 9 Karma: 10 Join Date: Dec 2019 Device: Kindle Paperwhite 3 Wi-Fi	Update: I downgraded to 5.9.6.1 factory, problem remains. Should I try resetting again? I removed all of the books already. Should I reset through recovery? U-Boot? are these methods different than "reset" button or FACTORY_RESET file?

12-15-2019, 10:41 AM	#3
knc1 Going Viral Posts: 17,212 Karma: 18210809 Join Date: Feb 2012 Location: Central Texas Device: No K1, PW2, KV, KOA	Try registering the device with your Amazon account, then see if there is a change.

12-15-2019, 03:02 PM	#5
knc1 Going Viral Posts: 17,212 Karma: 18210809 Join Date: Feb 2012 Location: Central Texas Device: No K1, PW2, KV, KOA	Since you have serial port access, download an earlier firmware version from the Amazon server. You might have more luck with older firmware that did not crater when the Amazon system finds it blacklisted. That feature is a fairly recent "improvement" to block Mobileread owners from modifying Jeff's device.

12-15-2019, 03:49 PM	#6
dzervas Junior Member Posts: 9 Karma: 10 Join Date: Dec 2019 Device: Kindle Paperwhite 3 Wi-Fi	I downgraded to factory and I still have the problem... 😢 I did get last “ps aux” (did a while true) and the problem is a zombie process (sh <defunct>). I really can’t see what the problem could be... A flag in nvram (not affected by updates)

12-15-2019, 04:22 PM	#8
dzervas Junior Member Posts: 9 Karma: 10 Join Date: Dec 2019 Device: Kindle Paperwhite 3 Wi-Fi	I’m on an XPS 13 with Arch Linux. I have a Mac available too. I know, maybe the fuses? too far fetched... I dunno what I’m missing... Maybe COMPLETELY reset it like it’s straight out of the factory? (dunno how can I do that)

12-15-2019, 06:33 PM	#12
dzervas Junior Member Posts: 9 Karma: 10 Join Date: Dec 2019 Device: Kindle Paperwhite 3 Wi-Fi	Wow, for reals? I’m used to embedded systems running completely naive code (with symbols, debugging, not obfuscated, etc). Jeez why do they do that...

12-19-2019, 03:37 AM	#13
dzervas Junior Member Posts: 9 Karma: 10 Join Date: Dec 2019 Device: Kindle Paperwhite 3 Wi-Fi	For anyone having the same problem: I solved it (not really). I was pretty discouraged by the previous comments and while being in factory fw I cleared all the storage from books and Calibre metadata (lots of em) and left the kindle for dead and started searching non-Amazon ebook readers (pretty meh if you ask me). 2 days later I just bump the button and boom backlight instantly turns on. Calibre metadata? A specific book? Needed rest? Just wanted me to gut it for no reason? The JB? I (hope) will never know. Good luck and thank you knc1! Keep it up!

12-19-2019, 08:22 AM	#15
dzervas Junior Member Posts: 9 Karma: 10 Join Date: Dec 2019 Device: Kindle Paperwhite 3 Wi-Fi	but I had the same behavior even AFTER a reset. but who knows what nasty stuff remain in the FS even after the reset... Anyway, it’s from these devices that I don’t wanna fiddle till I’m dead, I just want it to work. I won’t even update it to a consumer fw until something goes wrong (unless you suggest otherwise, you won the place of “single point of truth” in my heart ❤️ ) Wish me luck and I hope nobody has such problems. Also I wanna note that I changed the ID of the device. last 8 digits to 1111 2222. I know that COULD be someone else’s ID, but come on... Also I don’t even care, amazon fuck you. Although I wont say how, could clearly help thieves. Maybe that helped (invalidated precious cache). I still can’t register the device but I don’t care. Wish me luck.

Advert

Advert