Woke up this morning without a working computer. It had basically frozen, only on existing prompt still worked, and issuing "reboot" command didn't work. Strangely enough, things like ls -l and htop did work. And updatedb was shown using 102% cpu.
There were messages about soft lockup on CPU0, and after a hard reboot and looking at the log I found this:
Aug 6 12:10:14 ruby kernel: [93101.322902] watchdog: BUG: soft lockup - CPU#0 stuck for 23943s! [updatedb.plocat:248268]
Aug 6 12:11:10 ruby kernel: [93157.323605] watchdog: BUG: soft lockup - CPU#0 stuck for 23995s! [updatedb.plocat:248268]
Aug 6 12:11:38 ruby kernel: [93185.323956] watchdog: BUG: soft lockup - CPU#0 stuck for 24021s! [updatedb.plocat:248268]
Aug 6 12:13:14 ruby kernel: [93281.325161] watchdog: BUG: soft lockup - CPU#0 stuck for 24111s! [updatedb.plocat:248268]
Aug 6 12:15:18 ruby kernel: [93405.326717] watchdog: BUG: soft lockup - CPU#0 stuck for 24226s! [updatedb.plocat:248268]
Aug 6 12:18:18 ruby kernel: [93585.328976] watchdog: BUG: soft lockup - CPU#0 stuck for 24394s! [updatedb.plocat:248268]
Aug 6 12:20:38 ruby kernel: [93725.330732] watchdog: BUG: soft lockup - CPU#0 stuck for 24524s! [updatedb.plocat:248268]
Aug 6 12:22:14 ruby kernel: [93821.331937] watchdog: BUG: soft lockup - CPU#0 stuck for 24613s! [updatedb.plocat:248268]
Aug 6 12:24:18 ruby kernel: [93945.333493] watchdog: BUG: soft lockup - CPU#0 stuck for 24729s! [updatedb.plocat:248268]
Aug 6 12:30:46 ruby kernel: [94333.338362] watchdog: BUG: soft lockup - CPU#0 stuck for 25090s! [updatedb.plocat:248268]
Aug 6 12:31:14 ruby kernel: [94361.338713] watchdog: BUG: soft lockup - CPU#0 stuck for 25116s! [updatedb.plocat:248268]
Aug 6 12:34:14 ruby kernel: [94541.340972] watchdog: BUG: soft lockup - CPU#0 stuck for 25284s! [updatedb.plocat:248268]
And a degraded raid array. That has since been rebuild nicely. Now, this is a NAS storage system, build from off the shelf parts. Nothing fancy, for home use as a media and file server as well as the home network server. It, up until now, has always worked rock solid.
It's the plocate cron job that seemingly locks up everything. I have no idea what is going on, this kind of thin usually doesn't happen. So far I checked the file sytems, those where fine, and ran mem checks, also fine.
The system is
LSB Version: core-11.1.0ubuntu4-noarch:security-11.1.0ubuntu4-noarch
Distributor ID: Ubuntu
Description: Ubuntu 22.04.3 LTS
Release: 22.04
Codename: jammy
5.15.0-78-generic
Intel(R) Core(TM) i5-2500 CPU @ 3.30GHz
MemTotal 10072172 kB
I've googled, but all advice seems to be from 2004, 2008 etc. Not very helpfull. Anyone point me in the right directions?
Edit, I disabled updatedb, but, it happened again, I caught the full log this time:
Message from syslogd@ruby at Aug 7 12:53:00 ...
kernel:[51380.810110] watchdog: BUG: soft lockup - CPU#0 stuck for 2765s! [rm:81024]
Aug 7 12:53:00 ruby kernel: [51380.810110] watchdog: BUG: soft lockup - CPU#0 stuck for 2765s! [rm:81024]
Aug 7 12:53:00 ruby kernel: [51380.810836] Modules linked in: wireguard curve25519_x86_64 libchacha20poly1305 chacha_x86_64 poly1305_x86_64 libcurve25519_generic libchacha tls veth ip6t_REJECT nf_reject_ipv6 xt_MASQUERADE xt_nat xt_connmark xt_TCPMSS nft_limit xt_limit xt_helper xt_multiport xt_conntrack xt_tcpudp ipt_REJECT nf_reject_ipv4 xt_set xt_NFLOG nft_compat nf_nat_irc nf_conntrack_irc nf_nat_sip nf_conntrack_sip nf_nat_ftp nf_conntrack_ftp nf_nat_pptp nf_conntrack_pptp ip6_tables ip_set_hash_net ip_set_hash_ip ip_set vhost_vsock vmw_vsock_virtio_transport_common vhost vhost_iotlb vsock l2tp_ppp l2tp_netlink l2tp_core ip6_udp_tunnel udp_tunnel pppox nft_masq nft_counter ifb nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 bridge nf_tables overlay 8021q garp mrp stp llc nfnetlink_log nfnetlink binfmt_misc intel_rapl_msr mei_hdcp intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_hdmi kvm_intel kvm snd_hda_codec_realtek snd_hda_codec_generic ledtrig_audio
Aug 7 12:53:00 ruby kernel: [51380.810878] crct10dif_pclmul ghash_clmulni_intel aesni_intel snd_hda_intel crypto_simd snd_intel_dspcfg cryptd rapl snd_intel_sdw_acpi serio_raw intel_cstate snd_hda_codec input_leds snd_hda_core snd_hwdep mxm_wmi snd_pcm at24 snd_seq_midi snd_seq_midi_event snd_rawmidi i915 snd_seq ttm snd_seq_device snd_timer drm_kms_helper cec rc_core i2c_algo_bit fb_sys_fops snd syscopyarea mei_me sysfillrect sysimgblt soundcore mei mac_hid sch_fq_codel hwmon_vid msr parport_pc nfsd ppdev auth_rpcgss nfs_acl drm lp ramoops lockd parport efi_pstore reed_solomon grace pstore_blk sunrpc pstore_zone ip_tables x_tables autofs4 xfs raid10 raid1 multipath linear dm_mirror dm_region_hash dm_log raid0 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor hid_generic raid6_pq usbhid libcrc32c hid ahci i2c_i801 crc32_pclmul psmouse i2c_smbus libahci lpc_ich pata_acpi r8169 realtek sata_promise xhci_pci xhci_pci_renesas wmi video
Aug 7 12:53:00 ruby kernel: [51380.810930] CPU: 0 PID: 81024 Comm: rm Tainted: G L 5.15.0-78-generic #85-Ubuntu
Aug 7 12:53:00 ruby kernel: [51380.810932] Hardware name: ECS Z77H2-A2X Deluxe/Z77H2-A2X Deluxe, BIOS 4.6.5 07/04/2012
Aug 7 12:53:00 ruby kernel: [51380.810933] RIP: 0010:native_queued_spin_lock_slowpath.part.0+0x51/0x200
Aug 7 12:53:00 ruby kernel: [51380.810939] Code: 2b 08 0f 92 c2 8b 03 0f b6 d2 c1 e2 08 30 e4 09 d0 a9 00 01 ff ff 0f 85 2a 01 00 00 85 c0 74 0e 8b 03 84 c0 74 08 f3 90 8b 03 <84> c0 75 f8 b8 01 00 00 00 66 89 03 5b 41 5c 41 5d 41 5e 41 5f 5d
Aug 7 12:53:00 ruby kernel: [51380.810940] RSP: 0018:ffffbec40b717ca0 EFLAGS: 00000202
Aug 7 12:53:00 ruby kernel: [51380.810942] RAX: 0000000000000108 RBX: ffff96c5e21d7b98 RCX: 000000000000000b
Aug 7 12:53:00 ruby kernel: [51380.810943] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff96c5e21d7b98
Aug 7 12:53:00 ruby kernel: [51380.810944] RBP: ffffbec40b717cc8 R08: ffffbec40b717df0 R09: 0000000000000064
Aug 7 12:53:00 ruby kernel: [51380.810945] R10: 0000000000000000 R11: ffffffffffffffff R12: ffff96c5e21d7b98
Aug 7 12:53:00 ruby kernel: [51380.810946] R13: ffff96c5c1e9f180 R14: 000000007007a7ea R15: 0000000000000000
Aug 7 12:53:00 ruby kernel: [51380.810947] FS: 00007fb4a0abb740(0000) GS:ffff96c815200000(0000) knlGS:0000000000000000
Aug 7 12:53:00 ruby kernel: [51380.810949] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Aug 7 12:53:00 ruby kernel: [51380.810950] CR2: 00007f0fd521d010 CR3: 0000000168504001 CR4: 00000000000606f0
Aug 7 12:53:00 ruby kernel: [51380.810951] Call Trace:
Aug 7 12:53:00 ruby kernel: [51380.810953] <TASK>
Aug 7 12:53:00 ruby kernel: [51380.810955] native_queued_spin_lock_slowpath+0x2c/0x40
Aug 7 12:53:00 ruby kernel: [51380.810958] _raw_spin_lock+0x22/0x30
Aug 7 12:53:00 ruby kernel: [51380.810961] __d_lookup+0x64/0x150
Aug 7 12:53:00 ruby kernel: [51380.810965] d_lookup+0x2e/0x50
Aug 7 12:53:00 ruby kernel: [51380.810966] lookup_dcache+0x1e/0x70
Aug 7 12:53:00 ruby kernel: [51380.810969] __lookup_hash+0x24/0xa0
Aug 7 12:53:00 ruby kernel: [51380.810971] ? __cond_resched+0x1a/0x50
Aug 7 12:53:00 ruby kernel: [51380.810974] do_unlinkat+0x12c/0x2c0
Aug 7 12:53:00 ruby kernel: [51380.810977] __x64_sys_unlinkat+0x3a/0x70
Aug 7 12:53:00 ruby kernel: [51380.810979] do_syscall_64+0x5c/0xc0
Aug 7 12:53:00 ruby kernel: [51380.810982] ? syscall_exit_to_user_mode+0x27/0x50
Aug 7 12:53:00 ruby kernel: [51380.810984] ? do_syscall_64+0x69/0xc0
Aug 7 12:53:00 ruby kernel: [51380.810986] ? exit_to_user_mode_prepare+0x37/0xb0
Aug 7 12:53:00 ruby kernel: [51380.810990] ? syscall_exit_to_user_mode+0x27/0x50
Aug 7 12:53:00 ruby kernel: [51380.810992] ? do_syscall_64+0x69/0xc0
Aug 7 12:53:00 ruby kernel: [51380.810994] ? do_syscall_64+0x69/0xc0
Aug 7 12:53:00 ruby kernel: [51380.810996] ? do_syscall_64+0x69/0xc0
Aug 7 12:53:00 ruby kernel: [51380.810998] ? do_syscall_64+0x69/0xc0
Aug 7 12:53:00 ruby kernel: [51380.811000] ? do_syscall_64+0x69/0xc0
Aug 7 12:53:00 ruby kernel: [51380.811002] entry_SYSCALL_64_after_hwframe+0x61/0xcb
Aug 7 12:53:00 ruby kernel: [51380.811003] RIP: 0033:0x7fb4a0bd428b
Aug 7 12:53:00 ruby kernel: [51380.811006] Code: 73 01 c3 48 8b 0d a5 2b 10 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa b8 07 01 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 75 2b 10 00 f7 d8 64 89 01 48
Aug 7 12:53:00 ruby kernel: [51380.811007] RSP: 002b:00007fffe7186c58 EFLAGS: 00000246 ORIG_RAX: 0000000000000107
Aug 7 12:53:00 ruby kernel: [51380.811008] RAX: ffffffffffffffda RBX: 000055843d019a10 RCX: 00007fb4a0bd428b
Aug 7 12:53:00 ruby kernel: [51380.811009] RDX: 0000000000000000 RSI: 000055843d019b18 RDI: 0000000000000006
Aug 7 12:53:00 ruby kernel: [51380.811010] RBP: 000055843c7e0440 R08: 0000000000000003 R09: 0000000000000000
Aug 7 12:53:00 ruby kernel: [51380.811011] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000000000
Aug 7 12:53:00 ruby kernel: [51380.811012] R13: 00007fffe7186d80 R14: 0000000000000000 R15: 0000000000000002
Aug 7 12:53:00 ruby kernel: [51380.811014] </TASK>
