"USB Connected" screen image replacement

mergen3107 · 12-18-2018, 10:34 PM

Dear Mobileread Community,

I need your help in replacing screen image when Kindle Paperwhite 3 (5.9.7) is connected via USB.
I had no problem doing that on Kindle 4 Non-Touch.
However, it seems like besides the png file itself, their is also an eips (?) command to draw something else.
What I did:
1) Prepared an image. Just took my favorite one and after some tweaks in GIMP, I finally converted it to a proper eips-compatible format:

Code:

convert input.png -type GrayScale -depth 8 -colors 256 -resize 1072x1448! output.png

2) Replaced bg_usbconnect.png in /usr/share/blanket/usb and gave it the same permission chmod as it was of the original one. I attached my screen image to this post.
3) Now, when I connect to USB, my new screen image shows up very well, but on top of that there are two more things. One is a text 'If you want to read while still charging... blahblah', another is a small white square of a charging icon. I can see that it is ov_default_charging.png (I attached it too) in the same folder.
4) I returned to (1) and added a white circle approximately at location around that square.

Why approximately? Because I don't have exact coordinates or a combined pictures of them all.
Well, here come two problems:
1) I have no idea how to take screenshot of the screen while Kindle is connected via USB. I tried to:
— press the diagonally opposite corners of the screen (as for usual screenshot). Screen blinks, as if it took a screenshot, but I can't find it. I guess, because /mnt/us/ is now unmounted and presented to PC, there is no place to put screenshot to.
— access ssh during usb connection, but Kindle is inaccessible when connected, so I can't reach command line to invoke 'screenshot' command.
— connect to ssh first, then do 'sleep 20; screenshot' command, then connect to usb and wait for these 20 sec to pass. Screen again flashes as if it took the screenshot, but I can't find it anywhere.
2) I have no success in finding a script for USB connection event neither to see how these two extra things are drawn. I looked up in /etc/upstart/ using Total Commander's 'Search in files' feature trying to find anything related to 'usb'. There should be a daemon (or sort of 'listener') that catches the /mnt/us/ upon usb connection and manages its mount to PC and back to Kindle.

If I have at least coordinates of that little square, I could've replaced it by the same pixels of my new image at these coordinates, so that the square would seem 'transparent'.

Do you guys have any suggestions?
Thanks!

knc1 · 12-18-2018, 10:50 PM

Didn't dos1 create a set of files and script for capturing events?

Found it:
https://www.mobileread.com/forums/sh...d.php?t=198484

It should be possible to modify his scripts to capture the event(s) that you want.

mergen3107 · 12-19-2018, 05:18 PM

Thanks knc1!
I've looked through eventHandler, but can't see how can it help me. It is, so far, limited to only three events: boot, screen goes on, screen goes off.

Meanwhile I did:
1) SSH over Wi-Fi, command line: showlog -f
2) Connected Kindle to USB, waited for the log to update
3) Disconnectd from USB.

This is the full log:

Spoiler:

Code:

/var/log$ showlog -f
   181219:165050 phd[2212]: I udp_tphv3:sending_still_here:srv=xxx.xxx.189.44, port=33434,reason=On Wifi mode:
   181219:165058 cvm[4742]: I HeapMonitor:CVMGC:gcStatus=start:
   181219:165058 cvm[4742]: I HeapMonitor:CVMGC:gcStatus=end:
   181219:165117 phd[2212]: I udp_tphv3:sending_still_here:srv=xxx.xxx.189.44, port=33434,reason=On Wifi mode:
   181219:165122 scan[5602]: I NATIVE:dlclose:nclosed=1,so=/usr/lib/ccat/libfileE.so:
   181219:165122 scan[5602]: I NATIVE:dlclose:nclosed=2,so=/usr/lib/ccat/libfileE.so:
