Register Guidelines E-Books Search Today's Posts Mark Forums Read

Go Back   MobileRead Forums > E-Book Readers > Kobo Reader > Kobo Developer's Corner

Notices

Reply
 
Thread Tools Search this Thread
Old 04-22-2020, 05:52 AM   #1
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
Loop execution stops unexpectedly after several cycles (rtcwake)

Hi there,

I am running a script to show a screensaver/wordclock on my kobo. The script is essentially a loop that displays an image on the kobo an then sends it to sleep via rtcwake. I'm connected to the kobo via telnet (Wifi) and start the script using nohup.

Structure of script:
Kill Kobo-Stuff (nickel etc.)
Shutdown Wifi to save energy
Looping the following
Do something
Send device to sleep (rtcwake -m mem -s 180)
repeat

This runs nicely for some time. But then the script unexpectedly stops. In this case (sent to sleep 180s) it breaks after about half a day. It appears that it breaks after a number of cycles rather than time (when increasing the time sent to sleep it runs much longer).

Most frequently the script stops in front of the rtcwake command but sometimes in the middle of the "do something"-part.

Any ideas what causes the script to stop and how to further debug?

Kind regards
KristianR




PS:
What I tried so far:
- I echoed some debuginformation like running processes, battery-level, date vs hwclock, free memory - nothing obvious to me.
- enabled syslog via "devmodeon" and selecting all logging options. No syslog gets written to .kobo-Directory unless I hit save log (but this is not accessible since in the case of stopped script I can't access the menu). After resetting and saving the log, this log does not contain information of the events before the reset
- dmesg also only shows information after the reset
- tried to establish access via usbnet to connect after script stops. But was not able to get it running - I'm getting following error "insmod: can't insert '/drivers/mx6sl-ntx/usb/gadget/arcotg_udc.ko': invalid module format"
KristianR is offline   Reply With Quote
Old 04-22-2020, 08:44 AM   #2
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
Define "stop". The USBNet plan was a good one to answer that question, more on that later .

We'll also probably going to need to see actual code.

Huh. Nice catch on the USBNet front, apparently that module is builtin on Mk. 6. Did not expect that .
Updated script here.
NiLuJe is offline   Reply With Quote
Advert
Old 04-22-2020, 10:42 AM   #3
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
Hi NiLuJe,

thanks for your response.

"Stop" in the sense of: after the expected timeframe the script appears not to proceed - i.e. there is no new image on the kobo. Last entry in nohup.out is long before I reset the device.

Before starting the following script I kill nickel and hindenburg.

One further information: Currently I'm testing this on a Kobo that's still on 3.19.5761 (but 4.20 shows same behaviour).

Code:
#!/bin/sh
echo "Starting Loop .."
	echo "calling wdn"
	sh wifidown.sh	
	echo "rmmod dhd"
	rmmod dhd
	echo "rmmod sdio"
	rmmod sdio_wifi_pwr
	sleep 5
while [ 1 ]
  do 
	echo ""
	echo "Next loop started at $(date) / $(hwclock)"
	cat /sys/devices/platform/pmic_battery.1/power_supply/mc13892_bat/capacity > batlevel
	# Get a random file to display
	echo "Calling Screensaverscript"
    	filetomove=$(ls -1 wallpaper/*.png | while read x; do echo "$RANDOM:$x"; done | sort -n|cut -d':' -f2| head -1)
	echo $filetomove
	fbink -g file=./$filetomove,halign=CENTER,valign=CENTER -f
	sleep 1
	ps -a
	fbink "{$(date)}"
	free	
	sleep 5
	rtcwake -m mem -s 180
	sleep 5
  done

Copied the updated usbnet-toggle.sh to my device but get the same error - are there any prerequsites necessary?

Kind Regards
KristianR
KristianR is offline   Reply With Quote
Old 04-22-2020, 02:19 PM   #4
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
Huh. Does the file (the kernel module, I mean) actually exist on your device? (It's not in the FW package, and it should definitely not be here at all from my understanding of the kernel config...).
Stupid but obvious remark: make sure you're actually running the updated version of the script .

Other than that, some general remarks: set -xeo pipefail, curly braces, quoting, shellcheck, check FBInk's output, and given set -x: check the output, period .

Last edited by NiLuJe; 04-22-2020 at 03:47 PM.
NiLuJe is offline   Reply With Quote
Old 04-22-2020, 03:44 PM   #5
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
Another specific comment about passing image filenames: while you can quote suboptions (like -g's file) just fine, one caveat of being a suboption is that it cannot contain a comma, as that's the suboption separator.

As such, when passing dynamic values, I'd recommend using the -i flag instead (and quoting the arg). The redundancy in functionality exists purely to circumvent the comma limitation of the suboption approach .
NiLuJe is offline   Reply With Quote
Advert
Old 04-22-2020, 06:10 PM   #6
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
Quote:
Originally Posted by NiLuJe View Post
Huh. Does the file (the kernel module, I mean) actually exist on your device? (It's not in the FW package, and it should definitely not be here at all from my understanding of the kernel config...).
Stupid but obvious remark: make sure you're actually running the updated version of the script .
I will double check tomorrow on both devices (3.19 vs. 4.20) but I‘m quite sure I navigated to the directory and the file was there.


Quote:
Other than that, some general remarks: set -xeo pipefail, curly braces, quoting, shellcheck, check FBInk's output, and given set -x: check the output, period .
Thanks for this hint - I corrected some flaws and further simplified the script for testing. Just outputting date, no image. Letting this run overnight and will report back.

Kind regards
KristianR
KristianR is offline   Reply With Quote
Old 04-22-2020, 06:14 PM   #7
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
@KristianR: Huh. Yeah, I'd be glad to know if there's a difference on that front between the two (assuming the "old" one was downgraded via a full, proper factory reset).

That should point out whether earlier firmwares used to ship it as a module. It's mildly unlikely though, because the kernel sources are old, never updated, and were already making it a builtin :s.

(I suppose earlier FW could have mistakenly shipped an incompatible Mk. 5 module, on the other hand).
NiLuJe is offline   Reply With Quote
Old 04-22-2020, 06:19 PM   #8
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
In the meantime, here's take two on the USBNet script issue .
NiLuJe is offline   Reply With Quote
Old 04-23-2020, 10:14 AM   #9
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
Quote:
Originally Posted by NiLuJe View Post
@KristianR: Huh. Yeah, I'd be glad to know if there's a difference on that front between the two (assuming the "old" one was downgraded via a full, proper factory reset).
...
I will have a look as soon as the script broke the next time.

So far concerning the "history" of both devices:
- Kobo1 (FW 3.19.xx): Bought new several years ago. Definitively unwillingly updated to a 4.x-SW. Downgraded to 3.19.x by executing the according KoboRoot.tgz (no Factory reset).

Just checked: file is there
"-rw-r--r-- 1 root root 45074 Dec 31 2015 arcotg_udc.ko"

modinfo: can't open '/lib/modules/3.0.35+/modules.dep': No such file or directory



- Kobo4 (FW 4.20.xx): Bought used recently. Had a 2.x on it with which I was not able to register (Wifi broke all the time). Did a factory reset. Ran the 3.19.x KoboRoot.tgz, was able to connect to wifi, registered and got updated to current 4.20.xx

Just checked: file is there
"-rw-r--r-- 1 root root 45074 Dec 31 2015 arcotg_udc.ko"

modinfo: can't open '/lib/modules/3.0.35+/modules.dep': No such file or directory


Quote:
In the meantime, here's take two on the USBNet script issue
This one worked
And after installing RNDIS-driver I was able to connect to the device.


Now to further debugging whats going wrong:
RTCWAKE appears not to work while connected via USBNet (error message: short write). So I connected to the Kobo via wifi, toggled USBNet to on (cable detached) and started the script via wifi. Hoping to be able to connect later as soon as the script stops ...


Below are the last two cycles of the script execution last night (copied from nohup.out):
This was the last loop that went OK
Code:
+ date
+ hwclock
+ echo Next loop started at Thu Apr 23 03:58:07 CEST 2020 / Thu Apr 23 01:58:07 2020  0.000000 seconds
Next loop started at Thu Apr 23 03:58:07 CEST 2020 / Thu Apr 23 01:58:07 2020  0.000000 seconds
+ sleep 1
+ ps -a
PID   USER     TIME   COMMAND
    1 root       0:00 init
    2 root       0:00 [kthreadd]
    3 root       0:08 [ksoftirqd/0]
    4 root       0:00 [kworker/0:0]
    6 root       0:00 [khelper]
   44 root       0:00 [GPIOFN]
  139 root       0:00 [sync_supers]
  141 root       0:00 [bdi-default]
  143 root       0:00 [kblockd]
  184 root       0:00 [khubd]
  195 root       0:00 [irq/395-ricoh61]
  330 root       0:00 [swapper]
  332 root       0:00 [usb_wakeup thre]
  341 root       0:00 [kswapd0]
  342 root       0:00 [ksmd]
  401 root       0:00 [fsnotify_mark]
  414 root       0:00 [crypto]
  426 root       0:00 [EPDC Submit]
  427 root       0:00 [EPDC Interrupt]
  428 root       0:00 [EPDC AA]
  452 root       0:00 [tps65185_PWRGOO]
  458 root       0:00 [tps65185_INT]
  483 root       0:00 [kapmd]
  543 root       0:00 [ricoh61x_factor]
  551 root       0:00 [ricoh61x_batter]
  552 root       0:00 [r5t61x_charger_]
  585 root       0:01 [kinteractiveup]
  587 root       0:00 [mmcqd/0]
  593 root       0:00 [jbd2/mmcblk0p1-]
  594 root       0:00 [ext4-dio-unwrit]
  601 root       0:00 [flush-179:0]
  621 root       0:00 /sbin/udevd -d
  628 root       0:00 [kworker/0:0]
  644 messageb   0:00 /bin/dbus-daemon --system
  645 root       0:00 /bin/dbus-daemon --session --print-address --fork
  654 root       0:00 /sbin/getty -L ttymxc0 115200 vt100
  655 root       0:00 /bin/busybox inetd -f /etc/inetd.conf
 1014 root       0:00 syslogd -C500 -S
 1016 root       0:00 {sickel-launcher} /bin/sh /usr/local/Kobo/sickel-launcher.sh
 1017 root       0:00 /usr/local/Kobo/sickel -platform kobo:noscreen
 1084 root       0:00 {fickel-launcher} /bin/sh /usr/local/Kobo/fickel-launcher.sh
 1085 root       0:00 /usr/local/Kobo/fickel -platform kobo:noscreen
 1141 root       0:01 /libexec/dhcpcd-dbus
 1160 root       0:00 dhcpcd -d
 1179 root       0:00 {busybox} telnetd -l /bin/login -i
 1180 root       0:00 -sh
 1547 root       0:00 [kworker/0:1]
 1574 root       0:03 {loop.sh} /bin/sh ./loop.sh
 1634 root       0:06 [kworker/u:1]
 1647 root       0:00 [kworker/u:4]
 2261 root       0:01 [kworker/u:2]
 2568 root       0:00 [kworker/u:0]
 2588 root       0:00 ps -a
+ let loopcount=82+1
+ echo Loop Number: 83
Loop Number: 83
+ date
+ fbink Thu Apr 23 03:58:08 CEST 2020 / Loop: 83
[FBInk] Detected a Kobo Glo HD (371 => Alyssum @ Mark 6)
[FBInk] Clock tick frequency appears to be 100 Hz
[FBInk] Screen density set to 300 dpi
[FBInk] Variable fb info: 1072x1448, 16bpp @ rotation: 3 (Counter Clockwise, 270°)
[FBInk] Fontsize set to 24x24 (IBM base glyph size: 8x8)
[FBInk] Line length: 44 cols, Page size: 60 rows
[FBInk] Vertical fit isn't perfect, shifting rows down by 4 pixels
[FBInk] Fixed fb info: ID is "mxc_epdc_fb", length of fb mem: 6782976 bytes & line length: 2176 bytes
[FBInk] Pen colors set to #000000 for the foreground and #FFFFFF for the background
Printing string 'Thu Apr 23 03:58:08 CEST 2020 / Loop: 83' @ column 0 + 0px, row 0 + 0px (overlay: N, no BG: N, no FG: N, inverted: N, flashing: N, centered: N, halfway: N, left padded: N, right padded: N, clear screen: N, waveform: AUTO, dithering: PASSTHROUGH, nightmode: N, skip refresh: N, font: 0, font scaling: x0)
Next line should start @ row 1
+ free
             total         used         free       shared      buffers
Mem:        508068       117992       390076            0         4024
-/+ buffers:             113968       394100
Swap:            0            0            0
+ sleep 5
+ rtcwake -m mem -s 180
wakeup from "mem" at Thu Apr 23 02:01:14 2020
+ sleep 5
+ true
+ echo
Here it just stops
Code:
+ date
+ hwclock
+ echo Next loop started at Thu Apr 23 04:01:19 CEST 2020 / Thu Apr 23 02:01:19 2020  0.000000 seconds
Next loop started at Thu Apr 23 04:01:19 CEST 2020 / Thu Apr 23 02:01:19 2020  0.000000 seconds
+ sleep 1
+ ps -a
PID   USER     TIME   COMMAND
    1 root       0:00 init
    2 root       0:00 [kthreadd]
    3 root       0:08 [ksoftirqd/0]
    4 root       0:00 [kworker/0:0]
    6 root       0:00 [khelper]
   44 root       0:00 [GPIOFN]
  139 root       0:00 [sync_supers]
  141 root       0:00 [bdi-default]
  143 root       0:00 [kblockd]
  184 root       0:00 [khubd]
  195 root       0:00 [irq/395-ricoh61]
  330 root       0:00 [swapper]
  332 root       0:00 [usb_wakeup thre]
  341 root       0:00 [kswapd0]
  342 root       0:00 [ksmd]
  401 root       0:00 [fsnotify_mark]
  414 root       0:00 [crypto]
  426 root       0:00 [EPDC Submit]
  427 root       0:00 [EPDC Interrupt]
  428 root       0:00 [EPDC AA]
  452 root       0:00 [tps65185_PWRGOO]
  458 root       0:00 [tps65185_INT]
  483 root       0:00 [kapmd]
  543 root       0:00 [ricoh61x_factor]
  551 root       0:00 [ricoh61x_batter]
  552 root       0:00 [r5t61x_charger_]
  585 root       0:01 [kinteractiveup]
  587 root       0:00 [mmcqd/0]
  593 root       0:00 [jbd2/mmcblk0p1-]
  594 root       0:00 [ext4-dio-unwrit]
  601 root       0:00 [flush-179:0]
  621 root       0:00 /sbin/udevd -d
  628 root       0:00 [kworker/0:0]
  644 messageb   0:00 /bin/dbus-daemon --system
  645 root       0:00 /bin/dbus-daemon --session --print-address --fork
  654 root       0:00 /sbin/getty -L ttymxc0 115200 vt100
  655 root       0:00 /bin/busybox inetd -f /etc/inetd.conf
 1014 root       0:00 syslogd -C500 -S
 1016 root       0:00 {sickel-launcher} /bin/sh /usr/local/Kobo/sickel-launcher.sh
 1017 root       0:00 /usr/local/Kobo/sickel -platform kobo:noscreen
 1084 root       0:00 {fickel-launcher} /bin/sh /usr/local/Kobo/fickel-launcher.sh
 1085 root       0:00 /usr/local/Kobo/fickel -platform kobo:noscreen
 1141 root       0:01 /libexec/dhcpcd-dbus
 1160 root       0:00 dhcpcd -d
 1179 root       0:00 {busybox} telnetd -l /bin/login -i
 1180 root       0:00 -sh
 1547 root       0:00 [kworker/0:1]
 1574 root       0:03 {loop.sh} /bin/sh ./loop.sh
 1634 root       0:06 [kworker/u:1]
 1647 root       0:00 [kworker/u:4]
 2261 root       0:01 [kworker/u:2]
 2568 root       0:00 [kworker/u:0]
 2599 root       0:00 ps -a
+ let loopcount=83+1
+ echo Loop Number: 84
Loop Number: 84
+ date
+ fbink Thu Apr 23 04:01:20 CEST 2020 / Loop: 84
[FBInk] Detected a Kobo Glo HD (371 => Alyssum @ Mark 6)
[FBInk] Clock tick frequency appears to be 100 Hz
[FBInk] Screen density set to 300 dpi
[FBInk] Variable fb info: 1072x1448, 16bpp @ rotation: 3 (Counter Clockwise, 270°)
[FBInk] Fontsize set to 24x24 (IBM base glyph size: 8x8)
[FBInk] Line length: 44 cols, Page size: 60 rows
[FBInk] Vertical fit isn't perfect, shifting rows down by 4 pixels
[FBInk] Fixed fb info: ID is "mxc_epdc_fb", length of fb mem: 6782976 bytes & line length: 2176 bytes
[FBInk] Pen colors set to #000000 for the foreground and #FFFFFF for the background
Printing string 'Thu Apr 23 04:01:20 CEST 2020 / Loop: 84' @ column 0 + 0px, row 0 + 0px (overlay: N, no BG: N, no FG: N, inverted: N, flashing: N, centered: N, halfway: N, left padded: N, right padded: N, clear screen: N, waveform: AUTO, dithering: PASSTHROUGH, nightmode: N, skip refresh: N, font: 0, font scaling: x0)
Next line should start @ row 1
+ free
             total         used         free       shared      buffers
Mem:        508068       117992       390076            0         4024
-/+ buffers:             113968       394100
Swap:            0            0            0
+ sleep 5
+ rtcwake -m mem -s 180
wakeup from "mem" at Thu Apr 23 02:04:26 2020
+ sleep 5

Last edited by KristianR; 04-23-2020 at 03:27 PM.
KristianR is offline   Reply With Quote
Old 04-23-2020, 12:12 PM   #10
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
Okay, so that simply appears to be rtcwake (or the actual rtc) screwing the pooch (i.e., it suspends, but never wakes up).

Unfortunately, I don't think I have a better option for you than basically rewriting the suspend and rtc code yourself, which is... non trivial (c.f., KOReader & Plato for viable implementations of said madness).
Alternatively, you *could* try with a real rtcwake binary cross-compiled (or pulled from Debian) from util-linux instead of the old busybox version Kobo is shipping.
NiLuJe is offline   Reply With Quote
Old 04-23-2020, 03:59 PM   #11
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
Concerning the Kernel-Module I edited my last post above. Both times module is present. If you like I can do a factory reset and have a look afterwards.


I managed to connect to the device after the script stopped this evening. Strange enough once again at loop 84

Code:
Loop Number: 84
+ date
+ fbink Thu Apr 23 17:46:38 CEST 2020 / Loop: 84
[FBInk] Detected a Kobo Glo HD (371 => Alyssum @ Mark 6)
[FBInk] Clock tick frequency appears to be 100 Hz
[FBInk] Screen density set to 300 dpi
[FBInk] Variable fb info: 1072x1448, 16bpp @ rotation: 3 (Counter Clockwise, 270°)
[FBInk] Fontsize set to 24x24 (IBM base glyph size: 8x8)
[FBInk] Line length: 44 cols, Page size: 60 rows
[FBInk] Vertical fit isn't perfect, shifting rows down by 4 pixels
[FBInk] Fixed fb info: ID is "mxc_epdc_fb", length of fb mem: 6782976 bytes & line length: 2176 bytes
[FBInk] Pen colors set to #000000 for the foreground and #FFFFFF for the background
Printing string 'Thu Apr 23 17:46:38 CEST 2020 / Loop: 84' @ column 0 + 0px, row 0 + 0px (overlay: N, no BG: N, no FG: N, inverted: N, flashing: N, centered: N, halfway: N, left padded: N, right padded: N, clear screen: N, waveform: AUTO, dithering: PASSTHROUGH, nightmode: N, skip refresh: N, font: 0, font scaling: x0)
Next line should start @ row 1
+ free
             total         used         free       shared      buffers
Mem:        508068       118076       389992            0         3968
-/+ buffers:             114108       393960
Swap:            0            0            0
+ sleep 5
+ rtcwake -m mem -s 180
wakeup from "mem" at Thu Apr 23 15:49:44 2020
+ sleep 5
Either the device was still up or woken by plugging the cable. I called dmesg but this only contained the following info. Despite dmesg is there a way to access additional logs (syslog appears to be running, but nothing gets written to .kobo or /var/log ...).
Code:
...
PMU: mainFlowOfLowVoltage :	No9 :Cap is 6286 , low_rate is 55, dsoc is 5483, capnow is 6300, capzero is 64, delta cc is -1, delta cc ori is -2
PMU: mainFlowOfLowVoltage :	No10 :temp_mas is -240, offset_mas is -54, value is -110, final value is -1
PMU : set_current_time2register : second is 1587667876, hour is 441018
PMU:STATUS= 7: IBAT= -20: VSYS= 3893000: VBAT= 3893725: DSOC= 5483: RSOC= 5400: cc_delta=99: rrf= 0
PMU: mainFlowOfLowVoltage :	Noxx : cc_delta_cap is -1, cc_delta_cap_now is -309, last_cc_delta_cap is -308
PMU: mainFlowOfLowVoltage :	Noxx : temp_cc_delta_cap is 0, after temp_cc_delta_cap_mas is -240, cc_cap_mas -168051
PMU: mainFlowOfLowVoltage :	No9 :Cap is 6326 , low_rate is 54, dsoc is 5483, capnow is 6340, capzero is 64, delta cc is 0, delta cc ori is -1
PMU: mainFlowOfLowVoltage :	No10 :temp_mas is -533, offset_mas is -293, value is -54, final value is 0
PMU : set_current_time2register : second is 1587667906, hour is 441018
PMU:STATUS= 7: IBAT= -20: VSYS= 3893000: VBAT= 3896200: DSOC= 5483: RSOC= 5400: cc_delta=99: rrf= 0
otg udc vbus falling wakeup
try_wake_up_udc: udc out low power mode
PMU:charger_adp_isr
PMU:charger_usb_isr
PMU:charger_in_isr
PMU:charger_irq_work In
charger_irq_work : val = 1 plug in ADPt
g_ether gadget: high speed config #2: RNDIS
usb plugged 1-0
PMU:charger_irq_work Out
PMU: mainFlowOfLowVoltage :	Noxx : cc_delta_cap is 11, cc_delta_cap_now is -298, last_cc_delta_cap is -309
PMU: mainFlowOfLowVoltage :	Noxx : temp_cc_delta_cap is 0, after temp_cc_delta_cap_mas is -533, cc_cap_mas -162090
PMU FG_RESET : calc_capacity : capacity 52 init_pswr 55 cc_delta -298
PMU FG_RESET : calc_capacity_2 : capacity 5202 init_pswr 55 cc_delta -298
PMU : set_current_time2register : second is 1587667935, hour is 441018
PMU calc_capacity_in_period 1%FACAP(54360)[mAs], cc_sum(162090)[mAs], cc_sum_dec(-53370)
PMU calc_capacity_in_period Half-Clear CC, cc_sum is over 1%
...
KristianR is offline   Reply With Quote
Old 04-23-2020, 04:50 PM   #12
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
@KristianR: Nah, don't bother with a factory reset, it's probably leftover from earlier FWs, and you've confirmed that the current approach taken in the script works anyway, thanks .

----

The syslog is a ringbuffer that you can access via logread. I'd recommend enabling developper settings (search for devmodeon), and ticking a few extra things in the logging section of the dev menu (I *think* one of those concerns rtc).

I think @geek1011 mentioned issues with Nickel potentially periodically taking over the rtc when he was dealing with larger values for the default counters, something similar may be happening here.
(Obvious solution would be to try with nickel & friends killed, but that's obviously counter-productive to your goals here ^^).

If the process is still up, you could try attaching to it via strace, seeing what it's locked on might be interesting .
NiLuJe is offline   Reply With Quote
Old 04-24-2020, 02:00 PM   #13
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
rtcwake does not appear to be the culprit here.

In addition to nickel and hindenburg, this time I also killed fickel and sickel.

I started a second script in parallel that was monitoring via "pgrep" if the script loop.sh was still running. If not it called dmesg and restarted the script.

Once again script loop.sh broke after 84 cycles. According to dmesg-Output it appears that suspend and resume went fine (output see below).

After loop.sh was restarted by the monitoring script it ran for more than 150 cycle before I stopped it.

What I do right now is starting the loop.sh from another script (killing nickel and friends, changing directory, and starting the script with "nohup ./loop.sh &" - usually I started from the console without the "&") - this instance right now is at cycle 174 without breaking.

Is there a difference in calling nohup from the console or from another script - or is it important to immediately send nohup to backround with "&"?



Code:
ricoh619 2-0032: PMU: print_time *** rtc-time : 4/24/2020 13:58:22 *****
PMU: ricoh61x_rtc_alarm_enable :1
PMU: ricoh61x_rtc_alarm_enable :1
cpufreq_save_default_governor():save policy "interactive"
cpufreq_set_governor():set policy "performance"
PM: Syncing filesystems ... done.
PM: Preparing system for mem sleep
Freezing user space processes ... freeze 1!!!!!!!!!!!!!!!!!!!!
(elapsed 0.01 seconds) done.
Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
PM: Entering mem sleep
Suspending console(s) (use no_console_suspend to debug)
udc suspend begins
USB Gadget suspend ends
PMU: ricoh61x_battery_suspend START ================================================================================
ricoh619-battery ricoh619-battery: sleep entry time : 1587736671 secs
PMU: cc_sum = 119: cc_cap_res= 23: cc_cap_mas = -1687126528
PMU: cc_cap_offset= 23: 
PMU : ricoh61x_battery_suspend : Suspend : temp_cc_delta_cap_mas is -874, cc_delta is 119, last_cc_delta_cap_mas is 459
PMU FG_RESET : calc_capacity_2 : capacity 9100 init_pswr 91 cc_delta 0
PMU: ricoh61x_battery_suspend status(7), rrf(0), suspend_soc(9144), suspend_cc(0)
PMU: ricoh61x_battery_suspend DSOC(9144), init_pswr(91), cc_delta(0)
PMU : set_current_time2register : second is 1587736671, hour is 441037
PMU FG_RESET : calc_capacity_2 : capacity 9100 init_pswr 91 cc_delta 0
PMU: ricoh61x_battery_suspend : STATUS(7), DSOC(9144), RSOC(9100), init_pswr*100(9100), cc_delta(0) ====================
PMU: ricoh61x_battery_suspend : fl_current(0), slp_state(0), sus_current(1900), hiber_current(889)
PM: suspend of devices complete after 97.951 msecs
PM: late suspend of devices complete after 0.269 msecs
PM: early resume of devices complete after 0.139 msecs
PMU: ricoh61x_rtc_alarm_enable :0
PMU: ricoh61x_battery_resume START ================================================================================
ricoh619-battery ricoh619-battery: sleep exit time : 1587736702 secs
PMU : ricoh61x_battery_resume : 	suspend_period_time is 31, sleepExitTime is 1587736702 sleepEntryTime is 1587736671 ==========
PMU calc_capacity_in_period 1%FACAP(54360)[mAs], cc_sum(213)[mAs], cc_sum_dec(-213)
PMU: ricoh61x_battery_resume : Discharge Processing (rrf=0)
PMU : calc_cc_value_by_sleepPeriod : delta_cap is 479100 [uAs], Period is 31 [s], fa_cap is 1510 [mAh], delta_soc is 0 [0.01%], offset is 479100 [uAs]
PMU: calc_soc_by_currentMethod Suspend(S/W) slp_current(1900), sus_current(1900), fl_current(0), cc_delta(0) ----------
PMU : calc_soc_by_currentMethod : slp_state is 0, soc is 9144 [0.01%]  ----------
PMU : calc_soc_by_voltageMethod : VBAT is 4109800 [uV], soc is 9900 [0.01%] ----------
PMU: ricoh61x_battery_resume : soc_current(9144), soc_voltage(9900), Diff(-756) ==========
PMU: update_rsoc_on_currentMethod : Current Method. state(7), dsoc(9144), rsoc(9100), init_pswr(91), cc_delta(0) ----------
PMU FG_RESET : calc_capacity : capacity 91 init_pswr 91 cc_delta 0
PMU:check_charge_status_2 Resume Sus_soc(9144), cc(0)
PMU : set_current_time2register : second is 1587736702, hour is 441037
PMU FG_RESET : calc_capacity_2 : capacity 9100 init_pswr 91 cc_delta 0
PMU: ricoh61x_battery_resume : STATUS(7), DSOC(9144), RSOC(9100), init_pswr*100(9100), cc_delta(0) ====================
USB Gadget resume begins
fsl_udc_resume, Wait for wakeup thread finishes
dr_controller_run: udc enter low power mode 
USB Gadget resume ends
PM: resume of devices complete after 294.863 msecs
PM: Finishing wakeup.
Restarting tasks ... done.
cpufreq_set_governor():set policy "interactive"
cpufreq_restore_default_governor():restore policy "interactive"
PMU: ricoh61x_rtc_alarm_enable :0
drivers/input/keyboard/tle4913_keypad.c(79): gpio140,val=1
PMU: mainFlowOfLowVoltage :	Noxx : cc_delta_cap is -1, cc_delta_cap_now is 0, last_cc_delta_cap is 0
PMU: mainFlowOfLowVoltage :	Noxx : temp_cc_delta_cap is -1, after temp_cc_delta_cap_mas is -331, cc_cap_mas 457
PMU: mainFlowOfLowVoltage :	No9 :Cap is 9269 , low_rate is 88, dsoc is 9144, capnow is 9280, capzero is 61, delta cc is 0, delta cc ori is -1
PMU: mainFlowOfLowVoltage :	No10 :temp_mas is -809, offset_mas is -478, value is -88, final value is 0
PMU : set_current_time2register : second is 1587736703, hour is 441037
PMU:STATUS= 7: IBAT= -7: VSYS= 4054000: VBAT= 4109800: DSOC= 9144: RSOC= 9100: cc_delta=0: rrf= 0
TPS65185 temprature data = 0x15,21
KristianR is offline   Reply With Quote
Old 04-24-2020, 04:07 PM   #14
NiLuJe
BLAM!
NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.NiLuJe ought to be getting tired of karma fortunes by now.
 
NiLuJe's Avatar
 
Posts: 11,984
Karma: 21222282
Join Date: Jun 2010
Location: Paris, France
Device: Kindle 2i, 3g, 4, 5w, PW & PW2; Kobo H2O, Forma & Elipsa
IIRC, nohup has a number of weird and interesting quirks, and it generally doesn't do what people think it does . (By which I mean, emulating daemon() in shell takes quite a bit more effort than that).

This might be doubly true for the ancient version shipped in Kobo's busybox version.

bb's up to date source (https://git.busybox.net/busybox/tree/coreutils/nohup.c) helpfully points out an example which definitely sends it to bg, which is what I naively assumed you were doing (or launching it via something that effectively meant the same thing in practice).

----

That said, I still wouldn't recommend sending any kind of long-running script's output to disk, especially somewhere under /mnt/sd or /mnt/onboard, as that can and will go down during an USBMS session.

(Note that HOME is stupidly / in Kobo's ash, which is also very much not great).

Last edited by NiLuJe; 04-24-2020 at 04:12 PM.
NiLuJe is offline   Reply With Quote
Old 04-24-2020, 04:50 PM   #15
KristianR
Member
KristianR began at the beginning.
 
Posts: 17
Karma: 10
Join Date: Feb 2016
Device: none
So - a missing Ampersand kept me busy for a while
Always thought this was optional with nohup.

@NiLuJe: Thank you very much for your patience, support and valuable input

Kind regards
KristianR

Last edited by KristianR; 04-24-2020 at 04:52 PM.
KristianR is offline   Reply With Quote
Reply

Thread Tools Search this Thread
Search this Thread:

Advanced Search

Forum Jump

Similar Threads
Thread Thread Starter Forum Replies Last Post
rtcwake on Kobo? z000ao8q Kobo Developer's Corner 77 02-15-2021 12:44 AM
max. time for rtc1 by using rtcwake mdauso Kindle Developer's Corner 4 02-19-2020 04:59 AM
AFTER THE EXECUTION jpraven Self-Promotions by Authors and Publishers 0 10-31-2013 03:30 AM
Direct shellscript execution Viacheslav iRex 0 08-25-2009 01:31 PM
iLiad QT/E execution problem! ericshliao iRex Developer's Corner 7 02-12-2009 03:36 PM


All times are GMT -4. The time now is 12:13 PM.


MobileRead.com is a privately owned, operated and funded community.