Kindle PW2 battery issues 5.7.2.1

[knc1]

I have a 'rain-day' or two here (as an excuse not to do spring-time outdoor work) -
so I will take a look at a comparison of the two - see if they are making any changes or if their build system is just cranking out a new kernel build with each "make release" call.

= = = =

Take a look at 'top' in 5.7.3 -
See what the topmost (cpu hog) process is now.

Note:
My report earlier in this thread was taken over the serial port - -
BUT
sshd and telnetd where running (although without any connection to anything).

So your report taken over ssh (USBnetworking) should be comparable.

Note 2:
@NiLuJe: Any reason you can think of why cvm is running wild when sshd, telnetd is 'up'?
Shouldn't they just be passively waiting for a connection, with no effect on cvm at all?

[SlashMaster]

For the moment I cannot run "top" via ssh nor kterm ('xterm': unknown terminal type.) And if i try to run top via screen (locally/xterm), I get "unknown vt100 type".
So, for now the only option is to run top from the old(er) xterm kual extension. Is there any other easy method for screenprints besides my camera?

Oh, and the batterry indicator (bar) is below 50%. Would de-registering / fake-registering help reducing framework/cvm tasks ? I tried that (de-register) after the 5.7.2.1 update and coupled with Airplane mode, seemed to reduce power consumption. But I would use it as a last and temporary resort.

[knc1]

Originally Posted by SlashMaster

For the moment I cannot run "top" via ssh nor kterm ('xterm': unknown terminal type.) And if i try to run top via screen (locally/xterm), I get "unknown vt100 type".
So, for now the only option is to run top from the old(er) xterm kual extension. Is there any other easy method for screenprints besides my camera?

Oh, and the batterry indicator (bar) is below 50%. Would de-registering / fake-registering help reducing framework/cvm tasks ? I tried that (de-register) after the 5.7.2.1 update and coupled with Airplane mode, seemed to reduce power consumption. But I would use it as a last and temporary resort.

The Kindle understands a "two finger salute" -
Simultaniously touch two diagonal corners == screenprint.

But that was good enough - it showed the same thing I saw on my 5.6.1.1

I just returned from morning errands, for Lunch I'll look at those two config files.

A note on what you can't see (without a serial port connection) - -
With sshd and telnetd 'down' and the USB storage exported over the USB cable - -
cvm isn't even running (it isn't on the process list - only upstart is mentioned as waiting to start cvm). . . .
AND
everything about the 'top' display looks like an idle device (I.E: as expected).

So if the problem is in something that cvm is running -
that means somewhere in the closed source (Java) part of the system.

[knc1]

Hmm...
Some more debug hints - not sure how they will fit into the overall troubleshooting yet.

Devices that are too slow to resume or suspend:
http://lkml.iu.edu/hypermail/linux/k...4.0/02268.html

A quote from:
https://community.freescale.com/docs/DOC-98327
(Yes, Android is run by the Linux kernel.)

• System can not enter suspend mode:
• Check below setting items have been disabled:
  • Whether the usb cable has been removed(usb gadget will hold a wake lock)
  • Setting->Display->Sleep, check whether the inactivity timeout period setting is longer than your expected time.
    Does not apply.
  • Setting->System->Developer options->stay awake(stay awake not be set), check whether the option is disabled.
    Does not apply.
• Check if all wake locks have been released(You can see which wake lock is held, and then debug into the specific module):
  

  # cat /sys/power/wake_lock

  Our build does not have that, but...
  

  [root@kindle power]# cat pm_async
  1

  (the usb cable is plugged in -> 1 wake lock)
  Which we may be able to get some use out of.

Also, this may be of use:

[root@kindle power]# cat pm_test
[none] core processors platform devices freezer

Which is a bit strange to see - since the kernel build has power management disabled.

[knc1]

Hmm...

[root@kindle power]# cat state
standby mem
[root@kindle power]# echo -n standby > state

That works - at least everything stops.
A quick tap of the power button wakes it up.

