Why does journalctl stop working every now and then?

Support Software & Applications
1

I do a backintime backup of / every night at 00:00:00 and sometimes (seldom!) backintime hangs and next morning i can’t stop rsync process - used by backintime - and i only can switch off my PC to force a reboot.

Tried as root in vain HTOP to kill the resync process.
Tried in vain killall rsync
Googled for killing a naughty process … tooo much input :slight_smile:

Right tiem to vacuum my logs … :frowning:

[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/system@bb313559a5c84fd49d56a42d484baec4-000000000002ec60-0005d8003762a57b.journal (8.2M).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/user-1000@0b3f4a1c4c4041dbbee55795eb8f725c-000000000002ef30-0005d80037bfe53f.journal (808.0K).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/system@bb313559a5c84fd49d56a42d484baec4-0000000000030eee-0005d837b3d332b3.journal (2.5M).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/user-1000@0b3f4a1c4c4041dbbee55795eb8f725c-0000000000030f7d-0005d837ecb2d306.journal (660.0K).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/system@bb313559a5c84fd49d56a42d484baec4-00000000000318c2-0005d839b1c0799d.journal (8.2M).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/user-1000@0b3f4a1c4c4041dbbee55795eb8f725c-00000000000318cf-0005d839b1f3b743.journal (840.0K).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/system@bb313559a5c84fd49d56a42d484baec4-0000000000033b71-0005d8661fbf5818.journal (8.1M).
[23.02.2022 04:08:01] Deleted archived journal /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/user-1000@0b3f4a1c4c4041dbbee55795eb8f725c-0000000000033efd-0005d87133a89372.journal (1.1M).
[23.02.2022 04:08:01] Vacuuming done, freed 30.6M of archived journals from /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a.

Do you see anything in jourhnalctl --since 00:00:00 as follows?
Strange: no events before 00:02:32 , reason see above …

Feb 23 00:02:32 manjaro CROND[1819093]: (root) CMDOUT (run-parts: failed to exec /etc/cron.hourly/protokoll: Exec format error)
Feb 23 00:02:32 manjaro systemd-journald[261]: Data hash table of /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/system.journal has a fill level at 75.0 (20480 of 27306 items, 15728640 file size, 768 bytes per hash table item), suggesting rotation.
Feb 23 00:02:32 manjaro systemd-journald[261]: /var/log/journal/f5cca6a2eef242e0a5619690cbc6aa0a/system.journal: Journal header limits reached or header out-of-date, rotating.
Feb 23 00:02:32 manjaro CROND[1819093]: (root) CMDOUT (run-parts: /etc/cron.hourly/protokoll exited with return code 1)
Feb 23 00:02:32 manjaro CROND[1819093]: (root) CMDEND (run-parts /etc/cron.hourly)
Feb 23 00:02:42 manjaro kernel: INFO: task usb-storage:1272 blocked for more than 122 seconds.
Feb 23 00:02:42 manjaro kernel:       Tainted: P           OE     5.15.21-1-MANJARO #1
Feb 23 00:02:42 manjaro kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 23 00:02:42 manjaro kernel: task:usb-storage     state:D stack:    0 pid: 1272 ppid:     2 flags:0x00004000
Feb 23 00:02:42 manjaro kernel: Call Trace:
Feb 23 00:02:42 manjaro kernel:  <TASK>
Feb 23 00:02:42 manjaro kernel:  __schedule+0x331/0x1530
Feb 23 00:02:42 manjaro kernel:  ? xhci_urb_enqueue+0x1e1/0x520
Feb 23 00:02:42 manjaro kernel:  schedule+0x5d/0xd0
Feb 23 00:02:42 manjaro kernel:  schedule_timeout+0x125/0x160
Feb 23 00:02:42 manjaro kernel:  wait_for_completion+0xa3/0x100
Feb 23 00:02:42 manjaro kernel:  usb_sg_wait+0xc9/0x1a0
Feb 23 00:02:42 manjaro kernel:  usb_stor_bulk_transfer_sglist.constprop.0+0x8e/0xd0 [usb_storage 0a998ce34ec89166bc31f0163576d8c895c0b778]
Feb 23 00:02:42 manjaro kernel:  usb_stor_Bulk_transport+0x192/0x430 [usb_storage 0a998ce34ec89166bc31f0163576d8c895c0b778]
Feb 23 00:02:42 manjaro kernel:  usb_stor_invoke_transport+0x56/0x520 [usb_storage 0a998ce34ec89166bc31f0163576d8c895c0b778]
Feb 23 00:02:42 manjaro kernel:  usb_stor_control_thread+0x227/0x2f0 [usb_storage 0a998ce34ec89166bc31f0163576d8c895c0b778]
Feb 23 00:02:42 manjaro kernel:  ? usb_stor_scan_dwork+0xe0/0xe0 [usb_storage 0a998ce34ec89166bc31f0163576d8c895c0b778]
Feb 23 00:02:42 manjaro kernel:  kthread+0x12f/0x160
Feb 23 00:02:42 manjaro kernel:  ? set_kthread_struct+0x50/0x50
Feb 23 00:02:42 manjaro kernel:  ret_from_fork+0x1f/0x30
Feb 23 00:02:42 manjaro kernel:  </TASK>
Feb 23 00:02:42 manjaro kernel: INFO: task jbd2/sda3-8:1550 blocked for more than 122 seconds.
Feb 23 00:02:42 manjaro kernel:       Tainted: P           OE     5.15.21-1-MANJARO #1
Feb 23 00:02:42 manjaro kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 23 00:02:42 manjaro kernel: task:jbd2/sda3-8     state:D stack:    0 pid: 1550 ppid:     2 flags:0x00004000
Feb 23 00:02:42 manjaro kernel: Call Trace:
Feb 23 00:02:42 manjaro kernel:  <TASK>
Feb 23 00:02:42 manjaro kernel:  ? bit_wait+0x60/0x60
Feb 23 00:02:42 manjaro kernel:  __schedule+0x331/0x1530
Feb 23 00:02:42 manjaro kernel:  ? __blk_mq_sched_dispatch_requests+0x112/0x160
Feb 23 00:02:42 manjaro kernel:  ? bit_wait+0x60/0x60
Feb 23 00:02:42 manjaro kernel:  schedule+0x5d/0xd0
Feb 23 00:02:42 manjaro kernel:  io_schedule+0x42/0x70
Feb 23 00:02:42 manjaro kernel:  bit_wait_io+0xd/0x60
Feb 23 00:02:42 manjaro kernel:  __wait_on_bit+0x28/0x90
Feb 23 00:02:42 manjaro kernel:  out_of_line_wait_on_bit+0x92/0xc0
Feb 23 00:02:42 manjaro kernel:  ? var_wake_function+0x30/0x30
Feb 23 00:02:42 manjaro kernel:  jbd2_journal_commit_transaction+0x1360/0x1c90 [jbd2 3742815e434ebd991c48f89d9ba8dac8dea17bce]
Feb 23 00:02:42 manjaro kernel:  kjournald2+0xdc/0x2c0 [jbd2 3742815e434ebd991c48f89d9ba8dac8dea17bce]
Feb 23 00:02:42 manjaro kernel:  ? do_wait_intr_irq+0xb0/0xb0
Feb 23 00:02:42 manjaro kernel:  ? load_superblock.part.0+0xc0/0xc0 [jbd2 3742815e434ebd991c48f89d9ba8dac8dea17bce]
Feb 23 00:02:42 manjaro kernel:  kthread+0x12f/0x160
Feb 23 00:02:42 manjaro kernel:  ? set_kthread_struct+0x50/0x50
Feb 23 00:02:42 manjaro kernel:  ret_from_fork+0x1f/0x30
Feb 23 00:02:42 manjaro kernel:  </TASK>
Feb 23 00:04:45 manjaro kernel: INFO: task scsi_eh_0:1270 blocked for more than 122 seconds.
Feb 23 00:04:45 manjaro kernel:       Tainted: P           OE     5.15.21-1-MANJARO #1

inxi -F

[john1@manjaro cron.hourly]$ inxi -F
System:
  Host: manjaro Kernel: 5.15.21-1-MANJARO x86_64 bits: 64
    Desktop: Xfce 4.16.0 Distro: Manjaro Linux
Machine:
  Type: Laptop System: LENOVO product: 81RS v: Lenovo Yoga S740-14IIL
    serial: <superuser required>
  Mobo: LENOVO model: LNVNB161216 v: SDK0J40709 WIN
    serial: <superuser required> UEFI: LENOVO v: BYCN39WW date: 05/28/2021
Battery:
  ID-1: BAT0 charge: 64.4 Wh (98.6%) condition: 65.3/62.0 Wh (105.3%)
CPU:
  Info: quad core model: Intel Core i7-1065G7 bits: 64 type: MT MCP cache:
    L2: 2 MiB
  Speed (MHz): avg: 1209 min/max: 400/3900 cores: 1: 1233 2: 1300 3: 1200
    4: 1200 5: 1200 6: 1201 7: 1155 8: 1183
Graphics:
  Device-1: Intel Iris Plus Graphics G7 driver: i915 v: kernel
  Device-2: NVIDIA GP108M [GeForce MX250] driver: nvidia v: 510.47.03
  Device-3: Chicony Integrated Camera type: USB driver: uvcvideo
  Display: x11 server: X.Org 1.21.1.3 driver: loaded: modesetting,nvidia
    unloaded: nouveau resolution: 1: 1920x1080~60Hz 2: 1920x1080~60Hz
  Message: Unable to show advanced data. Required tool glxinfo missing.
Audio:
  Device-1: Intel Ice Lake-LP Smart Sound Audio
    driver: sof-audio-pci-intel-icl
  Sound Server-1: ALSA v: k5.15.21-1-MANJARO running: yes
  Sound Server-2: PipeWire v: 0.3.45 running: yes
Network:
  Device-1: Intel Ice Lake-LP PCH CNVi WiFi driver: iwlwifi
  IF: wlp0s20f3 state: up mac: 04:33:c2:02:de:51
  Device-2: Realtek RTL8153 Gigabit Ethernet Adapter type: USB
    driver: r8152
  IF: enp0s13f0u1u4 state: up speed: 1000 Mbps duplex: full
    mac: 4c:e1:73:42:1f:6b
  IF-ID-1: pan1 state: down mac: 7a:5c:6a:f4:06:56
Bluetooth:
  Device-1: Intel AX201 Bluetooth type: USB driver: btusb
  Report: rfkill ID: hci0 state: up address: see --recommends
Drives:
  Local Storage: total: 1.86 TiB used: 364.25 GiB (19.2%)
  ID-1: /dev/nvme0n1 vendor: Micron model: MTFDHBA1T0TCK size: 953.87 GiB
  ID-2: /dev/sda type: USB vendor: Western Digital model: WD10EARX-00N0YB0
    size: 931.51 GiB
  ID-3: /dev/sdb type: USB vendor: Kingston model: DataTraveler 2.0
    size: 14.54 GiB
Partition:
  ID-1: / size: 57.9 GiB used: 38.52 GiB (66.5%) fs: ext4 dev: /dev/nvme0n1p8
  ID-2: /boot/efi size: 259.5 MiB used: 114.1 MiB (44.0%) fs: vfat
    dev: /dev/nvme0n1p1
Swap:
  ID-1: swap-1 type: partition size: 16.67 GiB used: 1024 KiB (0.0%)
    dev: /dev/nvme0n1p9
Sensors:
  System Temperatures: cpu: 52.0 C mobo: N/A
  Fan Speeds (RPM): N/A
Info:
  Processes: 291 Uptime: 2h 8m Memory: 15.2 GiB used: 2.75 GiB (18.1%)
  Shell: Bash inxi: 3.3.12
2

what are the return for

sudo journalctl --disk-usage

you lost connection USB disk at this time

3

nearly nothing

Archived and active journals take up 32.0M in the file system.

i do this vacuum every week …

Lost connection is the reason and i can live with that.

backintime seems to be blocked if USB connection is lost.

Good to know :slight_smile:

4

This topic was automatically closed 2 days after the last reply. New replies are no longer allowed.