search

yo8192 / fcron

fcron is an advanced cron for Linux/Unix systems
http://fcron.free.fr
GNU General Public License v2.0
136 stars 13 forks source link

fcron (randomly?) fails running jobs after systemupdate #19

Closed castilma closed 6 months ago

castilma commented 2 years ago

Recently I noticed fcron to be unable to run jobs again, and I had to restart it.

2022-02-15 21:14:16  INFO fcron[961] 3.2.1 started
2022-02-15 21:14:16  INFO updating configuration from /var/spool/fcron
2022-02-15 21:14:16  INFO adding file mcd
2022-02-15 21:14:16  INFO adding file systab
2022-02-15 21:14:36  INFO Job '/usr/bin/run-parts --report /etc/cron.daily' started for user systab (pid 1124)
2022-02-15 21:15:00  INFO Job './backup/dns/doit; ./backup/dns/clean;' started for user mcd (pid 1157)
2022-02-15 21:15:00  INFO Job '~/backup/hausdok/doit' started for user mcd (pid 1160)
2022-02-15 21:15:01  INFO Job '~/backup/hausdok/doit' completed
2022-02-15 21:15:03  INFO Job './backup/dns/doit; ./backup/dns/clean;' completed
2022-02-15 21:15:47  INFO Job '/usr/bin/run-parts --report /etc/cron.daily' completed
2022-02-15 21:15:47  INFO Job '/usr/bin/run-parts /etc/cron.weekly' started for user systab (pid 1228)
2022-02-15 21:15:47  INFO Job '/usr/bin/run-parts /etc/cron.weekly' completed
2022-02-15 22:42:04 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-02-15 22:42:05 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-02-15 22:42:06 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-02-15 22:42:07 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-02-15 23:01:40 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-02-15 23:01:41 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-02-15 23:01:42 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-02-15 23:01:43 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-02-15 23:02:00 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-02-15 23:02:01 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-02-15 23:02:02 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-02-15 23:02:03 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-02-15 23:12:14 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-02-15 23:12:15 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-02-15 23:12:16 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-02-15 23:12:17 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-02-15 23:42:12 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-02-15 23:42:13 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-02-15 23:42:14 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-02-15 23:42:15 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-02-15 23:50:40  INFO SIGTERM signal received
2022-02-15 23:50:40  INFO Exiting with code 0
2022-02-15 23:50:40  INFO fcron[15196] 3.2.1 started

I get error mails (without subject) about the failed jobs. Here are 2 examples:

Date: 15 Feb 2022 22:42:12 -0000
From: fcron <mcd@arctic.box>
Cc: recipient list not shown:

2022-02-15 23:42:12 ERROR Could not init PAM account management for user 'mcd': Module is unknown
2022-02-15 23:42:12 ERROR Job 'cd rrd/df && ./measure' has *not* run.
From: mcd@arctic (fcron)
To: mcd@arctic
Subject: fcron <mcd@arctic> Could not run fcron job: cd rrd/df && ./measure
Content-Type: text/plain; charset=ANSI_X3.4-1968
Auto-Submitted: auto-generated
X-Cron-Env: <USER=mcd>
X-Cron-Env: <LOGNAME=mcd>
X-Cron-Env: <HOME=/home/mcd>
X-Cron-Env: <PATH=/usr/bin:/usr/sbin>
X-Cron-Env: <SHELL=/usr/bin/sh>
Date: 15 Feb 2022 22:01:40 -0000
From: fcron <root@arctic.box>
Cc: recipient list not shown:

2022-02-15 23:01:40 ERROR Could not init PAM account management for user 'root': Module is unknown
2022-02-15 23:01:40 ERROR Job '/usr/bin/run-parts /etc/cron.hourly' has *not* run.
From: root@arctic (fcron)
To: root@arctic
Subject: fcron <systab@arctic> Could not run fcron job: /usr/bin/run-parts /etc/cron.hourly
Content-Type: text/plain; charset=ANSI_X3.4-1968
Auto-Submitted: auto-generated
X-Cron-Env: <USER=root>
X-Cron-Env: <LOGNAME=root>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/usr/sbin>
X-Cron-Env: <SHELL=/usr/bin/sh>

The only thing that might correlate is a system update I ran before:

[2022-02-15T22:12:41+0100] [PACMAN] Running 'pacman -Syu'
[2022-02-15T22:12:41+0100] [PACMAN] synchronizing package lists
[2022-02-15T22:12:54+0100] [PACMAN] starting full system upgrade
[2022-02-15T22:18:15+0100] [ALPM] running '60-mkinitcpio-remove.hook'...
[2022-02-15T22:18:15+0100] [ALPM] transaction started
[2022-02-15T22:18:15+0100] [ALPM] upgraded alsa-ucm-conf (1.2.6.2-2 -> 1.2.6.3-1)
[2022-02-15T22:18:15+0100] [ALPM] upgraded amd-ucode (20220119.0c6a7b3-2 -> 20220209.6342082-1)
[2022-02-15T22:18:15+0100] [ALPM] upgraded linux-api-headers (5.12.3-1 -> 5.16.8-1)
[2022-02-15T22:18:15+0100] [ALPM] upgraded iana-etc (20220110-1 -> 20220205-1)
[2022-02-15T22:18:15+0100] [ALPM] warning: /etc/locale.gen installed as /etc/locale.gen.pacnew
[2022-02-15T22:18:16+0100] [ALPM] upgraded glibc (2.33-5 -> 2.35-2)
[2022-02-15T22:18:16+0100] [ALPM-SCRIPTLET] Generating locales...
[2022-02-15T22:18:18+0100] [ALPM-SCRIPTLET]   de_DE.UTF-8... done
[2022-02-15T22:18:20+0100] [ALPM-SCRIPTLET]   en_US.UTF-8... done
[2022-02-15T22:18:20+0100] [ALPM-SCRIPTLET] Generation complete.
[2022-02-15T22:18:21+0100] [ALPM] upgraded libcap-ng (0.8.2-6 -> 0.8.2-7)
[2022-02-15T22:18:21+0100] [ALPM] upgraded util-linux-libs (2.37.3-2 -> 2.37.4-1)
[2022-02-15T22:18:22+0100] [ALPM] upgraded gcc-libs (11.1.0-3 -> 11.2.0-3)
[2022-02-15T22:18:22+0100] [ALPM] upgraded ncurses (6.3-1 -> 6.3-2)
[2022-02-15T22:18:22+0100] [ALPM] upgraded gdbm (1.22-1 -> 1.23-1)
[2022-02-15T22:18:22+0100] [ALPM] upgraded libnsl (2.0.0-1 -> 2.0.0-2)
[2022-02-15T22:18:34+0100] [ALPM] upgraded apparmor (3.0.3-3 -> 3.0.4-1)
[2022-02-15T22:18:34+0100] [ALPM] warning: /etc/pacman.d/mirrorlist installed as /etc/pacman.d/mirrorlist.pacnew
[2022-02-15T22:18:34+0100] [ALPM] upgraded artix-mirrorlist (20220103-1 -> 20220214-2)
[2022-02-15T22:18:34+0100] [ALPM] upgraded findutils (4.8.0-1 -> 4.9.0-1)
[2022-02-15T22:18:34+0100] [ALPM] upgraded libcap (2.63-1 -> 2.63-2)
[2022-02-15T22:18:35+0100] [ALPM] upgraded lib32-glibc (2.33-5 -> 2.35-2)
[2022-02-15T22:18:35+0100] [ALPM] upgraded ca-certificates-mozilla (3.74-1 -> 3.75-1)
[2022-02-15T22:18:35+0100] [ALPM] upgraded libelf (0.186-4 -> 0.186-5)
[2022-02-15T22:18:35+0100] [ALPM] upgraded binutils (2.36.1-3 -> 2.38-3)
[2022-02-15T22:18:35+0100] [ALPM] upgraded btrfs-progs (5.16-1 -> 5.16.1-1)
[2022-02-15T22:18:35+0100] [ALPM] upgraded libsysprof-capture (3.42.1-2 -> 3.42.1-3)
[2022-02-15T22:18:35+0100] [ALPM] upgraded glib2 (2.70.3-1 -> 2.70.4-1)
[2022-02-15T22:18:35+0100] [ALPM] upgraded harfbuzz (3.3.2-1 -> 3.4.0-1)
[2022-02-15T22:18:35+0100] [ALPM] upgraded pango (1:1.50.3-1 -> 1:1.50.4-1)
[2022-02-15T22:18:36+0100] [ALPM] upgraded llvm-libs (13.0.0-6 -> 13.0.1-1)
[2022-02-15T22:18:36+0100] [ALPM] upgraded xkeyboard-config (2.34-1 -> 2.35.1-1)
[2022-02-15T22:18:36+0100] [ALPM] upgraded xorg-server-common (21.1.3-1 -> 21.1.3-2)
[2022-02-15T22:18:36+0100] [ALPM] upgraded hwdata (0.355-1 -> 0.356-1)
[2022-02-15T22:18:36+0100] [ALPM] upgraded util-linux (2.37.3-2 -> 2.37.4-1)
[2022-02-15T22:18:36+0100] [ALPM] upgraded libwacom (2.0.0-2 -> 2.1.0-1)
[2022-02-15T22:18:36+0100] [ALPM] upgraded xorg-server (21.1.3-1 -> 21.1.3-2)
[2022-02-15T22:18:38+0100] [ALPM] upgraded nvidia-utils (495.46-2 -> 510.47.03-3)
[2022-02-15T22:18:38+0100] [ALPM-SCRIPTLET] If you run into trouble with CUDA not being available, run nvidia-modprobe first.
[2022-02-15T22:18:39+0100] [ALPM] upgraded mesa (21.3.5-1 -> 21.3.6-1)
[2022-02-15T22:18:39+0100] [ALPM] upgraded gtk-update-icon-cache (1:4.6.0-3 -> 1:4.6.1-2)
[2022-02-15T22:18:39+0100] [ALPM] upgraded gtk3 (1:3.24.31-1 -> 1:3.24.31-3)
[2022-02-15T22:18:39+0100] [ALPM] upgraded libtool (2.4.6+42+gb88cebd5-16 -> 2.4.6+59+gb55b1cc8-2)
[2022-02-15T22:18:39+0100] [ALPM] upgraded opus (1.3.1-2.1 -> 1.3.1-3)
[2022-02-15T22:18:39+0100] [ALPM] upgraded libcheese (41.1-1 -> 41.1-2)
[2022-02-15T22:18:39+0100] [ALPM] upgraded libavtp (0.1.0-2.1 -> 0.2.0-1)
[2022-02-15T22:18:39+0100] [ALPM] upgraded x265 (3.5-1 -> 3.5-2)
[2022-02-15T22:18:39+0100] [ALPM] upgraded imlib2 (1.7.5-1 -> 1.8.0-1)
[2022-02-15T22:18:39+0100] [ALPM] upgraded nss (3.74-1 -> 3.75-1)
[2022-02-15T22:18:40+0100] [ALPM] upgraded imagemagick (7.1.0.23-1 -> 7.1.0.24-1)
[2022-02-15T22:18:40+0100] [ALPM] upgraded cheese (41.1-1 -> 41.1-2)
[2022-02-15T22:18:40+0100] [ALPM] upgraded mpfr (4.1.0.p13-1 -> 4.1.0.p13-2)
[2022-02-15T22:18:40+0100] [ALPM] upgraded libmpc (1.2.1-1 -> 1.2.1-2)
[2022-02-15T22:18:41+0100] [ALPM] upgraded gcc (11.1.0-3 -> 11.2.0-3)
[2022-02-15T22:18:41+0100] [ALPM] upgraded compiler-rt (13.0.0-2 -> 13.0.1-1)
[2022-02-15T22:18:43+0100] [ALPM] upgraded clang (13.0.0-4 -> 13.0.1-1)
[2022-02-15T22:18:43+0100] [ALPM] upgraded device-mapper (2.03.14-2 -> 2.03.15-1)
[2022-02-15T22:18:43+0100] [ALPM] upgraded elfutils (0.186-4 -> 0.186-5)
[2022-02-15T22:18:43+0100] [ALPM] upgraded espeak-ng (1.50-4 -> 1.50-5)
[2022-02-15T22:18:43+0100] [ALPM] upgraded exempi (2.5.2-1 -> 2.6.1-1)
[2022-02-15T22:18:43+0100] [ALPM] upgraded faudio (22.01-1 -> 22.02-1)
[2022-02-15T22:18:43+0100] [ALPM] upgraded feh (3.8-1 -> 3.8-2.1)
[2022-02-15T22:18:44+0100] [ALPM] upgraded firefox (96.0.3-1 -> 97.0-1.5)
[2022-02-15T22:18:44+0100] [ALPM] upgraded firefox-i18n-de (96.0.3-1 -> 97.0-1)
[2022-02-15T22:18:45+0100] [ALPM] upgraded freeglut (3.2.1-2.1 -> 3.2.2-1)
[2022-02-15T22:18:45+0100] [ALPM] upgraded gcc-fortran (11.1.0-3 -> 11.2.0-3)
[2022-02-15T22:18:45+0100] [ALPM] upgraded upower (0.99.14-1 -> 0.99.15-1)
[2022-02-15T22:18:45+0100] [ALPM] upgraded libgdm (41.3-1.1 -> 41.3-2)
[2022-02-15T22:18:45+0100] [ALPM] upgraded gjs (2:1.70.0-3 -> 2:1.70.1-2)
[2022-02-15T22:18:45+0100] [ALPM] upgraded gtk4 (1:4.6.0-3 -> 1:4.6.1-2)
[2022-02-15T22:18:45+0100] [ALPM] upgraded libical (3.0.13-1 -> 3.0.14-1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded geocode-glib (3.26.2-1.1 -> 3.26.2+r9+g6047da3-1.1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded libgweather (40.0-1 -> 40.0+r87+g80e5a652-1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded libmm-glib (1.18.4-1 -> 1.18.6-1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded libarchive (3.5.2-3 -> 3.6.0-1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded lvm2 (2.03.14-2 -> 2.03.15-1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded gpgme (1.16.0-3 -> 1.17.0-2)
[2022-02-15T22:18:46+0100] [ALPM] upgraded harfbuzz-icu (3.3.2-1 -> 3.4.0-1)
[2022-02-15T22:18:46+0100] [ALPM] upgraded xdg-dbus-proxy (0.1.2-3 -> 0.1.3-1)
[2022-02-15T22:18:47+0100] [ALPM] upgraded webkit2gtk (2.34.4-1 -> 2.34.5-1)
[2022-02-15T22:18:47+0100] [ALPM] upgraded gdm (41.3-1.1 -> 41.3-2)
[2022-02-15T22:18:48+0100] [ALPM] upgraded glib2-docs (2.70.3-1 -> 2.70.4-1)
[2022-02-15T22:18:48+0100] [ALPM] upgraded gnome-control-center (41.2-3 -> 41.4-1)
[2022-02-15T22:18:49+0100] [ALPM] upgraded gnome-terminal (3.42.2-1 -> 3.42.2-2)
[2022-02-15T22:18:52+0100] [ALPM] upgraded go (2:1.17.6-2 -> 2:1.17.7-1)
[2022-02-15T22:18:52+0100] [ALPM] upgraded grim (1.3.2-1 -> 1.4.0-1)
[2022-02-15T22:18:53+0100] [ALPM] upgraded gwenhywfar (5.6.0-1 -> 5.8.2-1)
[2022-02-15T22:18:53+0100] [ALPM] upgraded qt5-translations (5.15.2+kde+r20-2 -> 5.15.2+kde+r22-1)
[2022-02-15T22:18:54+0100] [ALPM] upgraded qt5-base (5.15.2+kde+r297-1 -> 5.15.2+kde+r298-1)
[2022-02-15T22:18:54+0100] [ALPM] upgraded qt5-declarative (5.15.2+kde+r45-1 -> 5.15.2+kde+r46-1)
[2022-02-15T22:18:54+0100] [ALPM] upgraded qt5-wayland (5.15.2+kde+r48-1 -> 5.15.2+kde+r52-1)
[2022-02-15T22:18:54+0100] [ALPM] upgraded kwayland (5.90.0-1 -> 5.91.0-1)
[2022-02-15T22:18:55+0100] [ALPM] upgraded lib32-gcc-libs (11.1.0-3 -> 11.2.0-3)
[2022-02-15T22:18:55+0100] [ALPM] upgraded lib32-util-linux (2.37.3-1 -> 2.37.4-1)
[2022-02-15T22:18:55+0100] [ALPM] upgraded lib32-glib2 (2.70.3-1 -> 2.70.4-1)
[2022-02-15T22:18:55+0100] [ALPM] upgraded lib32-harfbuzz (3.3.2-1 -> 3.4.0-1)
[2022-02-15T22:18:55+0100] [ALPM] upgraded lib32-lcms2 (2.12-1 -> 2.13.1-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded lib32-llvm-libs (13.0.0-1 -> 13.0.1-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded lib32-mesa (21.3.5-1 -> 21.3.6-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded lib32-pango (1:1.50.3-1 -> 1:1.50.4-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libbpf (0.6.1-1 -> 0.7.0-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libpcap (1.10.1-1 -> 1.10.1-2)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libsigc++ (2.10.7-2 -> 2.10.8-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libspectre (0.2.9-2 -> 0.2.10-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libspeechd (0.10.2-1 -> 0.11.1-2)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libva-mesa-driver (21.3.5-1 -> 21.3.6-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded libvips (8.12.1-1 -> 8.12.2-1)
[2022-02-15T22:18:56+0100] [ALPM] upgraded mkinitcpio-busybox (1.34.1-1 -> 1.35.0-1)
[2022-02-15T22:19:02+0100] [ALPM] upgraded linux (5.16.3.artix1-1 -> 5.16.8.artix1-2)
[2022-02-15T22:19:02+0100] [ALPM] upgraded linux-firmware-whence (20220119.0c6a7b3-2 -> 20220209.6342082-1)
[2022-02-15T22:19:08+0100] [ALPM] upgraded linux-firmware (20220119.0c6a7b3-2 -> 20220209.6342082-1)
[2022-02-15T22:19:13+0100] [ALPM] upgraded linux-lts (5.15.16-1 -> 5.15.22-2)
[2022-02-15T22:19:24+0100] [ALPM] upgraded llvm (13.0.0-6 -> 13.0.1-1)
[2022-02-15T22:19:24+0100] [ALPM] upgraded mako (1.6-2 -> 1.6-3)
[2022-02-15T22:19:24+0100] [ALPM] upgraded man-db (2.9.4-2 -> 2.10.1-1)
[2022-02-15T22:19:24+0100] [ALPM] upgraded mesa-vdpau (21.3.5-1 -> 21.3.6-1)
[2022-02-15T22:19:24+0100] [ALPM] upgraded mongo-c-driver (1.20.1-1 -> 1.21.0-1)
[2022-02-15T22:19:25+0100] [ALPM] upgraded mutt (2.1.5-1 -> 2.2-1)
[2022-02-15T22:19:25+0100] [ALPM] upgraded nano (6.0-1 -> 6.1-1)
[2022-02-15T22:19:25+0100] [ALPM] upgraded notmuch-runtime (0.34.3-1 -> 0.35-1)
[2022-02-15T22:19:25+0100] [ALPM] upgraded neomutt (20211029-1 -> 20211029-2)
[2022-02-15T22:19:25+0100] [ALPM] upgraded sundials (6.1.0-2 -> 6.1.1-1)
[2022-02-15T22:19:25+0100] [ALPM] upgraded qt5-tools (5.15.2+kde+r17-5 -> 5.15.2+kde+r17-6)
[2022-02-15T22:19:26+0100] [ALPM] upgraded octave (6.4.0-3 -> 6.4.0-4)
[2022-02-15T22:19:26+0100] [ALPM] upgraded perl-http-message (6.35-1 -> 6.36-1)
[2022-02-15T22:19:26+0100] [ALPM] upgraded perl-json (4.04-1 -> 4.05-1)
[2022-02-15T22:19:26+0100] [ALPM] upgraded python-idna (3.3-3 -> 3.3-4)
[2022-02-15T22:19:27+0100] [ALPM] upgraded python-numpy (1.21.5-2 -> 1.22.2-1)
[2022-02-15T22:19:27+0100] [ALPM] upgraded qpdf (10.5.0-1 -> 10.6.1-1)
[2022-02-15T22:19:27+0100] [ALPM] upgraded python-pikepdf (4.4.1-1 -> 4.5.0-1)
[2022-02-15T22:19:27+0100] [ALPM] upgraded python-requests (2.26.0-5 -> 2.27.0-1)
[2022-02-15T22:19:27+0100] [ALPM] upgraded python-ruamel-yaml (0.17.20-1 -> 0.17.21-1)
[2022-02-15T22:19:30+0100] [ALPM] upgraded python-scipy (1.7.3-3.1 -> 1.8.0-1)
[2022-02-15T22:19:30+0100] [ALPM] upgraded python-setuptools (1:59.1.1-1 -> 1:59.3.0-1)
[2022-02-15T22:19:30+0100] [ALPM] upgraded python-tomlkit (0.9.0-1 -> 0.9.2-1)
[2022-02-15T22:19:30+0100] [ALPM] upgraded python-typing_extensions (4.0.1-1 -> 4.1.0-1)
[2022-02-15T22:19:30+0100] [ALPM] upgraded remmina (1:1.4.23-3 -> 1:1.4.24-1)
[2022-02-15T22:19:30+0100] [ALPM] upgraded seatd (0.6.3-2 -> 0.6.3-3)
[2022-02-15T22:19:46+0100] [ALPM] upgraded signal-desktop (5.30.0-1 -> 5.31.1-1)
[2022-02-15T22:19:46+0100] [ALPM] upgraded slurp (1.3.2-1 -> 1.3.2-2)
[2022-02-15T22:19:46+0100] [ALPM] upgraded squashfs-tools (4.5-1 -> 4.5-2)
[2022-02-15T22:19:46+0100] [ALPM] upgraded swaybg (1.1-2 -> 1.1-3)
[2022-02-15T22:19:46+0100] [ALPM] upgraded wlroots (0.15.0-4 -> 0.15.1-2)
[2022-02-15T22:19:46+0100] [ALPM] upgraded sway (1:1.7-1 -> 1:1.7-2)
[2022-02-15T22:19:46+0100] [ALPM] upgraded swayidle (1.7.1-1 -> 1.7.1-2)
[2022-02-15T22:19:46+0100] [ALPM] upgraded swaylock (1.5-2 -> 1.5-3)
[2022-02-15T22:19:53+0100] [ALPM] upgraded thunderbird (91.5.1-1 -> 91.6.0-1.1)
[2022-02-15T22:19:53+0100] [ALPM] installed libb64 (1.2.1-4)
[2022-02-15T22:19:53+0100] [ALPM] installed miniupnpc (2.2.2-2)
[2022-02-15T22:19:53+0100] [ALPM] installed libnatpmp (20150609-3)
[2022-02-15T22:19:53+0100] [ALPM] upgraded transmission-gtk (3.00-2 -> 3.00-3)
[2022-02-15T22:19:53+0100] [ALPM] upgraded vala (0.54.6-1 -> 0.54.7-1)
[2022-02-15T22:19:57+0100] [ALPM] upgraded valgrind (3.18.1-2 -> 3.18.1-3)
[2022-02-15T22:20:01+0100] [ALPM] upgraded webkit2gtk-4.1 (2.34.4-1 -> 2.34.5-1)
[2022-02-15T22:20:13+0100] [ALPM] upgraded wine (7.1-1 -> 7.2-1)
[2022-02-15T22:20:21+0100] [ALPM] upgraded wine-mono (7.0.0-2 -> 7.1.1-1)
[2022-02-15T22:20:21+0100] [ALPM] upgraded wpa_supplicant (2:2.10-1 -> 2:2.10-2)
[2022-02-15T22:20:21+0100] [ALPM] upgraded xfce4-notifyd (0.6.2-2 -> 0.6.3-1)
[2022-02-15T22:20:21+0100] [ALPM] upgraded xorg-server-devel (21.1.3-1 -> 21.1.3-2)
[2022-02-15T22:20:21+0100] [ALPM] upgraded xorg-server-xephyr (21.1.3-1 -> 21.1.3-2)
[2022-02-15T22:20:21+0100] [ALPM] upgraded xorg-server-xnest (21.1.3-1 -> 21.1.3-2)
[2022-02-15T22:20:21+0100] [ALPM] upgraded xorg-server-xvfb (21.1.3-1 -> 21.1.3-2)
[2022-02-15T22:20:23+0100] [ALPM] transaction completed
[2022-02-15T22:20:26+0100] [ALPM] running '20-sysusers.hook'...
[2022-02-15T22:20:28+0100] [ALPM] running '30-binfmt.hook'...
[2022-02-15T22:20:28+0100] [ALPM-SCRIPTLET] (B:: (BRunning binfmt(B    (B[(Bbusy(B](B    (B[(Bdone(B](B 
[2022-02-15T22:20:28+0100] [ALPM] running '30-tmpfiles.hook'...
[2022-02-15T22:20:28+0100] [ALPM] running '30-udev-hwdb.hook'...
[2022-02-15T22:20:32+0100] [ALPM] running '30-udev-reload.hook'...
[2022-02-15T22:20:32+0100] [ALPM] running '30-update-mime-database.hook'...
[2022-02-15T22:20:43+0100] [ALPM] running '40-update-ca-trust.hook'...
[2022-02-15T22:20:45+0100] [ALPM] running '60-depmod.hook'...
[2022-02-15T22:20:51+0100] [ALPM] running '90-mkinitcpio-install.hook'...
[2022-02-15T22:20:51+0100] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux-lts.preset: 'default'
[2022-02-15T22:20:51+0100] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux-lts -c /etc/mkinitcpio.conf -g /boot/initramfs-linux-lts.img
[2022-02-15T22:20:52+0100] [ALPM-SCRIPTLET] ==> Starting build: 5.15.22-2-lts
[2022-02-15T22:20:52+0100] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2022-02-15T22:20:53+0100] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2022-02-15T22:20:54+0100] [ALPM-SCRIPTLET]   -> Running build hook: [autodetect]
[2022-02-15T22:20:54+0100] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2022-02-15T22:20:55+0100] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2022-02-15T22:20:55+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: xhci_pci
[2022-02-15T22:20:55+0100] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2022-02-15T22:20:55+0100] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2022-02-15T22:20:56+0100] [ALPM-SCRIPTLET]   -> Running build hook: [resume]
[2022-02-15T22:20:56+0100] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2022-02-15T22:20:56+0100] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2022-02-15T22:20:57+0100] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: /boot/initramfs-linux-lts.img
[2022-02-15T22:20:57+0100] [ALPM-SCRIPTLET] ==> Image generation successful
[2022-02-15T22:20:57+0100] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux-lts.preset: 'fallback'
[2022-02-15T22:20:57+0100] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux-lts -c /etc/mkinitcpio.conf -g /boot/initramfs-linux-lts-fallback.img -S autodetect
[2022-02-15T22:20:57+0100] [ALPM-SCRIPTLET] ==> Starting build: 5.15.22-2-lts
[2022-02-15T22:20:57+0100] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: wd719x
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: aic94xx
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qla1280
[2022-02-15T22:20:58+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qed
[2022-02-15T22:20:59+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: bfa
[2022-02-15T22:20:59+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qla2xxx
[2022-02-15T22:20:59+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: xhci_pci
[2022-02-15T22:21:00+0100] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2022-02-15T22:21:01+0100] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2022-02-15T22:21:02+0100] [ALPM-SCRIPTLET]   -> Running build hook: [resume]
[2022-02-15T22:21:02+0100] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2022-02-15T22:21:03+0100] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2022-02-15T22:21:04+0100] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: /boot/initramfs-linux-lts-fallback.img
[2022-02-15T22:21:04+0100] [ALPM-SCRIPTLET] ==> Image generation successful
[2022-02-15T22:21:04+0100] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux.preset: 'default'
[2022-02-15T22:21:04+0100] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux -c /etc/mkinitcpio.conf -g /boot/initramfs-linux.img
[2022-02-15T22:21:04+0100] [ALPM-SCRIPTLET] ==> Starting build: 5.16.8-artix1-2
[2022-02-15T22:21:04+0100] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2022-02-15T22:21:05+0100] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2022-02-15T22:21:05+0100] [ALPM-SCRIPTLET]   -> Running build hook: [autodetect]
[2022-02-15T22:21:05+0100] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2022-02-15T22:21:05+0100] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2022-02-15T22:21:05+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: xhci_pci
[2022-02-15T22:21:05+0100] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET]   -> Running build hook: [resume]
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: /boot/initramfs-linux.img
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET] ==> Image generation successful
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux.preset: 'fallback'
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux -c /etc/mkinitcpio.conf -g /boot/initramfs-linux-fallback.img -S autodetect
[2022-02-15T22:21:06+0100] [ALPM-SCRIPTLET] ==> Starting build: 5.16.8-artix1-2
[2022-02-15T22:21:07+0100] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2022-02-15T22:21:07+0100] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2022-02-15T22:21:07+0100] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2022-02-15T22:21:07+0100] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2022-02-15T22:21:07+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: wd719x
[2022-02-15T22:21:08+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: aic94xx
[2022-02-15T22:21:08+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qla1280
[2022-02-15T22:21:08+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qed
[2022-02-15T22:21:08+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: bfa
[2022-02-15T22:21:08+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qla2xxx
[2022-02-15T22:21:09+0100] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: xhci_pci
[2022-02-15T22:21:09+0100] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2022-02-15T22:21:10+0100] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2022-02-15T22:21:11+0100] [ALPM-SCRIPTLET]   -> Running build hook: [resume]
[2022-02-15T22:21:11+0100] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2022-02-15T22:21:12+0100] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2022-02-15T22:21:13+0100] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: /boot/initramfs-linux-fallback.img
[2022-02-15T22:21:14+0100] [ALPM-SCRIPTLET] ==> Image generation successful
[2022-02-15T22:21:14+0100] [ALPM] running 'detect-old-perl-modules.hook'...
[2022-02-15T22:21:14+0100] [ALPM] running 'fontconfig.hook'...
[2022-02-15T22:21:15+0100] [ALPM] running 'fontconfig-32.hook'...
[2022-02-15T22:21:15+0100] [ALPM] running 'glib-compile-schemas.hook'...
[2022-02-15T22:21:15+0100] [ALPM] running 'gtk-query-immodules-3.0.hook'...
[2022-02-15T22:21:16+0100] [ALPM] running 'gtk-update-icon-cache.hook'...
[2022-02-15T22:21:16+0100] [ALPM] running 'gtk4-querymodules.hook'...
[2022-02-15T22:21:17+0100] [ALPM] running 'texinfo-install.hook'...
[2022-02-15T22:21:20+0100] [ALPM] running 'update-desktop-database.hook'...

I'm on artixlinux with runit. I should have older logs from another time this happened. Tell me, if you need them.

castilma commented 2 years ago

The message ERROR Could not init PAM account management for user 'root': Module is unknown should be more verbose, i.e. state which module could not be loaded.

2022-02-15 23:12:17 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-02-15 23:42:12 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success

To debug this, it would be a start to find out, how the pipe could have been closed. And, why read_write_pipe seemingly tries to read from a closed pipe/invalid file descriptor(?) returning 0 bytes instead of an error. If it reads from somewhere else, it would be good to know why that failed.

castilma commented 2 years ago

Today I noticed the error again, this time on my laptop, but with the same os.

2022-08-03 00:01:00  INFO Job '/usr/bin/run-parts /etc/cron.hourly' started for user systab (pid 7316)
2022-08-03 00:01:00  INFO Job '/usr/bin/run-parts /etc/cron.hourly' completed
2022-08-03 00:02:00  INFO Job '/usr/bin/run-parts /etc/cron.daily' started for user systab (pid 7417)
2022-08-03 00:03:11  INFO Job '/usr/bin/run-parts /etc/cron.daily' completed
2022-08-03 01:01:00 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-08-03 01:01:01 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-08-03 01:01:02 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-08-03 01:01:03 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-08-03 11:37:09  INFO suspend/hibernate detected: we woke up after 37999s instead of 1800s. The system was suspended for 36927s.
2022-08-03 11:37:09 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-08-03 11:37:10 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-08-03 11:37:11 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-08-03 11:37:12 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-08-03 12:01:00 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-08-03 12:01:01 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-08-03 12:01:02 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-08-03 12:01:03 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-08-03 13:01:00 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-08-03 13:01:01 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-08-03 13:01:02 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-08-03 13:01:03 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-08-03 14:01:00 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
2022-08-03 14:01:01 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
2022-08-03 14:01:02 ERROR read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
2022-08-03 14:01:03 ERROR Could not read job pid because of closed pipe: setting it to -1
2022-08-03 14:13:41  INFO suspend/hibernate detected: we woke up after 392s instead of 1800s. The system was suspended for 168s.

and theres been a system upgrade prior to the error:

[2022-08-03T00:40:35+0200] [ALPM] running '60-mkinitcpio-remove.hook'...
[2022-08-03T00:40:35+0200] [ALPM] transaction started
[2022-08-03T00:40:36+0200] [ALPM] upgraded linux-api-headers (5.17.5-2 -> 5.18.15-1)
[2022-08-03T00:40:38+0200] [ALPM] warning: /etc/locale.gen installed as /etc/locale.gen.pacnew
[2022-08-03T00:40:38+0200] [ALPM] upgraded glibc (2.35-6 -> 2.36-1)
[2022-08-03T00:40:38+0200] [ALPM-SCRIPTLET] Generating locales...
[2022-08-03T00:40:41+0200] [ALPM-SCRIPTLET]   de_DE.UTF-8... done
[2022-08-03T00:40:41+0200] [ALPM-SCRIPTLET] Generation complete.
[2022-08-03T00:40:43+0200] [ALPM] upgraded gcc-libs (12.1.0-3 -> 12.1.1-4)
[2022-08-03T00:40:43+0200] [ALPM] upgraded lib32-glibc (2.35-6 -> 2.36-1)
[2022-08-03T00:40:43+0200] [ALPM] upgraded libelf (0.187-1 -> 0.187-2)
[2022-08-03T00:40:44+0200] [ALPM] upgraded binutils (2.38-6 -> 2.38-7)
[2022-08-03T00:40:44+0200] [ALPM] upgraded mpfr (4.1.0.p13-2 -> 4.1.0.p13-3)
[2022-08-03T00:41:20+0200] [ALPM] upgraded linux (5.18.14.artix1-1 -> 5.18.15.artix1-2)
[2022-08-03T00:41:20+0200] [ALPM] upgraded acpi_call (1.2.2-57 -> 1.2.2-60)
[2022-08-03T00:41:21+0200] [ALPM] upgraded elfutils (0.187-1 -> 0.187-2)
[2022-08-03T00:41:21+0200] [ALPM] upgraded libsysprof-capture (3.44.0-1 -> 3.44.0-2)
[2022-08-03T00:41:21+0200] [ALPM] upgraded gsm (1.0.20-1 -> 1.0.21-1)
[2022-08-03T00:41:21+0200] [ALPM] upgraded opencore-amr (0.1.5-5 -> 0.1.6-1)
[2022-08-03T00:41:23+0200] [ALPM] upgraded libtiff (4.4.0-1 -> 4.4.0-3)
[2022-08-03T00:41:32+0200] [ALPM] upgraded firefox (103.0-1 -> 103.0.1-1)
[2022-08-03T00:41:32+0200] [ALPM] upgraded firefox-i18n-de (103.0-1 -> 103.0.1-1)
[2022-08-03T00:41:36+0200] [ALPM] upgraded gcc (12.1.0-3 -> 12.1.1-4)
[2022-08-03T00:41:52+0200] [ALPM] upgraded gcc-fortran (12.1.0-3 -> 12.1.1-4)
[2022-08-03T00:42:23+0200] [ALPM] upgraded libtool (2.4.7-2 -> 2.4.7-3)
[2022-08-03T00:42:26+0200] [ALPM] upgraded imagemagick (7.1.0.44-1 -> 7.1.0.45-1)
[2022-08-03T00:42:27+0200] [ALPM] upgraded iptables (1:1.8.8-1 -> 1:1.8.8-2)
[2022-08-03T00:42:30+0200] [ALPM] upgraded jre8-openjdk-headless (8.342.u07-1 -> 8.345.u01-1)
[2022-08-03T00:42:31+0200] [ALPM] upgraded lib32-gcc-libs (12.1.0-3 -> 12.1.1-4)
[2022-08-03T00:42:31+0200] [ALPM] upgraded lib32-libxcrypt (4.4.28-1 -> 4.4.28-2)
[2022-08-03T00:42:42+0200] [ALPM] upgraded libreoffice-fresh (7.3.4-2 -> 7.3.5-1)
[2022-08-03T00:42:52+0200] [ALPM] upgraded libreoffice-fresh-de (7.3.4-1 -> 7.3.5-1)
[2022-08-03T00:42:52+0200] [ALPM] upgraded libwpe (1.12.0-2 -> 1.12.2-1)
[2022-08-03T00:43:05+0200] [ALPM] upgraded sddm (0.19.0-8 -> 0.19.0-8.1)
[2022-08-03T00:43:05+0200] [ALPM] upgraded tp_smapi (0.43-410 -> 0.43-413)
[2022-08-03T00:43:05+0200] [ALPM] upgraded wavpack (5.4.0-1 -> 5.5.0-1)
[2022-08-03T00:43:05+0200] [ALPM] upgraded wayland-protocols (1.25-1 -> 1.26-1)
[2022-08-03T00:43:06+0200] [ALPM] upgraded webkit2gtk (2.36.5-1 -> 2.36.5-2)
[2022-08-03T00:43:07+0200] [ALPM] upgraded webkit2gtk-4.1 (2.36.5-1 -> 2.36.5-2)
[2022-08-03T00:43:08+0200] [ALPM] transaction completed
[2022-08-03T00:43:09+0200] [ALPM] running '20-sysusers.hook'...
[2022-08-03T00:43:10+0200] [ALPM] running '30-tmpfiles.hook'...
[2022-08-03T00:43:10+0200] [ALPM] running '30-update-mime-database.hook'...
[2022-08-03T00:43:11+0200] [ALPM] running '60-depmod.hook'...
[2022-08-03T00:45:48+0200] [ALPM] running '90-mkinitcpio-install.hook'...
[2022-08-03T00:45:49+0200] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux.preset: 'default'
[2022-08-03T00:45:49+0200] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux -c /etc/mkinitcpio.conf -g /boot/initramfs-linux.img
[2022-08-03T00:45:49+0200] [ALPM-SCRIPTLET] ==> Starting build: 5.18.15-artix1-2
[2022-08-03T00:45:49+0200] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2022-08-03T00:45:50+0200] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2022-08-03T00:45:51+0200] [ALPM-SCRIPTLET]   -> Running build hook: [autodetect]
[2022-08-03T00:45:51+0200] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2022-08-03T00:45:52+0200] [ALPM-SCRIPTLET]   -> Running build hook: [keymap]
[2022-08-03T00:45:52+0200] [ALPM-SCRIPTLET]   -> Running build hook: [consolefont]
[2022-08-03T00:45:52+0200] [ALPM-SCRIPTLET] ==> WARNING: consolefont: no font found in configuration
[2022-08-03T00:45:52+0200] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2022-08-03T00:45:52+0200] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2022-08-03T00:45:53+0200] [ALPM-SCRIPTLET]   -> Running build hook: [encrypt]
[2022-08-03T00:45:54+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qat_4xxx
[2022-08-03T00:45:58+0200] [ALPM-SCRIPTLET]   -> Running build hook: [lvm2]
[2022-08-03T00:46:01+0200] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2022-08-03T00:46:01+0200] [ALPM-SCRIPTLET]   -> Running build hook: [resume]
[2022-08-03T00:46:01+0200] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2022-08-03T00:46:01+0200] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2022-08-03T00:46:01+0200] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: /boot/initramfs-linux.img
[2022-08-03T00:46:02+0200] [ALPM-SCRIPTLET] ==> Image generation successful
[2022-08-03T00:46:02+0200] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux.preset: 'fallback'
[2022-08-03T00:46:02+0200] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux -c /etc/mkinitcpio.conf -g /boot/initramfs-linux-fallback.img -S autodetect
[2022-08-03T00:46:02+0200] [ALPM-SCRIPTLET] ==> Starting build: 5.18.15-artix1-2
[2022-08-03T00:46:02+0200] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2022-08-03T00:46:02+0200] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2022-08-03T00:46:03+0200] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2022-08-03T00:46:03+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: xhci_pci
[2022-08-03T00:46:04+0200] [ALPM-SCRIPTLET]   -> Running build hook: [keymap]
[2022-08-03T00:46:04+0200] [ALPM-SCRIPTLET]   -> Running build hook: [consolefont]
[2022-08-03T00:46:04+0200] [ALPM-SCRIPTLET] ==> WARNING: consolefont: no font found in configuration
[2022-08-03T00:46:04+0200] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2022-08-03T00:46:04+0200] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2022-08-03T00:46:07+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qla2xxx
[2022-08-03T00:46:07+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: aic94xx
[2022-08-03T00:46:08+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qed
[2022-08-03T00:46:09+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: bfa
[2022-08-03T00:46:12+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: wd719x
[2022-08-03T00:46:13+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qla1280
[2022-08-03T00:46:17+0200] [ALPM-SCRIPTLET]   -> Running build hook: [encrypt]
[2022-08-03T00:46:17+0200] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: qat_4xxx
[2022-08-03T00:46:18+0200] [ALPM-SCRIPTLET]   -> Running build hook: [lvm2]
[2022-08-03T00:46:18+0200] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2022-08-03T00:46:20+0200] [ALPM-SCRIPTLET]   -> Running build hook: [resume]
[2022-08-03T00:46:20+0200] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2022-08-03T00:46:21+0200] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2022-08-03T00:46:22+0200] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: /boot/initramfs-linux-fallback.img
[2022-08-03T00:46:24+0200] [ALPM-SCRIPTLET] ==> Image generation successful
[2022-08-03T00:46:24+0200] [ALPM] running 'detect-old-perl-modules.hook'...
[2022-08-03T00:46:24+0200] [ALPM] running 'gtk-update-icon-cache.hook'...
[2022-08-03T00:46:24+0200] [ALPM] running 'texinfo-install.hook'...
[2022-08-03T00:46:28+0200] [ALPM] running 'update-desktop-database.hook'...

If you give me concrete steps, I could debug it with gdb or something.

The following packages were update/installed both times:

binutils
elfutils
firefox
firefox-i18n-de
gcc
gcc-fortran
gcc-libs
glibc
imagemagick
lib32-gcc-libs
lib32-glibc
libelf
libsysprof-capture
libtool
linux
linux-api-headers
mpfr
webkit2gtk
webkit2gtk-4.1

Before the error printing code is a comment, asking, whether writing to a closed pipe is really an error, and that it should never happen. (job.c). Writing to a closed pipe is indicative of an error, and it can happen. The 'real' errror message is available in the mail or syslog:

cron.notice: Aug  3 00:03:11 fcron[7416]: Job '/usr/bin/run-parts /etc/cron.daily' completed
cron.err: Aug  3 01:01:00 fcron[18828]: Could not init PAM account management for user 'root': Module is unknown
cron.err: Aug  3 01:01:00 fcron[18828]: Job '/usr/bin/run-parts /etc/cron.hourly' has *not* run.
cron.err: Aug  3 01:01:00 fcron[18828]: Couldn't exec '/usr/bin/sendmail': No such file or directory
cron.err: Aug  3 01:01:00 fcron[18828]: fcron child aborted: this does not affect the main fcron daemon, but this may prevent a job from being run or an email from being sent.
cron.err: Aug  3 01:01:00 fcron[1015]: read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 1): Success
cron.err: Aug  3 01:01:01 fcron[1015]: read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 2): Success
cron.err: Aug  3 01:01:02 fcron[1015]: read_write_pipe(): read/write returned 0: retrying... (size: 4, size_processed: 0, num_retry: 3): Success
cron.err: Aug  3 01:01:03 fcron[1015]: Could not read job pid because of closed pipe: setting it to -1
castilma commented 2 years ago

Here are the open files of fcron

lr-x------ 1 root root 64  8. Aug 14:31 0 -> /dev/null
l-wx------ 1 root root 64  8. Aug 14:31 1 -> 'pipe:[17223]'
l-wx------ 1 root root 64  8. Aug 14:31 2 -> 'pipe:[17223]'
lrwx------ 1 root root 64  8. Aug 14:31 3 -> /run/fcron.pid
lrwx------ 1 root root 64  8. Aug 14:31 4 -> 'socket:[17652]'
lrwx------ 1 root root 64  8. Aug 14:31 5 -> 'socket:[17653]'
lrwx------ 1 root root 64  8. Aug 14:31 6 -> 'anon_inode:[timerfd]'

and an strace:

pselect6(7, [5 6], NULL, NULL, {tv_sec=49, tv_nsec=223536660}, NULL) = 0 (Timeout)
pipe2([7, 8], 0)                        = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fb77d372e90) = 14791
close(8)                                = 0
read(7, "", 4)                          = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=14791, si_uid=1000, si_status=2, si_utime=0, si_stime=0} ---
rt_sigreturn({mask=[]})                 = 0
getpid()                                = 1015
sendto(4, "<75>Aug  8 15:07:00 fcron[1015]:"..., 138, MSG_NOSIGNAL, NULL, 0) = 138
newfstatat(AT_FDCWD, "/etc/localtime", {st_mode=S_IFREG|0644, st_size=2298, ...}, 0) = 0
write(2, "2022-08-08 15:07:00 ERROR ", 26) = 26
write(2, "read_write_pipe(): read/write re"..., 106) = 106
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7ffda95bf740) = 0
read(7, "", 4)                          = 0
getpid()                                = 1015
sendto(4, "<75>Aug  8 15:07:01 fcron[1015]:"..., 138, MSG_NOSIGNAL, NULL, 0) = 138
newfstatat(AT_FDCWD, "/etc/localtime", {st_mode=S_IFREG|0644, st_size=2298, ...}, 0) = 0
write(2, "2022-08-08 15:07:01 ERROR ", 26) = 26
write(2, "read_write_pipe(): read/write re"..., 106) = 106
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7ffda95bf740) = 0
read(7, "", 4)                          = 0
getpid()                                = 1015
sendto(4, "<75>Aug  8 15:07:02 fcron[1015]:"..., 138, MSG_NOSIGNAL, NULL, 0) = 138
newfstatat(AT_FDCWD, "/etc/localtime", {st_mode=S_IFREG|0644, st_size=2298, ...}, 0) = 0
write(2, "2022-08-08 15:07:02 ERROR ", 26) = 26
write(2, "read_write_pipe(): read/write re"..., 106) = 106
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7ffda95bf740) = 0
read(7, "", 4)                          = 0
getpid()                                = 1015
sendto(4, "<75>Aug  8 15:07:03 fcron[1015]:"..., 96, MSG_NOSIGNAL, NULL, 0) = 96
newfstatat(AT_FDCWD, "/etc/localtime", {st_mode=S_IFREG|0644, st_size=2298, ...}, 0) = 0
write(2, "2022-08-08 15:07:03 ERROR ", 26) = 26
write(2, "Could not read job pid because o"..., 64) = 64
close(7)                                = 0
castilma commented 2 years ago

