I'm not at all sure whether the underlying cause is still the same, but
I'm getting a very similar-looking failure - albeit with different BUG
details - after a reboot a few nights ago into a new kernel.

I can currently reproduce the error on demand, by running
/etc/cron.daily/mlocate (as root) explicitly. When I do so, it exits in
under 15 seconds, with return code 137 and another instance of the BUG
dump in dmesg.

It may or may not be (but I suspect is) relevant that at the moment, one
of my RAID arrays is undergoing a consistency check. I cannot be sure
whether I will still be able to reproduce the problem after that check
finishes.

These checks happen every so often (about once a month or so, I think,
though I haven't kept track of exactly what triggers them; they could
well be on a cron job), and I don't remember seeing this happen during
previous such checks.


The RAID-array details are as follows:


# mdadm --detail /dev/md1
/dev/md1:
           Version : 1.2
     Creation Time : Thu Dec  6 09:15:21 2018
        Raid Level : raid6
        Array Size : 11716780032 (11173.99 GiB 11997.98 GB)
     Used Dev Size : 5858390016 (5587.00 GiB 5998.99 GB)
      Raid Devices : 4
     Total Devices : 4
       Persistence : Superblock is persistent

     Intent Bitmap : Internal

       Update Time : Sun May  3 08:37:38 2020
             State : clean, checking
    Active Devices : 4
   Working Devices : 4
    Failed Devices : 0
     Spare Devices : 0

            Layout : left-symmetric
        Chunk Size : 512K

Consistency Policy : bitmap

      Check Status : 71% complete

              Name : obfuscated:1  (local to host obfuscated)
              UUID : obfuscated
            Events : 71597

    Number   Major   Minor   RaidDevice State
       0       8        1        0      active sync   /dev/sda1
       1       8       17        1      active sync   /dev/sdb1
       2       8       33        2      active sync   /dev/sdc1
       3       8       49        3      active sync   /dev/sdd1


The (first) BUG from dmesg is as follows:


[204955.926690] BUG: unable to handle page fault for address:
ffffffff97693740
[204955.926694] #PF: supervisor write access in kernel mode
[204955.926695] #PF: error_code(0x0002) - not-present page
[204955.926696] PGD 26500e067 P4D 26500e067 PUD 26500f063 PMD 61b527063
PTE 800ffffd9ab6c062
[204955.926699] Oops: 0002 [#1] SMP PTI
[204955.926701] CPU: 1 PID: 27515 Comm: updatedb.mlocat Tainted: G
  W         5.5.0-2-amd64 #1 Debian 5.5.17-1
[204955.926702] Hardware name: System manufacturer System Product
Name/SABERTOOTH X58, BIOS 1402    08/09/2012
[204955.926707] RIP: 0010:native_queued_spin_lock_slowpath+0x13e/0x1d0
[204955.926709] Code: 02 89 c6 c1 e6 10 0f 84 93 00 00 00 c1 ee 12 83 e0
03 83 ee 01 48 c1 e0 05 48 63 f6 48 05 40 d7 02 00 48 03 04 f5 80 f9 16
97 <48> 89 10 8b 42 08 85 c0 75 09 f3 90 8b 42 08 85 c0 74 f7 48 8b 02
[204955.926710] RSP: 0018:ffffa90c42c03c88 EFLAGS: 00010282
[204955.926711] RAX: ffffffff97693740 RBX: ffffa90c42c03d38 RCX:
0000000000080000
[204955.926712] RDX: ffff8d7167a6d740 RSI: 00000000000001ff RDI:
ffff8d6d0eae5c18
[204955.926713] RBP: ffff8d6d0eae5c18 R08: 0000000000080000 R09:
ffff8d6da4ae2020
[204955.926714] R10: ffff8d6d0eae5bc0 R11: 160062617477656e R12:
0000000000000002
[204955.926715] R13: ffffa90c42c03d30 R14: 0000000000000000 R15:
00000000000007ff
[204955.926716] FS:  00007fd94e4f7580(0000) GS:ffff8d7167a40000(0000)
knlGS:0000000000000000
[204955.926717] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[204955.926718] CR2: ffffffff97693740 CR3: 0000000104f42003 CR4:
00000000000206e0
[204955.926719] Call Trace:
[204955.926724]  _raw_spin_lock+0x1a/0x20
[204955.926727]  lockref_get_not_dead+0x4f/0x90
[204955.926731]  legitimize_path.isra.0+0x2d/0x60
[204955.926732]  unlazy_walk+0x36/0x70
[204955.926734]  complete_walk+0x2f/0x80
[204955.926735]  path_lookupat.isra.0+0xb6/0x120
[204955.926736]  filename_lookup+0xae/0x170
[204955.926739]  ? __check_object_size+0x136/0x147
[204955.926741]  ? strncpy_from_user+0x47/0x150
[204955.926743]  vfs_statx+0x7a/0xf0
[204955.926744]  __do_sys_newlstat+0x39/0x70
[204955.926747]  ? __x64_sys_poll+0x9e/0x130
[204955.926750]  do_syscall_64+0x52/0x180
[204955.926752]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[204955.926753] RIP: 0033:0x7fd94e420b66
[204955.926755] Code: e3 0c 00 64 c7 00 16 00 00 00 b8 ff ff ff ff c3 0f
1f 40 00 41 89 f8 48 89 f7 48 89 d6 41 83 f8 01 77 29 b8 06 00 00 00 0f
05 <48> 3d 00 f0 ff ff 77 02 c3 90 48 8b 15 f9 e2 0c 00 f7 d8 64 89 02
[204955.926756] RSP: 002b:00007ffc095603d8 EFLAGS: 00000246 ORIG_RAX:
0000000000000006
[204955.926757] RAX: ffffffffffffffda RBX: 000055eae924e580 RCX:
00007fd94e420b66
[204955.926758] RDX: 00007ffc09560450 RSI: 00007ffc09560450 RDI:
000055eae926d2d9
[204955.926758] RBP: 000055eae926d2d9 R08: 0000000000000001 R09:
000055eae924d5b0
[204955.926759] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000078
[204955.926760] R13: 00007ffc09560630 R14: 0000000000000000 R15:
0000000000000000
[204955.926761] Modules linked in: tun ufs qnx4 hfsplus hfs minix vfat
msdos fat jfs xfs nfsv3 bnep bluetooth drbg ansi_cprng ecdh_generic ecc
rfkill binfmt_misc fuse nfsd auth_rpcgss nfs_acl nfs lockd grace fscache
sunrpc w83627ehf hwmon_vid loop firewire_sbp2 parport_pc ppdev lp
parport intel_powerclamp coretemp kvm_intel kvm irqbypass
crct10dif_pclmul ghash_clmulni_intel radeon snd_usb_audio
snd_hda_codec_realtek snd_hda_codec_generic snd_usbmidi_lib
ledtrig_audio snd_hda_codec_hdmi ttm snd_virtuoso snd_hda_intel
aesni_intel snd_intel_dspcfg snd_oxygen_lib snd_hda_codec
snd_mpu401_uart crypto_simd cryptd snd_rawmidi glue_helper
drm_kms_helper snd_hda_core mc snd_seq_device snd_hwdep snd_pcm_oss
intel_cstate snd_mixer_oss serio_raw pcspkr snd_pcm intel_uncore drm
joydev evdev mxm_wmi snd_timer iTCO_wdt iTCO_vendor_support watchdog snd
soundcore i2c_algo_bit i7core_edac sg i5500_temp button acpi_cpufreq
ext4 crc16 mbcache jbd2 btrfs blake2b_generic zstd_decompress
zstd_compress dm_mod raid10
[204955.926790]  raid0 multipath linear raid456 async_raid6_recov
async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c
crc32c_generic raid1 md_mod sd_mod hid_generic sr_mod cdrom usbhid hid
crc32_pclmul r8169 ahci xhci_pci realtek uhci_hcd libahci xhci_hcd
ehci_pci crc32c_intel firewire_ohci libphy libata ehci_hcd psmouse
firewire_core crc_itu_t usbcore lpc_ich mfd_core scsi_mod i2c_i801
usb_common wmi
[204955.926804] CR2: ffffffff97693740
[204955.926806] ---[ end trace ff3d7f0c82e84c49 ]---


I can't guarantee that there isn't a hardware problem in the SATA
controller on this system, but if so it doesn't seem to have previously
manifested in any other way than intermittently making POST take several
times longer than it normally should. (This does not happen every time,
and it didn't happen at the most recent boot; IIRC, it happens most
frequently when not performing a cold boot, i.e. one after letting the
system sit unpowered for a while.)

(Well, I do have past experience indicating that if I do sustained write
I/O on this array for too long, it stops responding to writes until I
reboot, though I think reads remain fine. That said, I only encountered
that when doing mass replication of large parts of the Debian package
archive, and adding enough sleeps into the middle of the process made it
stop happening. IIRC, I found indication at the time that this was a
known kernel bug that was fixed in a newer version, and I've already
upgraded well past that version.)

-- 
   The Wanderer

The reasonable man adapts himself to the world; the unreasonable one
persists in trying to adapt the world to himself. Therefore all
progress depends on the unreasonable man.         -- George Bernard Shaw

Reply via email to