[19426.780764] PM: Syncing filesystems ... done.
[19426.827399] PM: Preparing system for standby sleep
[19426.830041] Freezing user space processes ... (elapsed 0.02 seconds) done.
[19426.853048] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
[19426.873065] PM: Entering standby sleep
[19426.873074] Suspending console(s) (use no_console_suspend to debug)
[19426.893764] udc suspend begins
[19426.893986] USB Gadget suspend ends
[19426.894128] KERNEL: I pmic:fg suspend battinfo:current=0mA, volt=4205mV, capav=100%, mAh=1467mAh:
[19426.913705] add wake up source irq 105
[19426.914966] add wake up source irq 51
[19426.915025] PM: suspend of devices complete after 41.500 msecs
[19426.915401] PM: late suspend of devices complete after 0.359 msecs
# tap power button -
[19426.920381] PM: early resume of devices complete after 0.187 msecs
[19426.920523] remove wake up source irq 51
[19427.122463] remove wake up source irq 105
[19427.142687] KERNEL: I pmic:fg resume battinfo:current=0mA, volt=4206mV, capav=100%, mAh=1466mAh:
[19427.145863] USB Gadget resume begins
[19427.145872] fsl_udc_resume, Wait for wakeup thread finishes
[19427.149345] USB Gadget resume ends
[19427.151052] KERNEL: I pmic:onkey::wario button online event
[19427.168286] PM: resume of devices complete after 247.810 msecs
[19427.168507] PM: Finishing wakeup.
[19427.168515] Restarting tasks ... done.
[19427.188456] mmc1: mmc_rescan_try_freq: trying to init card at 400000 Hz
[19427.304414] mmc1: mmc_rescan_try_freq: trying to init card at 300000 Hz
[19427.400930] mmc1: mmc_rescan_try_freq: trying to init card at 200000 Hz
[19427.515914] mmc1: mmc_rescan_try_freq: trying to init card at 100000 Hz
[19427.584262] g_file_storage gadget: high speed config #1

[knc1]

Now on the other hand:

[root@kindle power]# cat state
standby mem
[root@kindle power]# echo -n mem > state

That one works also and with a difference -
It leaves the screen alone.

This is the end step in a normal 'suspend' operation (see below) which leaves whatever was on the screen.

[knc1]

Another point of interest -
I set the PM threshold to 5000 microseconds (default is 50000 when in 'off' state) -
Removed the USB cable (which was generating (as it is supposed to) that wake_lock) -
Let it go to sleep last night -

Woke it this morning with the following found in the kernel's message buffer:

[root@kindle ksm]# dmesg
[24135.398799] PM: Syncing filesystems ... done.
[24135.417004] PM: Preparing system for mem sleep
[24135.419446] Freezing user space processes ... (elapsed 0.01 seconds) done.
[24135.434185] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
[24135.454195] PM: Entering mem sleep
[24135.454203] Suspending console(s) (use no_console_suspend to debug)
[24135.475077] udc suspend begins
[24135.475619] USB Gadget suspend ends
[24135.475761] KERNEL: I pmic:fg suspend battinfo:current=-164mA, volt=4129mV, capav=094%, mAh=1377mAh:
[24135.494984] PM: device platform:max77696-rtc.0 suspend too slow, it takes     13.112 msecs
[24135.495018] add wake up source irq 105
[24135.497787] add wake up source irq 51
[24135.497845] PM: suspend of devices complete after 43.186 msecs
[24135.498218] PM: late suspend of devices complete after 0.355 msecs
[24135.505188] PM: early resume of devices complete after 0.184 msecs
[24135.505330] remove wake up source irq 51
[24135.758247] PM: device platform:sdhci-esdhc-imx.1 resume too slow, it takes   252.819 msecs
[24135.758802] remove wake up source irq 105
[24135.759833] KERNEL: I pmic:onkey::wario button online event
[24135.781557] PM: device platform:max77696-rtc.0 resume too slow, it takes      22.224 msecs
[24135.787579] KERNEL: I pmic:fg resume battinfo:current=-2mA, volt=4127mV, capav=093%, mAh=1298mAh:
[24135.791579] PM: device platform:max77696-battery.0 resume too slow, it takes          6.527 msecs
[24135.791686] USB Gadget resume begins
[24135.791693] fsl_udc_resume, Wait for wakeup thread finishes
[24135.811652] dr_controller_run: udc enter low power mode 
[24135.811668] USB Gadget resume ends
[24135.811679] PM: device platform:fsl-usb2-udc resume too slow, it takes        19.990 msecs
[24135.831647] PM: resume of devices complete after 326.365 msecs
[24135.831869] PM: Finishing wakeup.
[24135.831876] Restarting tasks ... done.
[24135.851612] mmc1: mmc_rescan_try_freq: trying to init card at 400000 Hz
[24135.993329] mmc1: mmc_rescan_try_freq: trying to init card at 300000 Hz
[24136.160431] mmc1: mmc_rescan_try_freq: trying to init card at 200000 Hz
[24136.286284] mmc1: mmc_rescan_try_freq: trying to init card at 100000 Hz
[24149.529017] KERNEL: I pmic:charger chgina::charger connected
[24149.550688] otg udc vbus rising wakeup
[24149.551417] try_wake_up_udc: udc out low power mode
[24150.179060] g_file_storage gadget: high speed config #1

