Supposed to be fixed in 3.2.8, see:
2 Likes
Encountered a strange bug/issue:
tried to search Web Catalog, which couldnt connect or had some other issue, just saw the spinner on blank page, after a short time (~60 sec ?), spinner froze, display went black and wouldnt recover until (systemd was also “dead”, systemctl or journalctl commands didnt respond at all):
[defaultuser@Fairphone4 Project]$ ps auxww|grep patch
1312 root /usr/sbin/patchmanager --daemon
11734 root {rich-core-dumpe} /bin/bash /usr/sbin/rich-core-dumper --pid=1312 --signal=6 --name=patchmanager
12110 defaultu grep patch
[defaultuser@Fairphone4 Project]$ devel-su kill -9 11734 1312
afterwards display immediately turned on and everything is working as expected
1 Like
I’m not familiar with rich-core-dumper - how does it get activated? Is it a hint that something segfaulted?
I dont know, i only have partial dmesg output, but cant see anything strange (but not sure), (edit: was useless)
so:
rich-core-dumper is basically just a huge shell script, which gets executed by helper binary (setuid binary probably only there to allow the shell running as root)
one symlink is broken, but if thats the issue not sure, service unit seems working fine
/run/systemd/units/invocation:rich-core-early-collect.service: broken symbolic link to 158bce77036d49ba94db5b8ca357e12b
/usr/lib/systemd/system/graphical.target.wants/rich-core-early-collect.service: symbolic link to ../rich-core-early-collect.service
/usr/lib/systemd/system/rich-core-early-collect.service: ASCII text
/usr/lib/startup/preinit/late.d/rich-core-preinit: POSIX shell script, ASCII text executable
/usr/lib/sysctl.d/sp-rich-core.conf: ASCII text
/usr/libexec/rich-core-helper: setuid ELF 64-bit LSB executable, ARM aarch64, version 1 (SYSV), dynamically linked, interpreter /lib/ld-linux-aarch64.so.1, BuildID[sha1]=3d55833a001b9bde3352a1549d94effe38524a7d, for GNU/Linux 3.7.0, stripped
/usr/libexec/rich-core-check-oneshot: POSIX shell script, ASCII text executable
/usr/share/licenses/sp-rich-core-1.75.0: directory
/usr/sbin/rich-core-dumper: Bourne-Again shell script, ASCII text executable
[defaultuser@Fairphone4 ~]$ systemctl --no-pager status rich-core-early-collect.service
● rich-core-early-collect.service - Collects system logs early after boot if error conditions are detected.
Loaded: loaded (/usr/lib/systemd/system/rich-core-early-collect.service; disabled; vendor preset: enabled)
Active: active (exited) since Mon 2025-11-24 23:28:21 CET; 10h ago
Process: 5488 ExecStart=/bin/touch /tmp/richcore-early-collect-mark (code=exited, status=0/SUCCESS)
Process: 5484 ExecStart=/bin/sh -c grep "Shutdown:" /var/log/systemboot.log | tail -n1 | grep -qi "overheat" && /usr/sbin/rich-core-dumper --name=OverheatShutdown --signal=$RANDOM (code=exited, status=1/FAILURE)
Process: 5471 ExecStart=/usr/libexec/rich-core-check-oneshot (code=exited, status=0/SUCCESS)
Process: 5467 ExecStart=/bin/sh -c STATUS=$(/bin/sed -n "s|.*reset=kernel_wdt\([^ ]*\).*|HWreboot|p" /proc/cmdline) && /usr/bin/test -n "$STATUS" && /usr/sbin/rich-core-dumper --name=$STATUS --signal=$RANDOM (code=exited, status=1/FAILURE)
Process: 5464 ExecStart=/bin/sh -c STATUS=$(/bin/sed -n "s|.*pwr_on_status=pwr_on_by_HW_\([^ ]*\).*|HW\1|p" /proc/cmdline) && /usr/bin/test -n "$STATUS" && /usr/sbin/rich-core-dumper --name=$STATUS --signal=$RANDOM (code=exited, status=1/FAILURE)
Process: 5371 ExecStartPre=/usr/lib/startup/wait-for-file /run/user-session/post-user-init-done.flag (code=exited, status=0/SUCCESS)
Main PID: 5488 (code=exited, status=0/SUCCESS)
after checking the conf file:
privacy-notice-accepted=false
it should abort early? according to this:
# If the user hasn't agreed to the privacy notice abort here.
if [ x"${privacy_notice_accepted}" = x"false" ]; then
_log_msg "rich-core: privacy notice not accepted - not dumping"
exit
fi
But maybe then this is causing some issues? (if the setuid helper starts the script it runs as pid 0 ?)
# If dumping is disabled in settings, don't bother going further. However, the
# setting is overriden if this dump was invoked with PID 0, meaning only logs
# are collected, or the process was killed by SIGQUIT, which means user
# explicitly requested its termination from quick-feedback application.
if [ x"${coredumping}" = x"false" ] && { [ ! $core_pid -eq 0 ] || [ $core_sig -eq 3 ]; }; then
cat > /dev/null
exit
fi
1 Like
Thanks for the research. It’s a bit hard to triage this after the fact.
Now, while it’s quite possible that the PM crashed, and also possible for them to take Lipstick down (–> black screen), this really shouldn’t make the system unresponsive or even systemd not react any more.
What I believe may be the case here is that the rich core dumper collection resulted in a heavy IO, possibly OOM situation.
If that rich-core dumping tool
a) does not set the NO_PM_PRELOAD=1 variable (which disables the patchmanager preload) - and there’s no reason to believe it does
b) does not allow the patchmanager daemon to restart or otherwise act until it’s finished it collecting
this could cause lots of tries by the preload library to contact the daemon (it’s asking whether there are any patched files accessed), which may fail or deadlock.
Not sure what exactly happens in the kernel in such a situation, but I guess things like an overly long wait queue, very high loadavg while no or little CPU is being used and so on.
Which could explain what you are describing, black screen, some services not responding, but otherwise responsive system.
All this is a pure theory however.
In case you ever see this again, could you gather some info about:
- memory usage
- load averages
- queues
- top CPU and I/O processes?
basically what the dstat --load --cpu --page --disk --top-cpu --top-io --top-mem' tool shows.
1 Like
if i encounter this bug again and have ssh connection i’ll try to get more infos, should have at least checked top to see cpu and mem usage, but I always forget that busybox ps is very minimal and ps auxww is useless there (else it would show at least cpu and mem usage)
2 Likes
bug is currently occuring again, unfortunately I cant connect to phone
ssh just hangs, display wont turn on
$ ssh defaultuser@192.168.2.106
ssh: connect to host 192.168.2.106 port 22: Connection timed out
if you encounter this and arent already connected via ssh, no way to gain access to the device
$ ssh defaultuser@192.168.2.106
kex_exchange_identification: read: Software caused connection abort
banner exchange: Connection to 192.168.2.106 port 22: Software caused connection abort
edit:
also openrepos certificate expired again, maybe its related (this time)?
Problem retrieving files from 'openrepos-flypig'.
Download (curl) error for 'https://sailfish.openrepos.net/flypig/personal/main/repodata/repomd.xml':
Error code: Curl error 60
Error message: SSL certificate problem: certificate has expired
triggered again:
screen wont turn on:
top normal:
[defaultuser@Fairphone4 mednafen]$ top -bn 1|head -n 50
Mem: 4507344K used, 1128056K free, 319984K shrd, 179064K buff, 1790384K cached
CPU: 1.1% usr 1.1% sys 0.0% nic 97.7% idle 0.0% io 0.0% irq 0.0% sirq
Load average: 0.39 3.90 3.48 2/1699 9027
PID PPID USER STAT VSZ %VSZ CPU %CPU COMMAND
2149 1232 system S 10.5g197.1 0 0.7 {sensors@2.0-ser} /vendor/bin/hw/android.hardware.sensors@2.0-service.multihal
9026 41139 defaultu R 3580 0.0 7 0.7 top -bn 1
508 2 root SW 0 0.0 2 0.7 [crtc_event:110]
2468 1232 radio S 11.9g221.9 4 0.0 {main} /vendor/bin/hw/qcrild
2578 1232 radio S 11.7g218.7 7 0.0 {main} /vendor/bin/hw/qcrild -c 2
9947 1232 camerase S 11.4g212.2 5 0.0 {provider@2.4-se} /vendor/bin/hw/android.hardware.camera.provider@2.4-service_64
2400 1232 root S< 11.4g212.0 2 0.0 /vendor/bin/thermal-engine
2136 1232 system S 11.3g211.1 7 0.0 /vendor/bin/ssgtzd
2402 1232 radio S 11.2g208.3 2 0.0 /system/vendor/bin/netmgrd
2365 1232 media S 10.9g203.9 0 0.0 /usr/libexec/droid-hybris/system/bin/minimediaservice
2144 1232 gps S 10.9g203.1 0 0.0 {gnss@2.1-servic} /vendor/bin/hw/android.hardware.gnss@2.1-service-qti
2413 1232 mediacod S 10.9g203.0 2 0.0 {binder:2413_2} media.swcodec oid.media.swcodec/bin/mediaswcodec
7975 1232 system S 10.7g199.2 6 0.0 {composer-servic} /vendor/bin/hw/vendor.qti.hardware.display.composer-service
3878 1232 radio S 10.6g198.0 6 0.0 /vendor/bin/ims_rtp_daemon
2964 1232 radio S 10.6g197.7 0 0.0 /vendor/bin/imsdatadaemon
2389 1232 system S 10.6g197.5 2 0.0 /system/vendor/bin/cnd
2213 1232 root S 10.5g196.7 3 0.0 {perf@2.2-servic} /vendor/bin/hw/vendor.qti.hardware.perf@2.2-service
2146 1232 system S 10.5g196.2 1 0.0 {neuralnetworks@} /vendor/bin/hw/android.hardware.neuralnetworks@1.3-service-qti
3024 1232 system S 10.5g195.6 4 0.0 /vendor/bin/hvdcp_opti
2366 1232 system S 10.5g195.3 7 0.0 /usr/libexec/droid-hybris/system/bin/minisfservice
1300 1232 system S 10.5g195.3 6 0.0 {suspend-service} /system/bin/hw/android.system.suspend-service
1278 1232 system S 10.4g194.8 3 0.0 /vendor/bin/qseecomd
3888 1232 radio S 10.4g194.8 6 0.0 /vendor/bin/imsrcsd
1301 1232 keystore S 10.4g194.8 6 0.0 {binder:1301_2} /system/bin/keystore2 /data/misc/keystore
2232 1232 credstor S 10.4g194.8 6 0.0 /system/bin/credstore /data/misc/credstore
1782 1232 radio S 10.4g194.8 6 0.0 /system/vendor/bin/ipacm
2643 2420 gps S 10.4g194.5 7 0.0 lowi-server
2875 1232 system S 10.4g194.3 2 0.0 /system/vendor/bin/dpmQmiMgr
2660 1232 radio S 10.4g194.2 3 0.0 /system/vendor/bin/adpl
[defaultuser@Fairphone4 mednafen]$ dool --help
^C
[defaultuser@Fairphone4 mednafen]$ dstat --load --cpu --page --disk --top-cpu --top-io --top-mem'
> ^C
[defaultuser@Fairphone4 mednafen]$ dstat --load --cpu --page --disk --top-cpu --top-io --top-mem
^C
dstat or other commands did not work
[defaultuser@Fairphone4 mednafen]$ pgrep rich
8722
[defaultuser@Fairphone4 mednafen]$ kill -9 8722
bash: can't kill pid 8722: Operation not permitted
[defaultuser@Fairphone4 mednafen]$ devel-su kill -9 8722
kill rich-core.dumper, everything works again
[defaultuser@Fairphone4 mednafen]$ dstat --load --cpu --page --disk --top-cpu --top-io --top-mem
┄┄┄load┄avg┄┄┄┬┄┄total┄cpu┄usage┄┄┬┄┄┄paging┄┄┬┄dsk/total┄┬┄most┄expensive┄┬┄┄┄┄┄┄┄┄top-io┄┄┄┄┄┄┄┄┬┄┄most┄expensive┄
1m 5m 15m │usr sys idl wai stl│ in out │ read writ│ cpu process │ name read writ│ memory process
0.18 1.70 2.65│ 5 8 87 0 0│4534B 14k│1322k 220k│lipstick 0.3│systemd 29k 2337B│lipstick 263M
1 Like
Hi, thanks for reporting again and trying to debug!
It is clear that something is deeply wrong with the system when this occurs.
I am not convinced yet that Patchmanager has anything to do with it - although technically it is entirely possible that it does, or has some interaction with this rich-core-dumper tool that causes the issue.
But what we need here is a reproducer. We need to find a reliable, repeatable way to trigger this issue. I don’t see how it can be debugged otherwise.
1 Like
yes maybe a issue in the script (or the service which starts the script), I dont know, maybe next time it happens (if it happens again) I’m able to get some more info
I checked if there is some (rich-core) log created but unfortunately not
[defaultuser@Fairphone4 ~]$ ls -l /var/cache/core-dumps/|grep "Dec 23"
-rw-r--r-- 1 root root 434970 Dec 23 11:53 a.out-fp4-11-22412.rcore.lzo
-rw-r--r-- 1 root root 397521 Dec 23 10:31 android.hardware.audio.service-fp4-11-2137.rcore.lzo
-rw-r--r-- 1 root root 432767 Dec 23 10:32 android.hardware.camera.provider@2.4-service_64-fp4-6-2140.rcore.lzo
-rw-r--r-- 1 root root 420665 Dec 23 14:00 exec_cmd-fp4-11-13514.rcore.lzo
-rw-r--r-- 1 root root 430497 Dec 23 12:04 exec_cmd-fp4-11-38153.rcore.lzo
-rw-r--r-- 1 root root 407356 Dec 23 16:41 exec_cmd-fp4-11-4752.rcore.lzo
-rw-r--r-- 1 root root 404474 Dec 23 16:03 x64-fp4-11-47790.rcore.lzo
-rw-r--r-- 1 root root 401193 Dec 23 16:09 x64-fp4-11-48374.rcore.lzo
-rw-r--r-- 1 defaultu defaultu 2213694 Dec 23 16:09 x64-fp4-11-48772.rcore
-rw-r--r-- 1 root root 395906 Dec 23 16:09 x64-fp4-11-48772.rcore.lzo
-rw-r--r-- 1 root root 395545 Dec 23 16:14 x64-fp4-11-49224.rcore.lzo
-rw-r--r-- 1 root root 383822 Dec 23 16:18 x64-fp4-11-50001.rcore.lzo