[systemd-devel] 5.2rc2, circular lock warning systemd-journal and btrfs_page_mkwrite
Chris Murphy
lists at colorremedies.com
Tue Jun 4 18:24:12 UTC 2019
This is on Fedora Rawhide
systemd-242-3.git7a6d834.fc31.x86_64
kernel 5.2.0-0.rc2.git1.2.fc31.x86_64
Pretty and complete log:
https://drive.google.com/open?id=1vhnIki9lpiWK8T5Qsl81_RToQ8CFdnfU
Probably MUA wrapped, and excerpt only:
[ 7.816458] fmac.local systemd[1]: Starting Flush Journal to
Persistent Storage...
[ 7.833724] fmac.local systemd-journald[642]: Time spent on
flushing to /var is 83.426ms for 5804 entries.
[ 7.833724] fmac.local systemd-journald[642]: System journal
(/var/log/journal/6d5657355b064460b154f7f5da220b50) is 48.0M, max
4.0G, 3.9G free.
[ 7.886889] fmac.local kernel:
[ 7.886892] fmac.local kernel:
======================================================
[ 7.886893] fmac.local kernel: WARNING: possible circular locking
dependency detected
[ 7.886895] fmac.local kernel: 5.2.0-0.rc2.git1.2.fc31.x86_64 #1 Not tainted
[ 7.886896] fmac.local kernel:
------------------------------------------------------
[ 7.886897] fmac.local kernel: systemd-journal/642 is trying to acquire lock:
[ 7.886899] fmac.local kernel: (____ptrval____)
(&fs_info->reloc_mutex){+.+.}, at:
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.886926] fmac.local kernel:
but task is already holding lock:
[ 7.886926] fmac.local kernel: (____ptrval____)
(sb_pagefaults){.+.+}, at: btrfs_page_mkwrite+0x69/0x570 [btrfs]
[ 7.886943] fmac.local kernel:
which lock already depends on the new lock.
[ 7.886944] fmac.local kernel:
the existing dependency chain (in
reverse order) is:
[ 7.886945] fmac.local kernel:
-> #6 (sb_pagefaults){.+.+}:
[ 7.886949] fmac.local kernel: __sb_start_write+0x12b/0x1b0
[ 7.886965] fmac.local kernel: btrfs_page_mkwrite+0x69/0x570 [btrfs]
[ 7.886970] fmac.local kernel: do_page_mkwrite+0x2f/0x100
[ 7.886973] fmac.local kernel: do_wp_page+0x306/0x570
[ 7.886975] fmac.local kernel: __handle_mm_fault+0xce8/0x1730
[ 7.886976] fmac.local kernel: handle_mm_fault+0x16e/0x370
[ 7.886978] fmac.local kernel: do_user_addr_fault+0x1f9/0x480
[ 7.886980] fmac.local kernel: do_page_fault+0x33/0x210
[ 7.886983] fmac.local kernel: page_fault+0x1e/0x30
[ 7.886984] fmac.local kernel:
-> #5 (&mm->mmap_sem#2){++++}:
[ 7.886987] fmac.local kernel: __might_fault+0x60/0x80
[ 7.886989] fmac.local kernel: _copy_from_user+0x1e/0x90
[ 7.886992] fmac.local kernel: scsi_cmd_ioctl+0x218/0x440
[ 7.886994] fmac.local kernel: cdrom_ioctl+0x3c/0x1272
[ 7.886997] fmac.local kernel: sr_block_ioctl+0xa0/0xd0
[ 7.886998] fmac.local kernel: blkdev_ioctl+0x32b/0xad0
[ 7.887001] fmac.local kernel: block_ioctl+0x3f/0x50
[ 7.887003] fmac.local kernel: do_vfs_ioctl+0x400/0x740
[ 7.887004] fmac.local kernel: ksys_ioctl+0x5e/0x90
[ 7.887005] fmac.local kernel: __x64_sys_ioctl+0x16/0x20
[ 7.887008] fmac.local kernel: do_syscall_64+0x5c/0xa0
[ 7.887010] fmac.local kernel:
entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 7.887011] fmac.local kernel:
-> #4 (sr_mutex){+.+.}:
[ 7.887014] fmac.local kernel: __mutex_lock+0x92/0x930
[ 7.887016] fmac.local kernel: sr_block_open+0x81/0x100
[ 7.887018] fmac.local kernel: __blkdev_get+0xed/0x590
[ 7.887019] fmac.local kernel: blkdev_get+0x4a/0x380
[ 7.887021] fmac.local kernel: do_dentry_open+0x14c/0x3c0
[ 7.887022] fmac.local kernel: path_openat+0x4e6/0xca0
[ 7.887024] fmac.local kernel: do_filp_open+0x91/0x100
[ 7.887025] fmac.local kernel: do_sys_open+0x184/0x220
[ 7.887027] fmac.local kernel: do_syscall_64+0x5c/0xa0
[ 7.887028] fmac.local kernel:
entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 7.887029] fmac.local kernel:
-> #3 (&bdev->bd_mutex){+.+.}:
[ 7.887032] fmac.local kernel: __mutex_lock+0x92/0x930
[ 7.887033] fmac.local kernel: __blkdev_get+0x7a/0x590
[ 7.887034] fmac.local kernel: blkdev_get+0x214/0x380
[ 7.887036] fmac.local kernel: blkdev_get_by_path+0x46/0x80
[ 7.887053] fmac.local kernel: btrfs_get_bdev_and_sb+0x1b/0xb0 [btrfs]
[ 7.887069] fmac.local kernel: open_fs_devices+0x7a/0x2a0 [btrfs]
[ 7.887086] fmac.local kernel: btrfs_open_devices+0x92/0xa0 [btrfs]
[ 7.887097] fmac.local kernel: btrfs_mount_root+0x30b/0x690 [btrfs]
[ 7.887099] fmac.local kernel: legacy_get_tree+0x30/0x50
[ 7.887102] fmac.local kernel: vfs_get_tree+0x28/0xf0
[ 7.887104] fmac.local kernel: fc_mount+0xe/0x40
[ 7.887106] fmac.local kernel: vfs_kern_mount.part.0+0x71/0x90
[ 7.887117] fmac.local kernel: btrfs_mount+0x155/0x8b0 [btrfs]
[ 7.887119] fmac.local kernel: legacy_get_tree+0x30/0x50
[ 7.887121] fmac.local kernel: vfs_get_tree+0x28/0xf0
[ 7.887123] fmac.local kernel: do_mount+0x7f5/0xaa0
[ 7.887124] fmac.local kernel: ksys_mount+0x7e/0xc0
[ 7.887126] fmac.local kernel: __x64_sys_mount+0x21/0x30
[ 7.887128] fmac.local kernel: do_syscall_64+0x5c/0xa0
[ 7.887129] fmac.local kernel:
entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 7.887130] fmac.local kernel:
-> #2 (&fs_devs->device_list_mutex){+.+.}:
[ 7.887132] fmac.local kernel: __mutex_lock+0x92/0x930
[ 7.887149] fmac.local kernel: btrfs_run_dev_stats+0x46/0x3e0 [btrfs]
[ 7.887163] fmac.local kernel: commit_cowonly_roots+0xb5/0x300 [btrfs]
[ 7.887177] fmac.local kernel:
btrfs_commit_transaction+0x4e7/0xa30 [btrfs]
[ 7.887192] fmac.local kernel: btrfs_sync_file+0x38d/0x4b0 [btrfs]
[ 7.887193] fmac.local kernel: do_fsync+0x38/0x70
[ 7.887195] fmac.local kernel: __x64_sys_fsync+0x10/0x20
[ 7.887196] fmac.local kernel: do_syscall_64+0x5c/0xa0
[ 7.887198] fmac.local kernel:
entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 7.887198] fmac.local kernel:
-> #1 (&fs_info->tree_log_mutex){+.+.}:
[ 7.887201] fmac.local kernel: __mutex_lock+0x92/0x930
[ 7.887215] fmac.local kernel:
btrfs_commit_transaction+0x48f/0xa30 [btrfs]
[ 7.887230] fmac.local kernel: btrfs_sync_file+0x38d/0x4b0 [btrfs]
[ 7.887231] fmac.local kernel: do_fsync+0x38/0x70
[ 7.887232] fmac.local kernel: __x64_sys_fsync+0x10/0x20
[ 7.887234] fmac.local kernel: do_syscall_64+0x5c/0xa0
[ 7.887235] fmac.local kernel:
entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 7.887236] fmac.local kernel:
-> #0 (&fs_info->reloc_mutex){+.+.}:
[ 7.887239] fmac.local kernel: lock_acquire+0xa2/0x1b0
[ 7.887241] fmac.local kernel: __mutex_lock+0x92/0x930
[ 7.887255] fmac.local kernel:
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887269] fmac.local kernel: start_transaction+0x95/0x4f0 [btrfs]
[ 7.887283] fmac.local kernel: btrfs_dirty_inode+0x44/0xd0 [btrfs]
[ 7.887284] fmac.local kernel: file_update_time+0xeb/0x140
[ 7.887299] fmac.local kernel: btrfs_page_mkwrite+0xfe/0x570 [btrfs]
[ 7.887301] fmac.local kernel: do_page_mkwrite+0x2f/0x100
[ 7.887303] fmac.local kernel: do_wp_page+0x306/0x570
[ 7.887304] fmac.local kernel: __handle_mm_fault+0xce8/0x1730
[ 7.887306] fmac.local kernel: handle_mm_fault+0x16e/0x370
[ 7.887307] fmac.local kernel: do_user_addr_fault+0x1f9/0x480
[ 7.887308] fmac.local kernel: do_page_fault+0x33/0x210
[ 7.887310] fmac.local kernel: page_fault+0x1e/0x30
[ 7.887311] fmac.local kernel:
other info that might help us debug this:
[ 7.887312] fmac.local kernel: Chain exists of:
&fs_info->reloc_mutex -->
&mm->mmap_sem#2 --> sb_pagefaults
[ 7.887314] fmac.local kernel: Possible unsafe locking scenario:
[ 7.887315] fmac.local kernel: CPU0 CPU1
[ 7.887316] fmac.local kernel: ---- ----
[ 7.887316] fmac.local kernel: lock(sb_pagefaults);
[ 7.887317] fmac.local kernel:
lock(&mm->mmap_sem#2);
[ 7.887319] fmac.local kernel:
lock(sb_pagefaults);
[ 7.887320] fmac.local kernel: lock(&fs_info->reloc_mutex);
[ 7.887321] fmac.local kernel:
*** DEADLOCK ***
[ 7.887323] fmac.local kernel: 3 locks held by systemd-journal/642:
[ 7.887323] fmac.local kernel: #0: (____ptrval____)
(&mm->mmap_sem#2){++++}, at: do_user_addr_fault+0x12b/0x480
[ 7.887326] fmac.local kernel: #1: (____ptrval____)
(sb_pagefaults){.+.+}, at: btrfs_page_mkwrite+0x69/0x570 [btrfs]
[ 7.887342] fmac.local kernel: #2: (____ptrval____)
(sb_internal){.+.+}, at: start_transaction+0x37f/0x4f0 [btrfs]
[ 7.887357] fmac.local kernel:
stack backtrace:
[ 7.887359] fmac.local kernel: CPU: 1 PID: 642 Comm:
systemd-journal Not tainted 5.2.0-0.rc2.git1.2.fc31.x86_64 #1
[ 7.887360] fmac.local kernel: Hardware name: Apple Inc.
MacBookPro8,2/Mac-94245A3940C91C80, BIOS
MBP81.88Z.0050.B00.1804101331 04/10/18
[ 7.887361] fmac.local kernel: Call Trace:
[ 7.887365] fmac.local kernel: dump_stack+0x85/0xc0
[ 7.887367] fmac.local kernel: print_circular_bug.cold+0x15c/0x195
[ 7.887370] fmac.local kernel: __lock_acquire+0x165b/0x1c30
[ 7.887373] fmac.local kernel: ? find_held_lock+0x32/0x90
[ 7.887375] fmac.local kernel: ? sched_clock+0x5/0x10
[ 7.887378] fmac.local kernel: lock_acquire+0xa2/0x1b0
[ 7.887392] fmac.local kernel: ?
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887406] fmac.local kernel: ?
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887408] fmac.local kernel: __mutex_lock+0x92/0x930
[ 7.887422] fmac.local kernel: ?
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887425] fmac.local kernel: ? rcu_read_lock_sched_held+0x6b/0x80
[ 7.887427] fmac.local kernel: ? module_assert_mutex_or_preempt+0x14/0x40
[ 7.887441] fmac.local kernel: ?
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887443] fmac.local kernel: ? sched_clock_cpu+0xc/0xc0
[ 7.887458] fmac.local kernel: ?
btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887471] fmac.local kernel: btrfs_record_root_in_trans+0x44/0x70 [btrfs]
[ 7.887486] fmac.local kernel: start_transaction+0x95/0x4f0 [btrfs]
[ 7.887501] fmac.local kernel: btrfs_dirty_inode+0x44/0xd0 [btrfs]
[ 7.887503] fmac.local kernel: file_update_time+0xeb/0x140
[ 7.887518] fmac.local kernel: btrfs_page_mkwrite+0xfe/0x570 [btrfs]
[ 7.887520] fmac.local kernel: ? find_held_lock+0x32/0x90
[ 7.887522] fmac.local kernel: ? sched_clock+0x5/0x10
[ 7.887524] fmac.local kernel: do_page_mkwrite+0x2f/0x100
[ 7.887526] fmac.local kernel: do_wp_page+0x306/0x570
[ 7.887529] fmac.local kernel: __handle_mm_fault+0xce8/0x1730
[ 7.887532] fmac.local kernel: handle_mm_fault+0x16e/0x370
[ 7.887534] fmac.local kernel: do_user_addr_fault+0x1f9/0x480
[ 7.887536] fmac.local kernel: do_page_fault+0x33/0x210
[ 7.887538] fmac.local kernel: ? page_fault+0x8/0x30
[ 7.887540] fmac.local kernel: page_fault+0x1e/0x30
[ 7.887541] fmac.local kernel: RIP: 0033:0x7f97107ea383
[ 7.887544] fmac.local kernel: Code: ec 08 89 ee 49 89 d8 31 d2 6a
00 48 8b 4c 24 18 4c 89 f7 4c 8d 4c 24 30 e8 1a d8 ff ff 59 5e 85 c0
78 49 48 8b 44 24 20 31 d2 <48> 89 58 08 48 8b 5c 24 08 c7 40 01 00 00
00 00 66 89 50 05 c6 40
[ 7.887545] fmac.local kernel: RSP: 002b:00007ffc79ed77a0 EFLAGS: 00010246
[ 7.887546] fmac.local kernel: RAX: 00007f970eca84a8 RBX:
000000000000005d RCX: 0000000000000000
[ 7.887548] fmac.local kernel: RDX: 0000000000000000 RSI:
00007f97107ea408 RDI: 000055d0300e8160
[ 7.887549] fmac.local kernel: RBP: 0000000000000001 R08:
0000000000000001 R09: 000055d0300e8160
[ 7.887550] fmac.local kernel: R10: 00007ffc79f6a080 R11:
00000000000035fc R12: 00007ffc79ed78c8
[ 7.887551] fmac.local kernel: R13: 00007ffc79ed78c0 R14:
000055d0300efa60 R15: 0000000000c3d9ef
--
Chris Murphy
More information about the systemd-devel
mailing list