Note that the first few messages are from when it went to sleep (I couldn't very well clear the buffer after it went to sleep ).

# 95 95

[knc1]

Hmm....

Could this 'problem' be user induced?

I.E:
Leave USB cable connected to PC -
The Kindle will **look as if it powered down** (screen saver showing, front light off) but is still running -
The PC to which it is connected goes to sleep (turning off USB power to running Kindle).

Since the USB cable was not physically removed to generate a 'cable removed' event -
the Kindle will never enter 'suspend' mode.

Note in the above message listing -
such a situation would leave the Kindle drawing 80x the battery current as a normal suspend state would.

[knc1]

^ ^ ^ ^ But 'user induced' would not account for cvm sucking up 98% of cpu while the system is supposedly idle ^ ^ ^ ^

[root@kindle upstart]# /usr/bin/dump-stack `pidof cvm`
system: I dump-stack:dumpstack:cvm:pid=20321:begin native threads ==============================
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libpthread.so.0]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libgcc_s.so.1]

warning: Lowest section in /usr/lib/libicudata.so.50 is .gnu.hash at 000000b4
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /usr/lib/lua/libluasqlite3.]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libpthread.so.0]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libgcc_s.so.1]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /usr/lib/lua/libluasqlite3.]
system: I dump-stack:dumpstack:cvm:pid=20321:end native threads ================================
system: I dump-stack:dumpstack:cvm:pid=20321:begin proc maps ================================
system: I dump-stack:dumpstack:cvm:pid=20321:end proc maps    ================================
system: I tinyrot:def::Rotating file /var/log/messages with max size 256
/usr/sbin/tinyrot : Signaling syslog
system: I tinyrot:def::Rotating file /var/log/netlog with max size 256
system: I tinyrot:def::No file to rotate: /var/log/netlog
system: I tinyrot:def::Rotating file /var/log/odotlite with max size 2048
system: I tinyrot:def::No file to rotate: /var/log/odotlite
system: I tinyrot:def::Rotating file /var/log/wpa_supplicant with max size 128
system: I tinyrot:def::No file to rotate: /var/log/wpa_supplicant
system: I tinyrot:def::Rotating file /var/log/metrics_generic with max size 64
system: I tinyrot:def::No file to rotate: /var/log/metrics_generic
system: I tinyrot:def::Rotating file /var/log/metrics_high_priority with max size 64
system: I loginfo:devhw:boardID=0670:muscat device - rev 2
system: I loginfo:devsworig::Original System Software Version: 033-juno_6011_muscat_wario-263413
Wed Apr 15 08:15:02 PDT 2015
com.lab126.eink.muscat.os
system: I loginfo:devswota::OTA  Kindle 5.6.1.1 (~~otaVersion~~)
com.lab126.wan failed to access property localTimeOffset (0x3 lipcErrNoSuchSource)
system: W loginfo:ltofailwandoff:cannot retrieve local time offset - wand not running
/usr/sbin/tinyrot : Signaling syslog

Mis-matched cvm build and system library build.
Someone use the above dumpstack command to see if 5.7.x (or whatever your running) is any better.
those are back-ticks, not single quotes in the command.

next question?

[SlashMaster]

Here is my dumpstack:

[root@kindle vasi]#  /usr/bin/dump-stack `pidof cvm`
system: I dump-stack:dumpstack:cvm:pid=4508:begin native threads ==============================
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libpthread.so.0]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libgcc_s.so.1]