[!]181219:165127 dropbear[32001]: Child connection from 192.168.0.12:52336
[!]181219:165127 dropbear[32001]: Pubkey auth succeeded for 'root' with key sha1!! 0b:b4:b9:89:9d:58:41:41:7f:af:23:74:a3:62:21:34:17:06:0a:fe from 192.168.0.12:52336
[!]181219:165131 ADM[31960]: I Main: Received termination signal.
   181219:165144 phd[2212]: I udp_tphv3:sending_still_here:srv=xxx.xxx.189.44, port=33434,reason=On Wifi mode:
   181219:165205 powerd[2090]: I def:batmon:usb_charger_event received value = 1:
   181219:165205 [16442.615733] KERNEL: I pmic:charger chgina::charger connected
   181219:165205 powerd[2090]: I def:battstatech:prev=STANDALONE, next=STANDALONE_USB:State change: STANDALONE -> STANDALONE_USB
   181219:165205 powerd[2090]: I def:batmon:Charging state for PRIMARY battery = CHARGING:
   181219:165205 powerd[2090]: I def:powerd:batt-state-info:value={"battInfo":[{"type":"PRIMARY","cap":80,"charging":true}],"state":"STANDALONE_USB","aggr_batt":80,"usb":true}
   181219:165205 cvm[4742]: I BatteryServiceImpl:Information::Battery Event = battStateInfoChanged, Started at = 1545256325203, Ended at = 1545256325208
   181219:165205 powerd[2090]: I lipc:evts:name=battStateInfoChanged, origin=com.lab126.powerd, fparam={"battInfo":[{"type":"PRIMARY",:Event sent
   181219:165205 powerd[2090]: I lipc:evts:name=charging, origin=com.lab126.powerd:Event sent
[!]181219:165205 powerd[2090]: I def:batmon:USBEvent:name=USBPlugin, battery_percent = 80
   181219:165205 powerd[2090]: I def:metrics::prg_name=powerd,prg_source=USBEvent,name=USBPlugin,value=1
[!]181219:165205 volumd[2202]: I def:USB_EVENT_MONITOR:ipcCallback: Handling charging event:Scheduling Task
   181219:165205 volumd[2202]: I lipc:evts:name=userstoreIsLikelyToUnMount, origin=com.lab126.volumd:Event sent
[!]181219:165205 volumd[2202]: I def:USB_EVENT_MONITOR:Userstore Likely to Unmount:Should spawn thread ? Yes 
[!]181219:165205 [16442.660056] max77696_uic_isr: cancel: 0
[!]181219:165205 [16442.676730] otg udc vbus rising wakeup
[!]181219:165205 kfxreader: I :::Handling usb enter...
   181219:165205 scan[5602]: I userstore_likely_to_unmount:drivemode_on::
   181219:165205 scan[5602]: I set_drive_mode:sem_post:scan_status=0:
   181219:165205 scan[5602]: W watchdir:unknown:inotifyStatus=0:End of scanner_watch.
   181219:165205 cvm[4742]: I BatteryServiceImpl:Information::Battery Event = charging, Started at = 1545256325263, Ended at = 1545256325263
   181219:165205 lipc-send-event[32042]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
   181219:165205 lipc-send-event[32042]: I lipc:evts:name=usbPlugIn, origin=com.lab126.hal:Event sent
   181219:165205 powerd[2090]: I def:ipc_event_cb:Handling usb hal event = usbPlugIn:
   181219:165205 cvm[4742]: W url_builder:GetURLWarning:reason=missingGlobalParameter,param=currentSponsoredHotspot:
[!]181219:165205 tmd[2108]: I request_upload:received:id=63,pri=1600,pc=,net=wan,at=2018/12/19-Wed-16.52.05.:
   181219:165205 cvm[4742]: I TransferServiceImpl:Request:requestType=upload,id=63,key=<private>,status=success:Succesfully enqueued upload request
[!]181219:165205 [16442.856532] max77696_uic_adc_work adcval 31 in_otg 0
[!]181219:165205 [16442.911435] fsg_resume:3894
[!]181219:165205 [16442.911462] fsg_disconnect:764
[!]181219:165205 [16442.911519] 
   181219:165205 powerd[2090]: I def:chrgrevt::Received charger event
   181219:165205 powerd[2090]: W def:chrgrnobatt::Charger event without battery information
   181219:165205 lipc-send-event[32049]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
   181219:165205 lipc-send-event[32049]: I lipc:evts:name=usbConfigured, origin=com.lab126.hal:Event sent
   181219:165205 powerd[2090]: I def:ipc_event_cb:Handling usb hal event = usbConfigured:
[!]181219:165205 volumd[2202]: I def:USB_EVENT_MONITOR:ipcCallback: Handling usbConfigured event:Scheduling Task
   181219:165205 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=2:Event sent
[!]181219:165205 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_OFF to DRIVE_MODE_STATE_STARTING
[!]181219:165205 volumd[2202]: I def:USB_EVENT_MONITOR:plug_in Signal : Userstore Not Unmounting:
   181219:165205 stored[23899]: I com.lab126.store:JunoWidgetUserAgent::onUsbConnect:entered:
   181219:165205 blanket[2987]: I def:USB_EVENT_MONITOR:current vold_state = 2:
[!]181219:165205 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
   181219:165205 powerd[2090]: I lipc:evts:name=usbConfigured, origin=com.lab126.powerd:Event sent
[!]181219:165205 powerd[2090]: I def:batmon:USBEvent:name=USBMounted, battery_percent = 80
   181219:165205 powerd[2090]: I def:metrics::prg_name=powerd,prg_source=USBEvent,name=USBMounted,value=1
[!]181219:165205 [16442.911525] send_online_uevent:669 fsg_ 0x1 recovery_mode:0
[!]181219:165205 [16443.097703] g_file_storage gadget: high speed config #1
[!]181219:165205 [16443.097715] 
[!]181219:165205 [16443.097717] send_online_uevent:669 fsg_ 0x9 recovery_mode:0
[!]181219:165205 [16443.105041] fsg_disconnect:764
[!]181219:165205 [16443.105086] 
[!]181219:165205 [16443.105088] send_offline_uevent:641 fsg_ 0x9 unsafe 1 recovery_mode:0
   181219:165205 powerd[2090]: I def:chrgrevt::Received charger event
   181219:165205 powerd[2090]: W def:chrgrnobatt::Charger event without battery information
   181219:165205 lipc-send-event[32058]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
   181219:165205 lipc-send-event[32058]: I lipc:evts:name=usbUnconfigured, origin=com.lab126.hal, fparam=unsafe:Event sent
[!]181219:165205 [16443.192919] fsg_disconnect:764
[!]181219:165205 volumd[2202]: I def:USB_EVENT_MONITOR:ipcCallback: Handling usbUnconfigured event:Scheduling Task
   181219:165205 powerd[2090]: I def:ipc_event_cb:Handling usb hal event = usbUnconfigured:
[!]181219:165205 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : prerender usb window:charging state = 1
[!]181219:165205 [16443.288803] g_file_storage gadget: high speed config #1
[!]181219:165205 [16443.288814] 
   181219:165205 lipc-send-event[32065]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
   181219:165205 lipc-send-event[32065]: I lipc:evts:name=usbConfigured, origin=com.lab126.hal:Event sent
   181219:165206 powerd[2090]: W lipc:axstime:prop=load, source=com.lab126.blanket, ms=334:lipc property access time in milliseconds
   181219:165206 powerd[2090]: I def:chrgrevt::Received charger event
   181219:165206 powerd[2090]: W def:chrgrnobatt::Charger event without battery information
[!]181219:165206 powerd[2090]: I def:batmon:USBEvent:type=PRIMARY, name=USBUnmounted, battery_percent = 80, battery_percent_delta = 0, time_delta_value = 1
   181219:165206 powerd[2090]: I def:metrics::prg_name=powerd,prg_source=USBEvent,name=USBUnmounted,value=1
   181219:165206 powerd[2090]: I def:ipc_event_cb:Handling usb hal event = usbConfigured:
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:ipcCallback: Handling usbConfigured event:Scheduling Task
   181219:165206 powerd[2090]: I lipc:evts:name=usbConfigured, origin=com.lab126.powerd:Event sent
[!]181219:165206 powerd[2090]: I def:batmon:USBEvent:name=USBMounted, battery_percent = 80
   181219:165206 powerd[2090]: I def:metrics::prg_name=powerd,prg_source=USBEvent,name=USBMounted,value=1
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:usb start drive mode:unmounting base userstore
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:usb start drive mode:writing to usb mount file
   181219:165206 blanket[2987]: I def:USB_EVENT_MONITOR:current vold_state = 1:
[!]181219:165206 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : map usb window:image bringup
[!]181219:165206 [16443.288817] send_online_uevent:669 fsg_ 0x1 recovery_mode:0
[!]181219:165206 [16444.110444] cfg80211: Calling CRDA to update world regulatory domain
[!]181219:165206 [16444.110619] cfg80211: World regulatory domain updated:
[!]181219:165206 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
[!]181219:165206 [16444.120811] skipping TCP reset for port 22
[!]181219:165206 [16444.120905] skipping TCP reset for port 22
[!]181219:165206 [16444.122472] skipping TCP reset for port 22
[!]181219:165206 [16444.122564] skipping TCP reset for port 22
[!]181219:165206 [16444.123990] skipping TCP reset for port 22
[!]181219:165206 [16444.124078] skipping TCP reset for port 22
[!]181219:165206 [16444.227129] skipping TCP reset for port 22
[!]181219:165206 [16444.227175] skipping TCP reset for port 22
   181219:165206 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=1:Event sent
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_STARTING to DRIVE_MODE_STATE_ON
   181219:165206 volumd[2202]: I lipc:evts:name=userstoreUnAvailable, origin=com.lab126.volumd:Event sent
   181219:165206 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=3:Event sent
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_ON to DRIVE_MODE_STATE_STOPPING
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:usb stop drive mode:writing to usb mount file
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:usb stop drive mode:mounting user store
   181219:165206 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=0:Event sent
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_STOPPING to DRIVE_MODE_STATE_OFF
   181219:165206 volumd[2202]: I lipc:evts:name=userstoreAvailable, origin=com.lab126.volumd:Event sent
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:usb stop drive mode:user store is available
   181219:165206 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=2:Event sent
[!]181219:165206 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_OFF to DRIVE_MODE_STATE_STARTING
   181219:165206 cmd[2072]: I def:interfaceChange::New interface=:~:
[!]181219:165206 cmd[2072]: I def:ipchandler:wifi_connection,duration was =103.000000 sec:~:
   181219:165206 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165206 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165206 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165206 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165206 cmd[2072]: I def:statechange::Old State[3] = CONNECTED, new State = NA :~:
   181219:165206 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
[!]181219:165206 [16444.289961] skipping TCP reset for port 22
[!]181219:165206 [16444.290007] skipping TCP reset for port 22
   181219:165207 stored[23899]: I com.lab126.store:static gboolean NetworkManager::s_connectionEventListenerHandler(gpointer):CON_EVENT_INTERFACE_CHANGE:
   181219:165207 stored[23899]: I com.lab126.store:setConnected:new connected state = 0:
   181219:165207 stored[23899]: E com.lab126.store:virtual void JSObjectNet::onNetworkInterfaceChanged():callback function not assigned:
   181219:165207 stored[23899]: I com.lab126.store:JunoWidgetUserAgent::onUsbDisconnect:entered:
   181219:165207 stored[23899]: I com.lab126.store:JunoWidgetUserAgent::onUsbConnect:entered:
[!]181219:165207 kfxreader: I :::Handling usb leave...
   181219:165207 scan[5602]: I set_drive_mode:sem_post:scan_status=0:
   181219:165207 scan[5602]: I lipc:evts:name=fullScanStart, origin=com.lab126.scanner:Event sent
   181219:165207 scan[5602]: I fullscan:NATIVE::----1----
[!]181219:165207 dmld[5555]: I dmld:cmd_internet_connected_event_callback:Unused Event 0 received:
   181219:165207 cvm[4742]: I HTTPUtil:clearDNSCache:cache_size=1:clearing DNS cacheMap
   181219:165207 cvm[4742]: I HTTPUtil:clearConnectionCache::clearing keep alive cache
   181219:165207 cvm[4742]: I url_builder:HandlerExists::Adding/Updating property to handler
   181219:165207 cvm[4742]: I url_builder:HandlerExists::Adding/Updating property to handler
[!]181219:165207 contentpackd[3369]: I def:volumdEventCallback:userStoreAvailable:
[!]181219:165207 contentpackd[3369]: I def:pushCpdRequest:Bp:(null),Lang:(null),requestType:1:Inserting new contentpackd request in queue
   181219:165207 contentpackd[3369]: I def:signalUserStoreAvailability::
   181219:165207 contentpackd[3369]: I def:handle_cp_requests:BundlePath=(null),Language=(null):Obtained a cpd request to process
   181219:165207 contentpackd[3369]: I def:UserStoreAvailableRequestProcessing::
[!]181219:165207 contentpackd[3369]: I def:initializeChecksum:checksum:a39b151814d876c61052ee47e7ad6e50:
[!]181219:165207 contentpackd[3369]: I def:fullscan:Checksum:a39b151814d876c61052ee47e7ad6e50:Checksum verification successful
   181219:165207 contentpackd[3369]: I def:handle_cp_requests:BundlePath=(null),Language=(null):Cpd installation requested restart
   181219:165207 contentpackd[3369]: I def:handle_cp_requests::Waiting for cp requests
   181219:165207 winmgr[2986]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=invisible:Event sent
   181219:165207 blanket[2987]: I x11Handler:X11_EVENT:win=40004a,xev_type=12,module=usb:
   181219:165207 phd[2212]: I udp_tphv3:restarting_on_wifi_change::
   181219:165207 phd[2212]: I udp_tphv3:network_change:wifi_mode=0,network=0:
   181219:165207 phd[2212]: W udp_tphv3:network_down_message_received::
   181219:165207 phd[2212]: I udp_tphv3:Initalizing_udp_tphv3::
   181219:165207 phd[2212]: I udp_tphv3:stop_udp_tphv3_on_net_down::
   181219:165207 phd[2212]: I udp_tphv3:wait_udp_tphv3_rcvr:ret = 20:
   181219:165207 tmd[2108]: I lipc_cb_cmd:Connection Util Event:event = 0:
   181219:165207 tmd[2108]: I defer_active:redeferring:id=63,was=WAITING,wasby=NOTHING,now=DEFERRED,defby=DRIVE_MODE,qpos=0 of 1,pri=1600,toppri=1600:
   181219:165207 tmd[2108]: W get_resp_body:fopen_err:id=63,status=DEFERRED,resp=-1,errno=No such file or directory (2):
   181219:165207 tmd[2108]: I sendstatus:server_said:id=63,code=-1,status=DEFERRED,body="(nofile)":
   181219:165207 tmd[2108]: I lipc_cb_cmd:Connect event received:event = 1:
   181219:165207 wifid[2155]: W sysev:power::redundant Wakeup - discarded
   181219:165207 wifid[2155]: I spectator:conn-start:t=16444.314902, essid=any:
[!]181219:165207 wifid[2155]: I wmgr:wconn:scanning...::~:
   181219:165207 wifid[2155]: I wmgr:scan:hidden-nets=0 :starting...::~:
   181219:165207 wifid[2155]: I spectator:scan-start:t=16444.315746:
   181219:165207 wifid[2155]: I wmgr:wconn:networks-in-range=1/1::~:
   181219:165207 wifid[2155]: I wmgr:wconn:ssid=cc25338af77d24266a79ef588a98305a, prio=5 :connecting...::~:
   181219:165207 wifid[2155]: I spectator:scan-complete:t=16444.556680:
[!]181219:165207 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
[!]181219:165207 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
[!]181219:165207 deviced[2110]: I def:module:touch:IOCTL succeeded - Lock state is set to : 0
[!]181219:165207 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
   181219:165207 cvm[4742]: I KLL_GlossDictionaryManager:LoadedDictionary:id=kll.en.en,file=/mnt/us/system/kll/kll.en.en.klld:
   181219:165207 cvm[4742]: I KLL_GlossDictionaryManager:LoadedDictionary:id=kll.en.en,file=/mnt/us/system/kll/kll.en.en.klld:
   181219:165207 cmd[2072]: I def:statechange::Old State[2] = NA, new State = READY :~:
   181219:165207 lipc-daemon[2145]: W def:cmd::Command [/usr/bin/lipcd-scripts/lipc-events/interfaceChange.sh interfaceChange com.lab126.cmd '' '     :' 'internet'] returned error (1)
[!]181219:165207 [16444.893481] cfg80211: Calling CRDA for country: US
[!]181219:165207 [16444.893588] cfg80211: Regulatory domain changed to country: US
   181219:165207 wifid[2155]: I spectator:conn-assoc-done:t=16444.846585:
   181219:165207 fontscanner: I lipc:evts:name=ScanStarted, origin=com.lab126.userFontsScan:Event sent
   181219:165207 fontscanner: I lipc:evts:name=NoChange, origin=com.lab126.userFontsScan:Event sent
   181219:165207 tmd[2108]: I def:malloc_trim::start
   181219:165207 wifid[2155]: I spectator:conn-ip-ok:t=16445.025377:
   181219:165207 tmd[2108]: I def:malloc_trim:ret=1:end
   181219:165207 tmd[2108]: I tq_mh:memory_reclaimed:before=6640, after=6552, reclaimed=88:
   181219:165207 tmd[2108]: I recompute_retry_time_locked:Clear next retry time::
   181219:165207 tmd[2108]: I defer_active:redeferring:id=63,was=DEFERRED,wasby=DRIVE_MODE,now=DEFERRED,defby=NETWORK_DOWN,qpos=0 of 1,pri=1600,toppri=1600:
   181219:165207 tmd[2108]: W get_resp_body:fopen_err:id=63,status=DEFERRED,resp=-1,errno=No such file or directory (2):
   181219:165207 tmd[2108]: I sendstatus:server_said:id=63,code=-1,status=DEFERRED,body="(nofile)":
   181219:165207 tmd[2108]: I recompute_retry_time:new_time:next_retry_time = 2018/12/19-Wed-16.52.17.:next_retry_info = @165217.10 for any_transport,intvl=0m10s
   181219:165207 tmd[2108]: I defer_active:redeferring:id=63,was=DEFERRED,wasby=NETWORK_DOWN,now=DEFERRED,defby=DRIVE_MODE,qpos=0 of 1,pri=1600,toppri=1600:
   181219:165207 tmd[2108]: W get_resp_body:fopen_err:id=63,status=DEFERRED,resp=-1,errno=No such file or directory (2):
   181219:165207 tmd[2108]: I sendstatus:server_said:id=63,code=-1,status=DEFERRED,body="(nofile)":
[!]181219:165207 volumd[2202]: I def:USB_EVENT_MONITOR:usb start drive mode:unmounting base userstore
[!]181219:165207 volumd[2202]: I def:USB_EVENT_MONITOR:usb start drive mode:writing to usb mount file
[!]181219:165207 [16445.386357] cfg80211: Calling CRDA to update world regulatory domain
[!]181219:165207 [16445.386448] cfg80211: World regulatory domain updated:
   181219:165207 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=1:Event sent
[!]181219:165207 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_STARTING to DRIVE_MODE_STATE_ON
   181219:165207 volumd[2202]: I lipc:evts:name=userstoreUnAvailable, origin=com.lab126.volumd:Event sent
   181219:165207 wifid[2155]: I spectator:dns-nw-ok:t=16445.273977:
[!]181219:165207 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
[!]181219:165207 [16445.396088] skipping TCP reset for port 22
[!]181219:165207 [16445.396135] skipping TCP reset for port 22
   181219:165207 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165207 cmd[2072]: I def:statechange::Old State[1] = READY, new State = NA :~:
   181219:165208 tmd[2108]: I lipc_cb_cmd:Connect event received:event = 1:
   181219:165208 tmd[2108]: I recompute_retry_time_locked:Clear next retry time::
   181219:165208 blanket[2987]: I def:USB_EVENT_MONITOR:current vold_state = 0:
[!]181219:165208 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : unmap usb window:image teardown & destroy
   181219:165208 winmgr[2986]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=visible:Event sent
   181219:165208 blanket[2987]: I def:USB_EVENT_MONITOR:current vold_state = 2:
   181219:165208 cvm[4742]: I StatusBarController:Information::Initiating Clock Timer
   181219:165208 lipc-get-prop[32206]: W def:lipc:method=LipcOpenEx service=(null):Method has been deprecated.
   181219:165208 system: I asr_setup:Not in asr mode::reason=flag file not present. shutting down asr_setup::
   181219:165208 system: I asr_bt_userstore:winmgr_running=true. winmgr is ready::
   181219:165208 system: I asr_bt_userstore:lab126_gui_running=true. Triggering asr_bt_reboot::
[!]181219:165208 system: I system:emiting_event:trigger_asr_bt_reboot:
   181219:165209 system: D sytem:event_emitted:trigger_asr_bt_reboot:
   181219:165209 system: I asr_bt_reboot:asr_bt_reboot begin on trigger_asr_bt_reboot::
   181219:165209 scan[5602]: I fullscan:IDLE::----0----
[!]181219:165209 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : prerender usb window:charging state = 1
   181219:165209 blanket[2987]: I def:USB_EVENT_MONITOR:current vold_state = 1:
[!]181219:165209 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : map usb window:image bringup
   181219:165209 winmgr[2986]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=invisible:Event sent
   181219:165209 blanket[2987]: I x11Handler:X11_EVENT:win=40004d,xev_type=12,module=usb:
   181219:165218 cvm[4742]: I BatteryServiceImpl:Information::Battery Event = battLevelChanged, Started at = 1545256338927, Ended at = 1545256338927
   181219:165218 powerd[2090]: I lipc:evts:name=battLevelChanged, origin=com.lab126.powerd, fparam=80:Event sent
[!]181219:165227 [16464.938540] 
[!]181219:165227 [16464.938546] send_offline_uevent:641 fsg_ 0x9 unsafe 0 recovery_mode:0
   181219:165227 powerd[2090]: I def:chrgrevt::Received charger event
   181219:165227 powerd[2090]: W def:chrgrnobatt::Charger event without battery information
   181219:165227 lipc-send-event[32269]: W def:lipc:method=LipcOpenEx service=com.lab126.hal:Method has been deprecated.
   181219:165227 lipc-send-event[32269]: I lipc:evts:name=usbUnconfigured, origin=com.lab126.hal, fparam=safe:Event sent
[!]181219:165227 volumd[2202]: I def:USB_EVENT_MONITOR:ipcCallback: Handling usbUnconfigured event:Scheduling Task
   181219:165227 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=3:Event sent
[!]181219:165227 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_ON to DRIVE_MODE_STATE_STOPPING
[!]181219:165227 volumd[2202]: I def:USB_EVENT_MONITOR:usb stop drive mode:writing to usb mount file
[!]181219:165227 volumd[2202]: I def:USB_EVENT_MONITOR:usb stop drive mode:mounting user store
   181219:165227 powerd[2090]: I def:ipc_event_cb:Handling usb hal event = usbUnconfigured:
[!]181219:165227 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
[!]181219:165227 powerd[2090]: I def:batmon:USBEvent:type=PRIMARY, name=USBUnmounted, battery_percent = 81, battery_percent_delta = 1, time_delta_value = 21
   181219:165227 powerd[2090]: I def:metrics::prg_name=powerd,prg_source=USBEvent,name=USBUnmounted,value=1
   181219:165227 volumd[2202]: I lipc:evts:name=driveModeStateChanged, origin=com.lab126.volumd, fparam=0:Event sent
[!]181219:165227 volumd[2202]: I def:USB_EVENT_MONITOR:drive mode state changed:from DRIVE_MODE_STATE_STOPPING to DRIVE_MODE_STATE_OFF
   181219:165227 stored[23899]: I com.lab126.store:JunoWidgetUserAgent::onUsbDisconnect:entered:
[!]181219:165227 kfxreader: I :::Handling usb leave...
   181219:165227 tmd[2108]: I defer_active:redeferring:id=63,was=DEFERRED,wasby=DRIVE_MODE,now=DEFERRED,defby=NETWORK_DOWN,qpos=0 of 1,pri=1600,toppri=1600:
   181219:165227 tmd[2108]: W get_resp_body:fopen_err:id=63,status=DEFERRED,resp=-1,errno=No such file or directory (2):
   181219:165227 tmd[2108]: I sendstatus:server_said:id=63,code=-1,status=DEFERRED,body="(nofile)":
[!]181219:165227 deviced[2110]: I def:ipc:Event recieved:source=com.lab126.volumd,eventName=driveModeStateChanged
[!]181219:165227 deviced[2110]: I def:module:touch:IOCTL succeeded - Lock state is set to : 0
[!]181219:165227 [16465.086756] skipping TCP reset for port 22
[!]181219:165227 [16465.086803] skipping TCP reset for port 22
   181219:165227 tmd[2108]: I recompute_retry_time:new_time:next_retry_time = 2018/12/19-Wed-16.52.59.:next_retry_info = @165259.96 for any_transport,intvl=0m32s
   181219:165227 tmd[2108]: I conutils:lockAny::Locking shared lock for all connections
   181219:165227 tmd[2108]: I conutils:conEnsureConnectionInternal::setting cmd property
   181219:165227 wifid[2155]: W sysev:power::redundant Wakeup - discarded
   181219:165227 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165227 cmd[2072]: I def:req::Got a connection request:~:
   181219:165227 scan[5602]: I set_drive_mode:sem_post:scan_status=0:
   181219:165227 volumd[2202]: I lipc:evts:name=userstoreAvailable, origin=com.lab126.volumd:Event sent
[!]181219:165227 volumd[2202]: I def:USB_EVENT_MONITOR:usb stop drive mode:user store is available
   181219:165227 scan[5602]: I lipc:evts:name=fullScanStart, origin=com.lab126.scanner:Event sent
   181219:165227 scan[5602]: I fullscan:NATIVE::----1----
   181219:165227 cvm[4742]: I IndexerThread:Information::INDEXER_WAIT_DUE_TO_PAUSE_OR_ENVIRONMENT:Queue=0:Pausers:scanner:3500000ms:
[!]181219:165227 contentpackd[3369]: I def:volumdEventCallback:userStoreAvailable:
[!]181219:165227 contentpackd[3369]: I def:pushCpdRequest:Bp:(null),Lang:(null),requestType:1:Inserting new contentpackd request in queue
   181219:165227 contentpackd[3369]: I def:signalUserStoreAvailability::
   181219:165227 contentpackd[3369]: I def:handle_cp_requests:BundlePath=(null),Language=(null):Obtained a cpd request to process
   181219:165227 contentpackd[3369]: I def:UserStoreAvailableRequestProcessing::
   181219:165227 winmgr[2986]: I lipc:evts:name=titleBarVisiblityChange, origin=com.lab126.winmgr, fparam=visible:Event sent
   181219:165227 blanket[2987]: I def:USB_EVENT_MONITOR:current vold_state = 0:
[!]181219:165227 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : unmap usb window:image teardown & destroy
   181219:165227 wifid[2155]: I spectator:conn-start:t=16465.091330, essid=any:
[!]181219:165227 wifid[2155]: I wmgr:wconn:scanning...::~:
   181219:165227 wifid[2155]: I wmgr:scan:hidden-nets=0 :starting...::~:
   181219:165227 wifid[2155]: I spectator:scan-start:t=16465.092236:
   181219:165227 cvm[4742]: I KLL_GlossDictionaryManager:LoadedDictionary:id=kll.en.en,file=/mnt/us/system/kll/kll.en.en.klld:
   181219:165227 wifid[2155]: I spectator:conn-start:t=16465.138863, essid=any:
   181219:165227 wifid[2155]: I wmgr:wconn:networks-in-range=1/1::~:
   181219:165227 wifid[2155]: I wmgr:wconn:ssid=cc25338af77d24266a79ef588a98305a, prio=5 :connecting...::~:
   181219:165227 wifid[2155]: E wmgr:scan-result:fail-reason=16:
   181219:165227 wifid[2155]: I wmgr:wconn:networks-in-range=1/1::~:
   181219:165227 wifid[2155]: I wmgr:wconn:ssid=cc25338af77d24266a79ef588a98305a, prio=5 :connecting...::~:
   181219:165227 wifid[2155]: I spectator:scan-complete:t=16465.143774:
   181219:165227 cmd[2072]: I def:statechange::Old State[2] = NA, new State = READY :~:
   181219:165227 cvm[4742]: I KLL_GlossDictionaryManager:LoadedDictionary:id=kll.en.en,file=/mnt/us/system/kll/kll.en.en.klld:
[!]181219:165227 contentpackd[3369]: I def:initializeChecksum:checksum:a39b151814d876c61052ee47e7ad6e50:
[!]181219:165227 contentpackd[3369]: I def:fullscan:Checksum:a39b151814d876c61052ee47e7ad6e50:Checksum verification successful
   181219:165227 contentpackd[3369]: I def:handle_cp_requests:BundlePath=(null),Language=(null):Cpd installation requested restart
   181219:165227 contentpackd[3369]: I def:handle_cp_requests::Waiting for cp requests
   181219:165228 wifid[2155]: I spectator:conn-assoc-done:t=16465.426672:
   181219:165228 wifid[2155]: I spectator:conn-ip-ok:t=16465.540331:
   181219:165228 wifid[2155]: I spectator:dns-nw-ok:t=16465.660407:
   181219:165228 wifid[2155]: I spectator:conn-done:t=16465.661572:
   181219:165228 wifid[2155]: I wmgr:wconn:rssi=5::~:
   181219:165228 cvm[4742]: I StatusBarController:Information::Initiating Clock Timer
[!]181219:165228 [16465.913621] skipping TCP reset for port 22
[!]181219:165228 [16465.913677] skipping TCP reset for port 22
   181219:165228 cmd[2072]: I def:tcpreset_details::resetparam=43, skiplist=22,5900:TCP Reset details:~:
   181219:165228 cmd[2072]: I def:interfaceChange::New interface=wifi:~:
[!]181219:165228 cmd[2072]: I def:ipchandler:wifi_disconnection,duration was =22.000000 sec:~:
   181219:165228 cmd[2072]: I def:statechange::Old State[1] = READY, new State = CONNECTED :~:
   181219:165228 stored[23899]: I com.lab126.store:static gboolean NetworkManager::s_connectionEventListenerHandler(gpointer):CON_EVENT_INTERFACE_CHANGE:
   181219:165228 stored[23899]: I com.lab126.store:setConnected:new connected state = 0:
   181219:165228 stored[23899]: I conutils:lockAny::Locking shared lock for all connections
[!]181219:165228 dmld[5555]: I dmld:cmd_internet_connected_event_callback:Unused Event 0 received:
   181219:165228 phd[2212]: I udp_tphv3:restarting_on_wifi_change::
   181219:165228 phd[2212]: I udp_tphv3:network_change:wifi_mode=1,network=1:
   181219:165228 phd[2212]: I udp_tphv3:restarting_on_wan_connection:network=1:
   181219:165228 phd[2212]: I udp_tphv3:Initalizing_udp_tphv3::
   181219:165228 phd[2212]: I udp_tphv3:listening:pins_server = xxx.xxx.78.3:
   181219:165228 phd[2212]: I udp_tphv3:V3_HELLO:intf=WIFI,silent=420,session=600,mcc=0,mnc=0,device_type=A21RY355YUXQAF:params
   181219:165228 phd[2212]: I udp_tphv3:sending_hello:srv=xxx.xxx.78.3, port=33434:
   181219:165228 phd[2212]: I udp_tphv3:sending_hello:srv=xxx.xxx.78.3, port=49317:
   181219:165228 phd[2212]: I udp_tphv3:sending_hello:srv=xxx.xxx.78.3, port=40317:
   181219:165228 tmd[2108]: I lipc_cb_cmd:Connection Util Event:event = 0:
   181219:165228 tmd[2108]: I lipc_cb_cmd:Connect event received:event = 0:
   181219:165228 tmd[2108]: I recompute_retry_time:new_time:next_retry_time = 2018/12/19-Wed-16.54.28.:next_retry_info = @165428.83 for any_transport,intvl=2m
   181219:165228 tmd[2108]: I lipc_cb_cmd:Connection Util Event:event = 3:
   181219:165228 tmd[2108]: I lipc_cb_cmd:Connect event received:event = 0:
   181219:165228 tmd[2108]: I conutils:unlockAny::Unlocking shared lock for all connections
   181219:165228 tmd[2108]: I conutils:conEnsureConnectionResponse::response=0
   181219:165228 tmd[2108]: I conutils:shortcutEnsureCon::Using cached result for connection request
   181219:165228 stored[23899]: I conutils:shortcutEnsureCon::Using cached result for connection request
   181219:165228 stored[23899]: I conutils:unlockAny::Unlocking shared lock for all connections
   181219:165228 todo[2081]: I todo:ProcessingToDo:status=starting,reason=NetworkStartup:Started processing ToDo
   181219:165228 fontscanner: I lipc:evts:name=ScanStarted, origin=com.lab126.userFontsScan:Event sent
   181219:165228 fontscanner: I lipc:evts:name=NoChange, origin=com.lab126.userFontsScan:Event sent
   181219:165228 cvm[4742]: I HTTPUtil:clearDNSCache:cache_size=0:clearing DNS cacheMap
   181219:165228 cvm[4742]: I HTTPUtil:clearConnectionCache::clearing keep alive cache
   181219:165228 phd[2212]: I udp_tphv3:V3_GOTO:srv=xxx.xxx.189.44, port=33434, silent=27, session_to=28:received
   181219:165228 phd[2212]: I udp_tphv3:sending_still_here:srv=xxx.xxx.189.44, port=33434,reason=New session:
   181219:165228 stored[23899]: E com.lab126.store:virtual void JSObjectNet::onNetworkInterfaceChanged():callback function not assigned:
   181219:165228 stored[23899]: W com.lab126.store:static gboolean NetworkManager::s_connectionEventListenerHandler(gpointer):unhandled event [3]:
   181219:165228 tmd[2108]: I recompute_retry_time:new_time:next_retry_time = {never}:next_retry_info = {never} for recompute_retry_time() init
   181219:165228 tmd[2108]: I start_transfer:starting:id=63,dir=up,pri=1600,qpos=0 of 1,net=wan,on=wifi,was=DEFERRED,defby=NETWORK_DOWN,try=1,ceh=0x42629748:
   181219:165228 stored[23899]: I com.lab126.store:void NetworkManager::updateProxy():no proxy set - connection type=wifi reason=connection without proxy:
   181219:165228 stored[23899]: I com.lab126.store:setConnected:new connected state = 1:
   181219:165228 todo[2081]: I conutils:shortcutEnsureCon::Using cached result for connection request
   181219:165228 cvm[4742]: I WirelessImpl:SettingProxyInfo:interface={}:ProxyMapFromCMD
   181219:165228 cvm[4742]: I WirelessImpl:SettingProxyInfo:interface=wifi:Proxies setup done
   181219:165228 cvm[4742]: I url_builder:HandlerExists::Adding/Updating property to handler
   181219:165228 cvm[4742]: I lipc:evts:name=credentialsInstalled, origin=com.lab126.DeviceAuthenticationService:Event sent
   181219:165228 stored[23899]: I com.lab126.store:EventListener::glibSerilizationFunction: Listener at [0x14afb0] is executing for eventName [credentialsInstalled]:
   181219:165228 tmd[2108]: I Transfer Request:Credentials Installed::
   181219:165228 cvm[4742]: I url_builder:HandlerExists::Adding/Updating property to handler
   181219:165228 system: I asr_setup:Not in asr mode::reason=flag file not present. shutting down asr_setup::
   181219:165228 lipc-get-prop[32356]: W def:lipc:method=LipcOpenEx service=(null):Method has been deprecated.
   181219:165228 cvm[4742]: I WhisperSyncV2ServiceImpl:Information::starting the Sync operation
   181219:165228 cvm[4742]: I WhisperSyncV2ServiceImpl:Information::starting to upload the pending changes
   181219:165228 cvm[4742]: I WhisperSyncV2ServiceImpl:Information::Syncing pending dataset delete operations
   181219:165228 cvm[4742]: I GrokServiceImpl:UpdateState:action=skip,retcode=<none>,body=<none>:No change
   181219:165228 cvm[4742]: I WhisperSyncV2ServiceImpl:Information::Completed uploading the pending changes
   181219:165228 cvm[4742]: I WhisperSyncV2ServiceImpl:GetRemoteDirectoryUpdates:status=starting:
   181219:165228 system: I asr_bt_userstore:winmgr_running=true. winmgr is ready::
   181219:165229 cvm[4742]: I conutils:shortcutEnsureCon::Using cached result for connection request
   181219:165229 lipc-set-prop[32384]: W def:lipc:method=LipcOpenEx service=(null):Method has been deprecated.
   181219:165229 system: I asr_bt_userstore:lab126_gui_running=true. Triggering asr_bt_reboot::
[!]181219:165229 system: I system:emiting_event:trigger_asr_bt_reboot:
[!]181219:165229 [16466.614204] ThreadPool-Proc (27761): undefined instruction: pc=40c11850
[!]181219:165229 [16466.614214] Code: e590c004 e15c0008 0a000000 eafc790b (e7f000f0) 
[!]181219:165229 [16466.614328] ThreadPool-Proc (27761): undefined instruction: pc=40c11b90
[!]181219:165229 [16466.614336] Code: e590c004 e15c0008 0a000000 eafc783b (e7f000f0) 
[!]181219:165229 [16466.614622] ThreadPool-Proc (27761): undefined instruction: pc=40c21240
[!]181219:165229 [16466.614631] Code: e590c004 e15c0008 0a000000 eafc3a8f (e7f000f0) 
   181219:165229 system: D sytem:event_emitted:trigger_asr_bt_reboot:
[!]181219:165229 ADM[32393]: I Main: Registering event callbacks.
[!]181219:165229 ADM[32393]: I Main: Registering property callbacks.
[!]181219:165229 ADM[32393]: I Main: Starting the event listener thread.
[!]181219:165229 ADM[32393]: I Main: Waiting for tasks.
[!]181219:165229 ADM[32393]: I Main: Received wifi connection event.
[!]181219:165229 ADM[32393]: I Main: Received missed TPH event: interfaceChange.
[!]181219:165229 ADM[32393]: I Main: Received TPH event: missedTPH.
[!]181219:165229 ADM[32393]: I Main: Processing task.
   181219:165229 system: I asr_bt_reboot:asr_bt_reboot begin on trigger_asr_bt_reboot::
   181219:165229 lipc-set-prop[32408]: W def:lipc:method=LipcOpenEx service=(null):Method has been deprecated.
[!]181219:165229 ADM[32393]: I Main: Received TPH event: credentialsInstalled.
[!]181219:165229 ADM[32393]: I HttpClient: Making request to https://device-messaging-na.amazon.com/GetMessages
[!]181219:165229 cvm[4742]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
[!]181219:165229 cvm[4742]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
   181219:165229 cvm[4742]: I WhisperSyncV2ServiceImpl:GetRemoteDirectoryUpdates:status=61a986db-03d8-11e9-a993-b72529693dfb:requestId 
   181219:165229 cvm[4742]: I WhisperSyncV2ServiceImpl:GetRemoteDirectoryUpdates:status=Ending:
[!]181219:165229 ADM[32393]: I Main: Waiting for tasks.
[!]181219:165229 ADM[32393]: I Main: Processing task.
[!]181219:165229 ADM[32393]: I HttpClient: Making request to https://device-messaging-na.amazon.com/GetMessages
[!]181219:165230 ADM[32393]: I Main: Waiting for tasks.
[!]181219:165230 dropbear[32415]: Child connection from 192.168.0.12:52337
   181219:165231 scan[5602]: I fullscan:BRIDGE::----2----
[!]181219:165231 todo[2081]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
[!]181219:165231 todo[2081]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
[!]181219:165231 todo[2081]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
   181219:165231 tmd[2108]: I header:list:id=63,headers={:RESPONSE::HTTP/1.1 100 Continue}:
   181219:165231 tmd[2108]: I header:list:id=63,headers={:RESPONSE::HTTP/1.1 200 OK},{Content-Length:121},{Content-Type:application/json},{Date:Wed, 19 Dec 2018 21:52:31 GMT},{Server:Server}:
   181219:165231 tmd[2108]: I end_transfer:COMPLETED:id=63,dir=up,pri=1600,net=wan,on=wifi,curl=0,srv=200,try=1,resumes=0,declines=0,mm=receiving_body,len=1400,saved=0:
   181219:165231 tmd[2108]: I rate_stats1:COMPLETED:id=63,t1_tmdreq=@165205.72,t2_enq=0ms,t3_actv=1ms,t4_hprt1=22237ms,t5_hprt=@165227.95,t6_hpet1=965ms,t7_hpet=@165228.92,t8_start1=@165228.92,t9_start=@165228.92,t10_start=1ms,t11_work=801ms,t12_dns=26ms,t13_conn=43ms,t14_ssl=1387ms,t15_reqsent=0ms,t16_respst=555ms,t17_eoh=0ms,t18_dstart=48ms,t19_dend=100ms,t20_end=@165231.89,try=1:
[!]181219:165231 tmd[2108]: I rate_stats2:COMPLETED:id=63,session_time=2964ms,chunk_time=100ms,chunk_len=1400 of 1400,adj_len=1400,session_rate=472 B/sec,chunk_rate=14000 B/sec,overall=2s,active=2s,lost=0s,type=(unknown),start_wss=-1,end_wss=-1,c1_redir=0ms,c2_dns=21ms,c3_conn=47ms,c4_ssl=1387ms,c5_pret=0ms,c6_dstart=594ms,c7_dend=110ms,c8_total=2162ms,try=1,mcc=,mnc=:
   181219:165231 tmd[2108]: I moreinfo:COMPLETED:id=63,srv=200,srvbody=/tmp/tmd-2108-63:
   181219:165231 tmd[2108]: I def:malloc_trim::start
   181219:165231 cvm[4742]: I OdotLiteUploadService:HandleOdotMesgUploadToDo:status=postProcessing,key=/var/local/odot_outbox/exclude_none/messages.gz,file=/var/local/odot_outbox/exclude_none/messages.gz:
   181219:165231 tmd[2108]: I def:malloc_trim:ret=1:end
   181219:165231 tmd[2108]: I tq_mh:memory_reclaimed_trim:before=6768, after=6628, reclaimed=140:
   181219:165231 cvm[4742]: I TransferServiceImpl:Request:requestType=acknowledge,id=63,key=<private>,status=success:Succesfully dequeued transfer request
   181219:165231 cvm[4742]: I OdotLiteUploadService:HandleOdotMesgUploadToDo:status=success,key=/var/local/odot_outbox/exclude_none/messages.gz,file=/var/local/odot_outbox/exclude_none/messages.gz:Successfully uploaded ODOT outbox msgs to server.
   181219:165231 cvm[4742]: I ODOTStorageProviderImpl:Information::deleting messages.gz file...
[!]181219:165231 todo[2081]: I todo_get_document:todo_get_document:total(s)=2.02,DNS(s)@0.02,connect(s)@0.06,SSL(s)@1.94,pretrans(s)@1.96,first-byte-rcvd(s)@2.02,time-to-redirect(s)=0.00,size_upload(b)=0.00,size_download(b)=648.00,speed_download(bps)=321.00,speed_upload(bps)=0.00,:curl_easy_perform
   181219:165231 todo[2081]: I def:malloc_trim::start
   181219:165231 todo[2081]: I def:malloc_trim:ret=1:end
   181219:165231 todo[2081]: I todo:ProcessingToDoItem:id=archive,topic=archive.sync:
   181219:165231 archive[2080]: I archive:ProcessArchivedItemsToDo:status=skipping,id=archive,topic=archive.sync,processingReason=NetworkStartup,currentStatus=1:Processing archive items from ToDo
   181219:165231 archive[2080]: I archive:ProcessArchivedItemsToDo:status=success,id=archive,topic=archive.sync,processingReason=NetworkStartup:Processed archive items from ToDo
   181219:165232 todo[2081]: I todo:ProcessingToDoItem:id=B004GHNIRK,topic=legacy.UPD_LPRD.EBOK:
   181219:165232 cvm[4742]: I ToDoImpl:StartProcessingToDoItem:id=B004GHNIRK,topic=legacy.UPD_LPRD.EBOK:
   181219:165232 cvm[4742]: I LprToDoHandler:HandleLprToDo:status=received,id=B004GHNIRK,topic=legacy.UPD_LPRD.EBOK:Starting UPD_LPR processing
   181219:165232 cvm[4742]: E SyslogFormatter:FormatError:err-component=LprToDoHandler,err-id=UPD_LPR,err-msg=Path found successfully:Argument Value Mismatch
   181219:165232 cvm[4742]: E YJSDK:Error::Failed to get BookSecurity object from SDK
   181219:165232 cvm[4742]: W LprToDoHandler:HandleLprToDoFailed:reason=unableToOpenBook,id=B004GHNIRK,topic=legacy.UPD_LPRD.EBOK:unableToOpenBook
   181219:165232 cvm[4742]: I ToDoImpl:DoneProcessingToDoItem:id=B004GHNIRK,topic=legacy.UPD_LPRD.EBOK:
   181219:165232 todo[2081]: I todo:ProcessingToDoItem:id=NONE,topic=legacy.UPLOAD.MESG:
   181219:165232 cvm[4742]: I ToDoImpl:StartProcessingToDoItem:id=NONE,topic=legacy.UPLOAD.MESG:
   181219:165232 todo[2081]: I todo:ReportStatus:id=NONE,status=1,topic=legacy.UPLOAD.MESG,description=success:Reporting item status
   181219:165232 cvm[4742]: I ToDoImpl:DoneProcessingToDoItem:id=NONE,topic=legacy.UPLOAD.MESG:
   181219:165232 todo[2081]: I todo:ProcessingToDoItem:id=whispersync,topic=whispersync.upload:
   181219:165232 cvm[4742]: I ToDoImpl:StartProcessingToDoItem:id=whispersync,topic=whispersync.upload:
   181219:165232 cvm[4742]: I WhisperSyncToDoHandler:HandleToDo:status=success,id=whispersync,topic=whispersync.upload:Successfully scheduled WhisperSync journal upload
   181219:165232 cvm[4742]: I ToDoImpl:DoneProcessingToDoItem:id=whispersync,topic=whispersync.upload:
   181219:165232 cvm[4742]: I WhisperSyncV1Impl:UploadJournal:status=starting:
   181219:165232 cvm[4742]: I WhisperSyncV1Impl:UploadJournal:status=noJsonJournal:No json journal entries to upload, aborting
   181219:165232 todo[2081]: I conutils:lockAny::Locking shared lock for all connections
   181219:165232 todo[2081]: I conutils:conEnsureConnectionInternal::setting cmd property
   181219:165232 cmd[2072]: I def:req::Got a connection request:~:
   181219:165232 todo[2081]: I todo:ProcessingToDoItem:id=mrchUpdate,topic=MRCH.UPDATE:
   181219:165232 tmd[2108]: I lipc_cb_cmd:Connect event received:event = 0:
   181219:165232 todo[2081]: I conutils:unlockAny::Unlocking shared lock for all connections
   181219:165232 todo[2081]: I conutils:conEnsureConnectionResponse::response=0
   181219:165232 cvm[4742]: I ToDoImpl:StartProcessingToDoItem:id=mrchUpdate,topic=MRCH.UPDATE:
   181219:165232 cvm[4742]: I DownloadHandler:CampaignLifeCycle:timestamp=1545256352278:start handling merchant todo item
   181219:165232 cvm[4742]: I DownloadHandler:CampaignLifeCycle:timestamp=1545256352279:is updating=false, longer than 24hr=false
   181219:165232 cvm[4742]: I ToDoImpl:DoneProcessingToDoItem:id=mrchUpdate,topic=MRCH.UPDATE:
   181219:165232 todo[2081]: I todo:ProcessingToDoItems:status=finished:Finished processing ToDo
   181219:165232 scan[5602]: I fullscan:CLEANUP::----3----
[!]181219:165232 todo[2081]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
[!]181219:165232 todo[2081]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
[!]181219:165232 todo[2081]: I certman:CertmanCheckStatus:valid cert in keyfile:cache hit
[!]181219:165232 todo[2081]: I todo_send_item_status:post_status_legacy:total(s)=0.35,DNS(s)@0.02,connect(s)@0.06,SSL(s)@0.28,pretrans(s)@0.28,first-byte-rcvd(s)@0.35,time-to-redirect(s)=0.00,size_upload(b)=148.00,size_download(b)=84.00,speed_download(bps)=242.00,speed_upload(bps)=426.00,:curl_easy_perform
   181219:165232 todo[2081]: I def:malloc_trim::start
   181219:165232 todo[2081]: I def:malloc_trim:ret=1:end
   181219:165232 scan[5602]: I fullscan:OK:add=0,del=0,upd=0,ipaused=2 :Scanner succeeded to pause the indexer.
   181219:165232 scan[5602]: I lipc:evts:name=fullScanFinish, origin=com.lab126.scanner:Event sent
   181219:165232 scan[5602]: I broadcast_event:sent:msg=fullScanFinish:
[!]181219:165232 dropbear[32415]: Pubkey auth succeeded for 'root' with key sha1!! 0b:b4:b9:89:9d:58:41:41:7f:af:23:74:a3:62:21:34:17:06:0a:fe from 192.168.0.12:52337
   181219:165233 cvm[4742]: I conutils:lockAny::Locking shared lock for all connections
   181219:165233 cvm[4742]: I conutils:conEnsureConnectionInternal::setting cmd property
   181219:165233 cmd[2072]: I def:req::Got a connection request:~:
   181219:165233 cvm[4742]: I conutils:unlockAny::Unlocking shared lock for all connections
   181219:165233 cvm[4742]: I conutils:conEnsureConnectionResponse::response=0
   181219:165233 tmd[2108]: I lipc_cb_cmd:Connect event received:event = 0:
[!]181219:165236 dropbear[29446]: Exit (root): Keepalive timeout
   181219:165237 cvm[4742]: I IndexerThread:Information::allowed to index: ALL CONDITIONS MET
   181219:165237 cvm[4742]: I IndexerThread:CLEANUP:action=BEGIN_INDEXER_CLEANUP:
[!]181219:165238 [16475.607307] IndexerThread (5329): undefined instruction: pc=40bfb900
[!]181219:165238 [16475.607318] Code: e590c004 e15c0008 0a000000 eafcd0df (e7f000f0) 
   181219:165242 scan[5602]: I fullscan:THUMB::----4----
   181219:165243 scan[5602]: I libload:loaded:glob=*.kual,ep=load_file_extractor:
   181219:165243 scan[5602]: I NATIVE:dlopen:so=/usr/lib/ccat/libfileE.so:loaded
   181219:165243 scan[5602]: I libload:loaded:glob=*.txt,ep=load_file_extractor:
   181219:165243 scan[5602]: I NATIVE:dlopen:so=/usr/lib/ccat/libfileE.so:loaded
   181219:165243 scan[5602]: I fullscan:IDLE::----0----

The only interesting line that I found is:

Code:

181219:165009 blanket[2987]: I def:USB_EVENT_MONITOR:usb module : prerender usb window:charging state = 1

So 'blanket' is in /usr/sbin/ . I believe if 'charging state' was equal to 0, it would just change the battery icon from ov_default_charging.png to ov_default_notcharging.png

I can't find where this function of 'prerender usb window' comes from.

Also I found f_puts() function in /etc/upstart/functions, that looks like the one to draw these messages:

Code:

f_puts() {
  local eh=20 ew=12 # eips font size
  local x=$1 y=$2
  shift 2
  local mess="$*"

  [ $x -lt 0 ] && x=$(( _v_width/ew + x - $(expr length "$mess") + 1 ))
  [ $y -lt 0 ] && y=$(( _v_height/eh + y ))

  eips $x $y "$mess"
}

However I can't find any use of this function in any other /etc/upstart files.

NiLuJe · 12-19-2018, 05:41 PM

Blanket's in charge of the various full-screen state-specific screens (screensaver, USBMS, YKNR, ...).

Most of it is actual code, not shell scripting.

You'll find a few mentions around because it can communicate through lipc, but that's it.

You should be able to listen to the usb(Un)configured event in one way or another though, but those might be tad early.

(Basically, anything after lipc:evts, you should be able to hook into, just have to find the right one, timing wise).

12-18-2018, 10:50 PM	#2
knc1 Going Viral Posts: 17,212 Karma: 18210809 Join Date: Feb 2012 Location: Central Texas Device: No K1, PW2, KV, KOA	Didn't dos1 create a set of files and script for capturing events? Found it: https://www.mobileread.com/forums/sh...d.php?t=198484 It should be possible to modify his scripts to capture the event(s) that you want. Last edited by knc1; 12-18-2018 at 11:08 PM.

12-19-2018, 05:41 PM	#4
NiLuJe BLAM! Posts: 13,478 Karma: 26012494 Join Date: Jun 2010 Location: Paris, France Device: Kindle 2i, 3g, 4, 5w, PW, PW2, PW5; Kobo H2O, Forma, Elipsa, Sage, C2E	Blanket's in charge of the various full-screen state-specific screens (screensaver, USBMS, YKNR, ...). Most of it is actual code, not shell scripting. You'll find a few mentions around because it can communicate through lipc, but that's it. You should be able to listen to the usb(Un)configured event in one way or another though, but those might be tad early. (Basically, anything after lipc:evts, you should be able to hook into, just have to find the right one, timing wise). Last edited by NiLuJe; 12-19-2018 at 05:43 PM.

Similar Threads
Thread	Thread Starter	Forum	Replies	Last Post
Touch Kobo touch frozen on "connected and charging" screen	EricLandes	Kobo Reader	18	01-07-2013 01:57 AM
KT "Ghost covers/files" again at 670 books, "stale" image entries in firmware	VirgoGirl	Kobo Reader	4	04-06-2012 02:10 PM
Touch Horizontal white streaky lines - on "Connected and Charging" screen	beautifulsoup	Kobo Reader	0	07-27-2011 06:47 PM
Sony PRS700 says "USB Connected" but IS NOT!	macthekitten	Sony Reader	1	09-05-2010 07:59 AM
My Sony Reader only shows: "USB connected"	luisbeltran	Sony Reader	12	02-20-2009 10:15 PM

12-18-2018, 10:34 PM	#1
mergen3107 Wizard Posts: 1,061 Karma: 4234828 Join Date: Feb 2012 Location: Cape Canaveral Device: Kindle Scribe	"USB Connected" screen image replacement Dear Mobileread Community, I need your help in replacing screen image when Kindle Paperwhite 3 (5.9.7) is connected via USB. I had no problem doing that on Kindle 4 Non-Touch. However, it seems like besides the png file itself, their is also an eips (?) command to draw something else. What I did: 1) Prepared an image. Just took my favorite one and after some tweaks in GIMP, I finally converted it to a proper eips-compatible format: Code: convert input.png -type GrayScale -depth 8 -colors 256 -resize 1072x1448! output.png 2) Replaced bg_usbconnect.png in /usr/share/blanket/usb and gave it the same permission chmod as it was of the original one. I attached my screen image to this post. 3) Now, when I connect to USB, my new screen image shows up very well, but on top of that there are two more things. One is a text 'If you want to read while still charging... blahblah', another is a small white square of a charging icon. I can see that it is ov_default_charging.png (I attached it too) in the same folder. 4) I returned to (1) and added a white circle approximately at location around that square. Why approximately? Because I don't have exact coordinates or a combined pictures of them all. Well, here come two problems: 1) I have no idea how to take screenshot of the screen while Kindle is connected via USB. I tried to: — press the diagonally opposite corners of the screen (as for usual screenshot). Screen blinks, as if it took a screenshot, but I can't find it. I guess, because /mnt/us/ is now unmounted and presented to PC, there is no place to put screenshot to. — access ssh during usb connection, but Kindle is inaccessible when connected, so I can't reach command line to invoke 'screenshot' command. — connect to ssh first, then do 'sleep 20; screenshot' command, then connect to usb and wait for these 20 sec to pass. Screen again flashes as if it took the screenshot, but I can't find it anywhere. 2) I have no success in finding a script for USB connection event neither to see how these two extra things are drawn. I looked up in /etc/upstart/ using Total Commander's 'Search in files' feature trying to find anything related to 'usb'. There should be a daemon (or sort of 'listener') that catches the /mnt/us/ upon usb connection and manages its mount to PC and back to Kindle. If I have at least coordinates of that little square, I could've replaced it by the same pixels of my new image at these coordinates, so that the square would seem 'transparent'. Do you guys have any suggestions? Thanks! Attached Thumbnails Attached Images Last edited by mergen3107; 12-18-2018 at 10:37 PM.

Advert