The KiwiSDR 2 online store is open for orders! Please visit kiwisdr.nz
kiwid panic after 22 days
Hi,
One of my RXs had a kiwid panic this morning after 22 days uptime. It recovered OK. It seems to have been unable to allocate memory when a second user arrived while the first was using DRM.
From /var/log/syslog:
Sep 12 06:25:11 kiwisdr rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="446" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
Sep 12 06:53:54 kiwisdr systemd-timesyncd[231]: interval/delta/delay/jitter/drift 2048s/+0.001s/0.011s/0.002s/-72ppm
Sep 12 07:17:01 kiwisdr CRON[11705]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Sep 12 07:27:17 kiwisdr kiwid: 22d:12:21:19.387 01.. 1 3975.00 kHz am z8 "[User 1 IP redacted]" (ARRIVED)
Sep 12 07:28:02 kiwisdr systemd-timesyncd[231]: interval/delta/delay/jitter/drift 2048s/-0.000s/0.011s/0.002s/-72ppm
Sep 12 07:38:56 kiwisdr kiwid: 22d:12:32:58.041 01.. 1 3982.58 kHz drm z8 DRM "[User 1 IP redacted]" (LEAVING after 0:11:45)
Sep 12 07:39:34 kiwisdr kiwid: 22d:12:33:36.418 01.. 1 7100.00 kHz lsb z0 "[User 2 IP redacted]" [Location redacted] (ARRIVED)
Sep 12 07:39:35 kiwisdr kiwid: SYS_PANIC: "fork" Cannot allocate memory (support/non_block.cpp, line 123) Cannot allocate memory
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 0 0x8f7a4 /usr/local/bin/kiwid() [0x8f7a4]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 1 0x8f974 /usr/local/bin/kiwid() [0x8f974]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 2 0x919dc /usr/local/bin/kiwid() [0x919dc]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 3 0x91b60 /usr/local/bin/kiwid() [0x91b60]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 4 0x971a8 /usr/local/bin/kiwid() [0x971a8]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 5 0x8ccc4 /usr/local/bin/kiwid() [0x8ccc4]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 6 0xb698eae0 /lib/arm-linux-gnueabihf/libc.so.6(+0x26ae0) [0xb698eae0]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 7 0xb697f8e6 /lib/arm-linux-gnueabihf/libc.so.6(+0x178e6) [0xb697f8e6]
Sep 12 07:39:36 kiwisdr systemd[1]: kiwid.service: main process exited, code=exited, status=255/n/a
Sep 12 07:39:36 kiwisdr kiwid[12170]: DEBIAN 8
Sep 12 07:39:36 kiwisdr kiwid[12170]: USE_SPIDEV
Sep 12 07:39:36 kiwisdr kiwid[12170]: LOAD_SPI = no
Sep 12 07:39:36 kiwisdr kiwid[12170]: Stopping kiwid:
Sep 12 07:39:36 kiwisdr systemd[1]: Unit kiwid.service entered failed state.
Sep 12 07:39:46 kiwisdr kiwid[12191]: DEBIAN 8
Sep 12 07:39:46 kiwisdr kiwid[12191]: USE_SPIDEV
Sep 12 07:39:46 kiwisdr kiwid[12191]: LOAD_SPI = no
Sep 12 07:39:46 kiwisdr kiwid[12191]: Starting kiwid
Sep 12 07:39:47 kiwisdr kiwid[12191]: Start kiwid: OK
Sep 12 07:39:47 kiwisdr kiwid[12191]: Sat Sep 12 07:39:47 UTC 2020
Sep 12 07:39:47 kiwisdr kiwid: 00:00:00.739 KiwiSDR v1.402 --------------------------------------------------------------------
73,
Richard G4DYA
One of my RXs had a kiwid panic this morning after 22 days uptime. It recovered OK. It seems to have been unable to allocate memory when a second user arrived while the first was using DRM.
From /var/log/syslog:
Sep 12 06:25:11 kiwisdr rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="446" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
Sep 12 06:53:54 kiwisdr systemd-timesyncd[231]: interval/delta/delay/jitter/drift 2048s/+0.001s/0.011s/0.002s/-72ppm
Sep 12 07:17:01 kiwisdr CRON[11705]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Sep 12 07:27:17 kiwisdr kiwid: 22d:12:21:19.387 01.. 1 3975.00 kHz am z8 "[User 1 IP redacted]" (ARRIVED)
Sep 12 07:28:02 kiwisdr systemd-timesyncd[231]: interval/delta/delay/jitter/drift 2048s/-0.000s/0.011s/0.002s/-72ppm
Sep 12 07:38:56 kiwisdr kiwid: 22d:12:32:58.041 01.. 1 3982.58 kHz drm z8 DRM "[User 1 IP redacted]" (LEAVING after 0:11:45)
Sep 12 07:39:34 kiwisdr kiwid: 22d:12:33:36.418 01.. 1 7100.00 kHz lsb z0 "[User 2 IP redacted]" [Location redacted] (ARRIVED)
Sep 12 07:39:35 kiwisdr kiwid: SYS_PANIC: "fork" Cannot allocate memory (support/non_block.cpp, line 123) Cannot allocate memory
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 0 0x8f7a4 /usr/local/bin/kiwid() [0x8f7a4]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 1 0x8f974 /usr/local/bin/kiwid() [0x8f974]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 2 0x919dc /usr/local/bin/kiwid() [0x919dc]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 3 0x91b60 /usr/local/bin/kiwid() [0x91b60]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 4 0x971a8 /usr/local/bin/kiwid() [0x971a8]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 5 0x8ccc4 /usr/local/bin/kiwid() [0x8ccc4]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 6 0xb698eae0 /lib/arm-linux-gnueabihf/libc.so.6(+0x26ae0) [0xb698eae0]
Sep 12 07:39:35 kiwisdr kiwid: sys_panic: backtrace 7 0xb697f8e6 /lib/arm-linux-gnueabihf/libc.so.6(+0x178e6) [0xb697f8e6]
Sep 12 07:39:36 kiwisdr systemd[1]: kiwid.service: main process exited, code=exited, status=255/n/a
Sep 12 07:39:36 kiwisdr kiwid[12170]: DEBIAN 8
Sep 12 07:39:36 kiwisdr kiwid[12170]: USE_SPIDEV
Sep 12 07:39:36 kiwisdr kiwid[12170]: LOAD_SPI = no
Sep 12 07:39:36 kiwisdr kiwid[12170]: Stopping kiwid:
Sep 12 07:39:36 kiwisdr systemd[1]: Unit kiwid.service entered failed state.
Sep 12 07:39:46 kiwisdr kiwid[12191]: DEBIAN 8
Sep 12 07:39:46 kiwisdr kiwid[12191]: USE_SPIDEV
Sep 12 07:39:46 kiwisdr kiwid[12191]: LOAD_SPI = no
Sep 12 07:39:46 kiwisdr kiwid[12191]: Starting kiwid
Sep 12 07:39:47 kiwisdr kiwid[12191]: Start kiwid: OK
Sep 12 07:39:47 kiwisdr kiwid[12191]: Sat Sep 12 07:39:47 UTC 2020
Sep 12 07:39:47 kiwisdr kiwid: 00:00:00.739 KiwiSDR v1.402 --------------------------------------------------------------------
73,
Richard G4DYA
Comments
The backtrace is from the rx.kiwisdr.com registration process and has nothing to do (directly) with the second connection.
The DRM/Dream code was checked for memory leaks as much as was practical during porting. But assuming that code is at fault it's pretty much impossible to tell what's going on here. Dream is roughly 70k lines of C++ code and that doesn't include the FDK codec.
How many threads or subprocesses does kiwid use? I use them heavily, mainly to take better advantage of ubiquitous multi-core CPUs but also to make bugs and memory leaks easier to isolate and contain. At the very least, a short-lived thread will clean up its memory leaks when it exits, and an abnormal exit doesn't take the whole thing down.
The DRM decoder seems a natural candidate for a separate thread or process but my kiwisdr seems to be running just one big thread, kiwid. It consumes about 77% of a core. The only other task of note is spi1, consuming about 1%.
But the Beaglebone only seems to have one core anyway.