warning: Lowest section in /usr/lib/libicudata.so.50 is .gnu.hash at 000000b4
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /usr/lib/libdevice-cap.so]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libpthread.so.0]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /lib/libgcc_s.so.1]
Error while reading shared library symbols:
Dwarf Error: wrong version in compilation unit header (is 4, should be 2) [in module /usr/lib/libdevice-cap.so]
system: I dump-stack:dumpstack:cvm:pid=4508:end native threads ================================
system: I dump-stack:dumpstack:cvm:pid=4508:begin proc maps ================================
system: I dump-stack:dumpstack:cvm:pid=4508:end proc maps    ================================
system: I tinyrot:def::Rotating file /var/log/messages with max size 256
/usr/sbin/tinyrot : Signaling syslog
system: I tinyrot:def::Rotating file /var/log/netlog with max size 256
/usr/sbin/tinyrot : Signaling syslog
system: I tinyrot:def::Rotating file /var/log/odotlite with max size 2048
system: I tinyrot:def::No file to rotate: /var/log/odotlite
system: I tinyrot:def::Rotating file /var/log/wpa_supplicant with max size 128
/usr/sbin/tinyrot : Signaling syslog
system: I tinyrot:def::Rotating file /var/log/metrics_generic with max size 64
system: I tinyrot:def::Max file size hit 2 on /var/local/log/metrics_generic_00000048_20160310143004.gz
system: I loginfo:devhw:boardID=0620:bourbon device - rev 6
system: I loginfo:devsworig::Original System Software Version: 015-<private>-289939
Fri Feb 26 01:55:39 PST 2016
system: I loginfo:devswota::OTA  Kindle 5.7.3 (~~otaVersion~~)
com.lab126.wan failed to access property localTimeOffset (0x3 lipcErrNoSuchSource)
system: W loginfo:ltofailwandoff:cannot retrieve local time offset - wand not running
/usr/sbin/tinyrot : Signaling syslog
system: I tinyrot:def::Rotating file /var/log/metrics_high_priority with max size 64
system: I loginfo:devhw:boardID=0620:bourbon device - rev 6
system: I loginfo:devsworig::Original System Software Version: 015-<private>-289939
Fri Feb 26 01:55:39 PST 2016
system: I loginfo:devswota::OTA  Kindle 5.7.3 (~~otaVersion~~)
com.lab126.wan failed to access property localTimeOffset (0x3 lipcErrNoSuchSource)
system: W loginfo:ltofailwandoff:cannot retrieve local time offset - wand not running
/usr/sbin/tinyrot : Signaling syslog

[knc1]

durn, but that looks familar.

Since my posting, it has occured to me that perhaps that dumpstack utility is the only thing that got mis-built (and its output is meaningless).

I have also been digging around in /etc/upstart and reading the scripts.
There are quite a few debugging related things mentioned - I wish I knew which one would provide the answer.

You can enter the following command without any options and it will report on what options it accepts.

But cvm continues to hog the cpu (and the SoC still is drawing almost the max. current it can) -
Which means one of these services is broke:

