hfsplus truncation can crash/hang 5.19 kernels

[Colin Ian King]

 uname -a
Linux kinetic-amd64-efi 5.19.0-19-generic #19-Ubuntu SMP PREEMPT_DYNAMIC Tue Sep 27 16:03:25 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

How to reproduce:

git clone https://github.com/ColinIanKing/stress-ng
cd stress-ng
make clean
make -j 8
cd

pwd
/home/cking

dd if=/dev/zero of=test.img bs=1M count=1024
mkfs.hfsplus test.img
sudo mount -o loop /home/cking/test.img /mnt
sudo ./stress-ng/stress-ng --hdd 8 --temp-path=/mnt -v --verify --klog-check -t 20

An 8 concurrent hdd stressor produces the following, whereas using many instances (eg. 64) will crash/hang the kernel in quite a few tests.

stress-ng: debug: [1243] invoked with './stress-ng/stress-ng --hdd 8 --temp-path=/mnt -v --verify --klog-check -t 20' by user 0 'root'
stress-ng: debug: [1243] stress-ng 0.14.06 g54f1939abd9a
stress-ng: debug: [1243] system: Linux kinetic-amd64-efi 5.19.0-19-generic #19-Ubuntu SMP PREEMPT_DYNAMIC Tue Sep 27 16:03:25 UTC 2022 x86_64
stress-ng: debug: [1243] RAM total: 3.8G, RAM free: 2.3G, swap free: 0.0
stress-ng: debug: [1243] temporary file path: '/mnt', filesystem type: hfsplus
stress-ng: debug: [1243] 8 processors online, 8 processors configured
stress-ng: info: [1243] setting to a 20 second run per stressor
stress-ng: info: [1243] dispatching hogs: 8 hdd
stress-ng: debug: [1243] cache allocate: shared cache buffer size: 16384K
stress-ng: debug: [1243] starting stressors
stress-ng: debug: [1245] stress-ng-hdd: started [1245] (instance 0)
stress-ng: debug: [1246] stress-ng-hdd: started [1246] (instance 1)
stress-ng: debug: [1247] stress-ng-hdd: started [1247] (instance 2)
stress-ng: debug: [1248] stress-ng-hdd: started [1248] (instance 3)
stress-ng: debug: [1249] stress-ng-hdd: started [1249] (instance 4)
stress-ng: debug: [1250] stress-ng-hdd: started [1250] (instance 5)
stress-ng: debug: [1243] 8 stressors started
stress-ng: debug: [1251] stress-ng-hdd: started [1251] (instance 6)
stress-ng: debug: [1252] stress-ng-hdd: started [1252] (instance 7)
stress-ng: info: [1244] klog-check: warning: [485.934368] '------------[ cut here ]------------'
stress-ng: info: [1244] klog-check: warning: [485.934381] 'WARNING: CPU: 3 PID: 1246 at fs/hfsplus/extents.c:346 hfsplus_free_extents+0x110/0x120 [hfsplus]'
stress-ng: info: [1244] klog-check: warning: [485.934392] 'Modules linked in: nls_utf8 hfsplus cfg80211 nls_iso8859_1 snd_hda_codec_generic intel_rapl_msr ledtrig_audio pktcdvd intel_rapl_common snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec snd_hda_core snd_hwdep kvm_intel snd_pcm kvm snd_timer snd input_leds serio_raw soundcore joydev ppdev mac_hid rapl parport_pc parport dm_multipath ramoops scsi_dh_rdac scsi_dh_emc scsi_dh_alua pstore_blk msr pstore_zone reed_solomon efi_pstore qemu_fw_cfg ip_tables x_tables autofs4 btrfs blake2b_generic raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear hid_generic usbhid hid crct10dif_pclmul qxl crc32_pclmul ghash_clmulni_intel aesni_intel drm_ttm_helper ttm virtio_rng crypto_simd drm_kms_helper cryptd psmouse syscopyarea sysfillrect sysimgblt fb_sys_fops i2c_i801 virtio_net virtio_blk ahci net_failover xhci_pci libahci i2c_smbus lpc_ich drm failover xhci_pci_renesas'
stress-ng: info: [1244] klog-check: warning: [485.934470] 'CPU: 3 PID: 1246 Comm: stress-ng Not tainted 5.19.0-19-generic #19-Ubuntu'
stress-ng: info: [1244] klog-check: warning: [485.934473] 'Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015'
stress-ng: info: [1244] klog-check: warning: [485.934475] 'RIP: 0010:hfsplus_free_extents+0x110/0x120 [hfsplus]'
stress-ng: info: [1244] klog-check: warning: [485.934481] 'Code: de 73 ad 44 29 f3 44 89 f2 4c 89 c7 01 de e8 d7 89 00 00 41 89 c7 85 c0 0f 85 aa b4 00 00 0f cb 41 89 5c 24 04 e9 5a ff ff ff <0f> 0b e9 2e ff ff ff 66 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55'
stress-ng: info: [1244] klog-check: warning: [485.934483] 'RSP: 0018:ffffac9700c7bcf8 EFLAGS: 00010202'
stress-ng: info: [1244] klog-check: warning: [485.934486] 'RAX: ffff9bb79a11cc01 RBX: 0000000000000080 RCX: 0000000000000740'
stress-ng: info: [1244] klog-check: warning: [485.934488] 'RDX: 0000000000000080 RSI: ffff9bb79a533c58 RDI: 0000000000000000'
stress-ng: info: [1244] klog-check: warning: [485.934489] 'RBP: ffffac9700c7bd28 R08: ffff9bb78f5a5000 R09: 0000000000000000'
stress-ng: info: [1244] klog-check: warning: [485.934491] 'R10: 0000000000000000 R11: 0000000000000000 R12: ffff9bb79a533c58'
stress-ng: info: [1244] klog-check: warning: [485.934493] 'R13: 0000000000000000 R14: 0000000000000740 R15: 0000000000000000'
stress-ng: info: [1244] klog-check: warning: [485.934494] 'FS: 00007f7621a13680(0000) GS:ffff9bb7fbcc0000(0000) knlGS:0000000000000000'
stress-ng: info: [1244] klog-check: warning: [485.934497] 'CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033'
stress-ng: info: [1244] klog-check: warning: [485.934498] 'CR2: 000055fa539cf000 CR3: 0000000118240004 CR4: 0000000000370ee0'
stress-ng: info: [1244] klog-check: warning: [485.934503] 'DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000'
stress-ng: info: [1244] klog-check: warning: [485.934504] 'DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400'
stress-ng: info: [1244] klog-check: warning: [485.934506] 'Call Trace:'
stress-ng: info: [1244] klog-check: warning: [485.934508] ' <TASK>'
stress-ng: info: [1244] klog-check: warning: [485.934511] ' hfsplus_file_truncate+0x2e9/0x430 [hfsplus]'
stress-ng: info: [1244] klog-check: warning: [485.934518] ' hfsplus_delete_inode+0x68/0x90 [hfsplus]'
stress-ng: info: [1244] klog-check: warning: [485.934524] ' hfsplus_file_release+0x93/0xa0 [hfsplus]'
stress-ng: info: [1244] klog-check: warning: [485.934529] ' __fput+0x95/0x270'
stress-ng: info: [1244] klog-check: warning: [485.934533] ' ____fput+0xe/0x20'
stress-ng: info: [1244] klog-check: warning: [485.934536] ' task_work_run+0x61/0xa0'
stress-ng: info: [1244] klog-check: warning: [485.934540] ' exit_to_user_mode_loop+0xfc/0x130'
stress-ng: info: [1244] klog-check: warning: [485.934545] ' exit_to_user_mode_prepare+0xa5/0xb0'
stress-ng: info: [1244] klog-check: warning: [485.934548] ' syscall_exit_to_user_mode+0x26/0x50'
stress-ng: info: [1244] klog-check: warning: [485.934552] ' ? __x64_sys_close+0x11/0x50'
stress-ng: info: [1244] klog-check: warning: [485.934554] ' do_syscall_64+0x67/0x90'
stress-ng: info: [1244] klog-check: warning: [485.934556] ' ? exit_to_user_mode_prepare+0x30/0xb0'
stress-ng: info: [1244] klog-check: warning: [485.934560] ' ? syscall_exit_to_user_mode+0x26/0x50'
stress-ng: info: [1244] klog-check: warning: [485.934562] ' ? __x64_sys_read+0x19/0x30'
stress-ng: info: [1244] klog-check: warning: [485.934565] ' ? do_syscall_64+0x67/0x90'
stress-ng: info: [1244] klog-check: warning: [485.934567] ' ? do_syscall_64+0x67/0x90'
stress-ng: info: [1244] klog-check: warning: [485.934569] ' ? sysvec_apic_timer_interrupt+0x4b/0xd0'
stress-ng: info: [1244] klog-check: warning: [485.934571] ' entry_SYSCALL_64_after_hwframe+0x63/0xcd'
stress-ng: info: [1244] klog-check: warning: [485.934580] 'RIP: 0033:0x7f762190d224'
stress-ng: info: [1244] klog-check: warning: [485.934583] 'Code: eb b2 e8 ef 20 02 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 f3 0f 1e fa 80 3d bd 13 0f 00 00 74 13 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 44 c3 0f 1f 00 48 83 ec 18 89 7c 24 0c e8 53'
stress-ng: info: [1244] klog-check: warning: [485.934584] 'RSP: 002b:00007ffdd0dc0148 EFLAGS: 00000202 ORIG_RAX: 0000000000000003'
stress-ng: info: [1244] klog-check: warning: [485.934586] 'RAX: 0000000000000000 RBX: 00007ffdd0dc1380 RCX: 00007f762190d224'
stress-ng: info: [1244] klog-check: warning: [485.934587] 'RDX: 0000000000010000 RSI: 000000000003ffff RDI: 0000000000000004'
stress-ng: info: [1244] klog-check: warning: [485.934589] 'RBP: 0000000000000004 R08: 0000000007ff0001 R09: 00000000ffffffff'
stress-ng: info: [1244] klog-check: warning: [485.934590] 'R10: 0000000000001000 R11: 0000000000000202 R12: 0000000008000000'
stress-ng: info: [1244] klog-check: warning: [485.934591] 'R13: 0000000000000000 R14: 000055fa539c0000 R15: 00007ffdd0dc02c0'
stress-ng: info: [1244] klog-check: warning: [485.934594] ' </TASK>'
stress-ng: info: [1244] klog-check: warning: [485.934598] '---[ end trace 0000000000000000 ]---'

Issue also occurs with 6.0 kernel :-(

[Ubuntu Kernel Bot (ubuntu-kernel-bot)]

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1992298

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

[Colin Ian King (colin-king)]

Seems OK on Xenial 4.4 and Bionic 4.19 kernels, no crashing there.

[Colin Ian King (colin-king)]

Issue occurs on a Jammy 5.15.0-48 kernel, so this is not a regression for the 5.19 kernel, but occurred earlier.

[Colin Ian King (colin-king)]

Occurs also on Focal 5.4.0-126-generic. I recommend running with at least 8-16 stess-ng --hdd stressor instances to trigger the crash quickly.

[Utkarsh Gupta (utkarsh)]

Ubuntu 22.10 (Kinetic Kudu) has reached end of life, so this bug will not be fixed for that specific release.