now I looked at syslog again:

authpriv.err: Aug  3 01:01:00 fcron[18828]: PAM unable to dlopen(/usr/lib/security/pam_unix.so): /usr/lib/libc.so.6: version `GLIBC_ABI_DT_RELR' not found (required by /usr/lib/libpthread.so.0)
authpriv.err: Aug  3 01:01:00 fcron[18828]: PAM adding faulty module: /usr/lib/security/pam_unix.so

I guess it's the glibc update which brakes the ABI of something?

So, is this an fcron bug? I never experienced any daemon problems with PAM after an update. So maybe fcron is doing something more vulnerable. But I'm not sure how many daemons I'm using, that use PAM...

I wonder who's at fault: An update causes already running processes to continue running with an outdated libc, which breaks dlopen with newer libraries (I think that's the problem).

castilma commented 2 years ago

There is an archlinux forum post with a similar error message. Also, restarting fcron fixes it. So, even though the problem doesn't seem to be a fcron bug, maybe fcron should restart itself to fix this.

castilma commented 5 months ago

@yo8192 Could you please mention the commit, that fixed this?

Two weeks ago I only find this, which seems to fix #23, but not this issue.

yo8192 commented 5 months ago

@castilma I did a clean-up of issues then and I assumed this one was old and probably no longer relevant. I should have put a comment to say so, apologies for the confusion.

What you described here looks more like a distribution issue than a fcron issue. Also no one else has reported this on other distributions.

I see fcron is packaged under Artix Linux: https://packages.artixlinux.org/details/fcron. Did you use the distribution package to install fcron? If so I think it would be best to contact the Artix package maintainer to investigate and possibly to add some auto-restart in that scenario if that seems to help.

Also your original message mentions fcron 3.2.1... have you seen this problem with the latest fcron version 3.3.1?

castilma commented 5 months ago

I installed the one distributed by artix. No, I haven't seen it since.