[root@kindle upstart]# lipc-probe -l                                            
com.lab126.todo                                                                 
com.lab126.amazonRegistrationService                                            
com.lab126.otav1                                                                
com.lab126.kindleStatusService                                                  
com.lab126.winmgr.ligl                                                          
com.lab126.booklet                                                              
com.lab126.powerd                                                               
com.lab126.kaf                                                                  
com.lab126.winmgr                                                               
com.lab126.deviced                                                              
com.lab126.grokservice                                                          
com.amazon.ebook.util.net.certmanutilities                                      
com.lab126.booklet.home                                                         
com.lab126.odot                                                                 
com.lab126.freetime                                                             
com.lab126.transferService                                                      
com.lab126.JournalingService                                                    
com.lab126.adManager                                                            
com.lab126.LocalizationServices                                                 
com.lab126.pmond                                                                
com.lab126.DeviceAuthenticationService                                          
com.lab126.reader.readingtimer                                                  
com.lab126.blanket                                                              
com.lab126.archive                                                              
com.lab126.system                                                               
com.lab126.certmand                                                             
com.amazon.kindle.inputMethod                                                   
com.lab126.dsus                                                                 
com.lab126.indexer                                                              
com.lab126.extractor.java                                                       
com.lab126.scanner                                                              
com.lab126.transfer                                                             
com.lab126.dynconfig                                                            
com.lab126.cmd                                                                  
com.lab126.todo.kaf                                                             
com.lab126.refreshCache                                                         
com.lab126.keyboard                                                             
com.lab126.readingstreams                                                       
com.lab126.IdentityService                                                      
com.lab126.stored                                                               
com.lab126.pillow                                                               
com.lab126.demoservice                                                          
com.lab126.dpm.apps                                                             
com.lab126.wifid                                                                
com.lab126.mobi8                                                                
com.lab126.lxinit                                                               
com.lab126.appmgrd                                                              
com.lab126.devicemetrics                                                        
com.lab126.phd                                                                  
com.lab126.adRotationManager                                                    
com.lab126.sph                                                                  
com.lab126.volumd                                                               
com.lab126.bookcacher                                                           
com.lab126.tphv3                                                                
com.lab126.instantSearch                                                        
com.lab126.coverArtService                                                      
com.lab126.ccat                                                                 
com.lab126.contentpackd                                                         
com.lab126.store                                                                
com.lab126.linux.arm.connectionutilities                                        
com.lab126.reader.languagelayer                                                 
com.lab126.household                                                            
com.lab126.dpmManager                                                           
com.lab126.KindleIdentity                                                       
com.lab126.ota                                                                  
com.lab126.sharing                                                              
com.lab126.reader.qa                                                            
com.lab126.cvm                                                                  
com.lab126.merchant                                                             
org.freedesktop.DBus

the Kindle is a busy little thing, even when it isn't broke.

Another example of the command:

[root@kindle upstart]# lipc-probe -v com.lab126.cvm                             
        rw      Str     logMask [0x0fff0000]                                    
        rw      Str     logLevel        [Current log level=info                 
(Possible transient levels: all, perf, debug[9-0], info, warn, error, crit, non)
(Possible persistent levels: p_all, p_perf, p_debug[0-9], p_info, p_warn, p_err]

And this one has possibilities for the next generation of backdoor lock:

[root@kindle upstart]# lipc-probe -v com.lab126.ota                             
        w       Str     refreshCache                                            
        r       Int     isFirstBootAfterUpdate  [0]                             
        r       Str     getUpdateVersion        [0]                             
        r       Int     isUpdateAvailable       [0]                             
        w       Int     startUpdate                                             
        rw      Str     logLevel        [Current log level=info                 
(Possible transient levels: all, perf, debug[9-0], info, warn, error, crit, non)
(Possible persistent levels: p_all, p_perf, p_debug[0-9], p_info, p_warn, p_err]
        w       Int     scanUserstoreForUpdates                                 
        rw      Str     logMask [0x0fff0000]                                    
        r       Str     isUpdatePending []                                      
        rw      Has     transferProgressNotification    [*NOT SHOWN*]

But the only way to learn about how to use these things is by reading how they are used in the existing scripts, and hope someone left in some comments.

[NiLuJe]

@knc1: Which thread is hogging the cpu? (htop has a thread view if the bundled busybox ps sucks).

I'm also not sure CPU_IDLE is applicable on ARM/the freescale Kernel. I think the equivalent for mxc chips is properly handled somewhere else.

[knc1]

Unable to comprehend: "if the bundled ps six"

[NiLuJe]

Whoops, Apple's autocorrect strikes again ;p. Edited .

[knc1]

Originally Posted by NiLuJe

Whoops, Apple's autocorrect strikes again ;p. Edited .

OK, that I can make sense of.


I can see no problem with the display of CPU%, either the total summary or the indiviual listings.

It follows the battery current draw from -168ma (98.8%) to -2ma (less than 0.0%).

Which is reasonable and about the only thing that is reasonable about this problem.

But I will try to get 'per cvm thread' numbers also.

For the non-hardware guru readers:

The SoC is built with CMOS logic.
A characteristic of CMOS logic is that the current draw increases with (both) the frequency the logic devices switch states and the number of logic devices switching states.

Plus -
The problem is that the device is using too much battery power.
The comments about cpu load are just side-effects of whatever the real problem is.

And a real far out comment:
Keep in mind the SoC is no longer "Freescale" but "NXD" -
The new company owners may have let a manufacturing error slip into the process of building the i.MX6 devices.
The few people reporting problems may just have Kindles built with the floor sweepings of the chip foundry (higher chip construction error rates == lowered production costs).