|
Wizard
Posts: 1,500
Karma: 5000046
Join Date: Feb 2012
Location: Cape Canaveral
Device: Kindle Scribe
|
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.
Last edited by mergen3107; 12-19-2018 at 05:28 PM.
|