Greetings, 0day kernel testing robot got the below dmesg and the first bad commit is https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master commit 669de8bda87b92ab9a2fc663b3f5743c2ad1ae9f Author: Bart Van Assche AuthorDate: Thu Feb 14 15:00:54 2019 -0800 Commit: Ingo Molnar CommitDate: Thu Feb 28 07:55:47 2019 +0100 kernel/workqueue: Use dynamic lockdep keys for workqueues The following commit: 87915adc3f0a ("workqueue: re-add lockdep dependencies for flushing") improved deadlock checking in the workqueue implementation. Unfortunately that patch also introduced a few false positive lockdep complaints. This patch suppresses these false positives by allocating the workqueue mutex lockdep key dynamically. An example of a false positive lockdep complaint suppressed by this patch can be found below. The root cause of the lockdep complaint shown below is that the direct I/O code can call alloc_workqueue() from inside a work item created by another alloc_workqueue() call and that both workqueues share the same lockdep key. This patch avoids that that lockdep complaint is triggered by allocating the work queue lockdep keys dynamically. In other words, this patch guarantees that a unique lockdep key is associated with each work queue mutex. ====================================================== WARNING: possible circular locking dependency detected 4.19.0-dbg+ #1 Not tainted fio/4129 is trying to acquire lock: 00000000a01cfe1a ((wq_completion)"dio/%s"sb->s_id){+.+.}, at: flush_workqueue+0xd0/0x970 but task is already holding lock: 00000000a0acecf9 (&sb->s_type->i_mutex_key#14){+.+.}, at: ext4_file_write_iter+0x154/0x710 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #2 (&sb->s_type->i_mutex_key#14){+.+.}: down_write+0x3d/0x80 __generic_file_fsync+0x77/0xf0 ext4_sync_file+0x3c9/0x780 vfs_fsync_range+0x66/0x100 dio_complete+0x2f5/0x360 dio_aio_complete_work+0x1c/0x20 process_one_work+0x481/0x9f0 worker_thread+0x63/0x5a0 kthread+0x1cf/0x1f0 ret_from_fork+0x24/0x30 -> #1 ((work_completion)(&dio->complete_work)){+.+.}: process_one_work+0x447/0x9f0 worker_thread+0x63/0x5a0 kthread+0x1cf/0x1f0 ret_from_fork+0x24/0x30 -> #0 ((wq_completion)"dio/%s"sb->s_id){+.+.}: lock_acquire+0xc5/0x200 flush_workqueue+0xf3/0x970 drain_workqueue+0xec/0x220 destroy_workqueue+0x23/0x350 sb_init_dio_done_wq+0x6a/0x80 do_blockdev_direct_IO+0x1f33/0x4be0 __blockdev_direct_IO+0x79/0x86 ext4_direct_IO+0x5df/0xbb0 generic_file_direct_write+0x119/0x220 __generic_file_write_iter+0x131/0x2d0 ext4_file_write_iter+0x3fa/0x710 aio_write+0x235/0x330 io_submit_one+0x510/0xeb0 __x64_sys_io_submit+0x122/0x340 do_syscall_64+0x71/0x220 entry_SYSCALL_64_after_hwframe+0x49/0xbe other info that might help us debug this: Chain exists of: (wq_completion)"dio/%s"sb->s_id --> (work_completion)(&dio->complete_work) --> &sb->s_type->i_mutex_key#14 Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock(&sb->s_type->i_mutex_key#14); lock((work_completion)(&dio->complete_work)); lock(&sb->s_type->i_mutex_key#14); lock((wq_completion)"dio/%s"sb->s_id); *** DEADLOCK *** 1 lock held by fio/4129: #0: 00000000a0acecf9 (&sb->s_type->i_mutex_key#14){+.+.}, at: ext4_file_write_iter+0x154/0x710 stack backtrace: CPU: 3 PID: 4129 Comm: fio Not tainted 4.19.0-dbg+ #1 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014 Call Trace: dump_stack+0x86/0xc5 print_circular_bug.isra.32+0x20a/0x218 __lock_acquire+0x1c68/0x1cf0 lock_acquire+0xc5/0x200 flush_workqueue+0xf3/0x970 drain_workqueue+0xec/0x220 destroy_workqueue+0x23/0x350 sb_init_dio_done_wq+0x6a/0x80 do_blockdev_direct_IO+0x1f33/0x4be0 __blockdev_direct_IO+0x79/0x86 ext4_direct_IO+0x5df/0xbb0 generic_file_direct_write+0x119/0x220 __generic_file_write_iter+0x131/0x2d0 ext4_file_write_iter+0x3fa/0x710 aio_write+0x235/0x330 io_submit_one+0x510/0xeb0 __x64_sys_io_submit+0x122/0x340 do_syscall_64+0x71/0x220 entry_SYSCALL_64_after_hwframe+0x49/0xbe Signed-off-by: Bart Van Assche Signed-off-by: Peter Zijlstra (Intel) Cc: Andrew Morton Cc: Johannes Berg Cc: Linus Torvalds Cc: Paul E. McKenney Cc: Peter Zijlstra Cc: Tejun Heo Cc: Thomas Gleixner Cc: Waiman Long Cc: Will Deacon Link: https://lkml.kernel.org/r/20190214230058.196511-20-bvanassche@acm.org [ Reworked the changelog a bit. ] Signed-off-by: Ingo Molnar 108c14858b locking/lockdep: Add support for dynamic keys 669de8bda8 kernel/workqueue: Use dynamic lockdep keys for workqueues f90d64483e Merge tag 'usb-5.1-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb cf08baa296 Add linux-next specific files for 20190306 +--------------------------------------------------------------+------------+------------+------------+---------------+ | | 108c14858b | 669de8bda8 | f90d64483e | next-20190306 | +--------------------------------------------------------------+------------+------------+------------+---------------+ | boot_successes | 2811 | 2636 | 865 | 73 | | boot_failures | 15 | 31 | 8 | 1 | | INFO:task_blocked_for_more_than#seconds | 10 | | | | | Kernel_panic-not_syncing:hung_task:blocked_tasks | 10 | | | | | invoked_oom-killer:gfp_mask=0x | 5 | 1 | 3 | | | Mem-Info | 5 | 1 | 3 | | | WARNING:at_kernel/locking/lockdep.c:#lockdep_register_key/0x | 0 | 30 | 5 | 1 | | EIP:lockdep_register_key | 0 | 30 | 5 | 1 | | EIP:__get_user_4 | 0 | 1 | | | | Out_of_memory:Kill_process | 0 | 1 | | | +--------------------------------------------------------------+------------+------------+------------+---------------+ [ 1.855169] spin_lock-torture: lock_torture_stats task started [ 2.565387] workingset: timestamp_bits=14 max_order=17 bucket_order=3 [ 2.567522] NFS: Registering the id_resolver key type [ 2.568478] Key type id_resolver registered [ 2.569072] Key type id_legacy registered [ 2.570808] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:995 lockdep_register_key+0x37/0x386 [ 2.571658] CPU: 0 PID: 1 Comm: swapper Not tainted 5.0.0-rc8-00054-g669de8b #496 [ 2.571658] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014 [ 2.571658] EIP: lockdep_register_key+0x37/0x386 [ 2.571658] Code: 20 45 65 94 01 83 15 24 45 65 94 00 81 fe 00 00 80 92 72 2e 81 fe 00 d0 88 95 73 26 83 05 40 45 65 94 01 83 15 44 45 65 94 00 <0f> 0b 83 05 48 45 65 94 01 83 15 4c 45 65 94 00 83 c4 1c 5b 5e 5f [ 2.571658] EAX: 9586d254 EBX: 9586d1c0 ECX: 944f9cd8 EDX: 00000000 [ 2.571658] ESI: 9586d254 EDI: 9586d274 EBP: 975a9ee4 ESP: 975a9ebc [ 2.571658] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00210246 [ 2.571658] CR0: 80050033 CR2: 00000000 CR3: 1c4a5000 CR4: 00340690 [ 2.571658] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 2.571658] DR6: fffe0ff0 DR7: 00000400 [ 2.571658] Call Trace: [ 2.571658] ? debug_mutex_init+0x4b/0x63 [ 2.571658] ? __mutex_init+0x59/0x6c [ 2.571658] alloc_workqueue+0x227/0x84e [ 2.571658] ? proc_create+0x3e/0x52 [ 2.571658] ? trace_event_define_fields_smb3_rw_err_class+0x1b9/0x1b9 [ 2.571658] init_cifs+0x159/0x72f [ 2.571658] do_one_initcall+0x2c4/0x6bf [ 2.571658] kernel_init_freeable+0x6ef/0x841 [ 2.571658] ? rest_init+0x473/0x473 [ 2.571658] kernel_init+0x1e/0x26b [ 2.571658] ? schedule_tail_wrapper+0x9/0xc [ 2.571658] ret_from_fork+0x1e/0x28 [ 2.571658] irq event stamp: 410062 [ 2.571658] hardirqs last enabled at (410061): [<93a2ac73>] _raw_spin_unlock_irqrestore+0x133/0x17e [ 2.571658] hardirqs last disabled at (410062): [<92801bca>] trace_hardirqs_off_thunk+0xc/0x10 [ 2.571658] softirqs last enabled at (409970): [<93a2da14>] __do_softirq+0x904/0xa1d [ 2.571658] softirqs last disabled at (409965): [<92813eb9>] do_softirq_own_stack+0x3d/0x51 [ 2.571658] ---[ end trace c4eabde80fbbdbf0 ]--- [ 3.753943] String selftests succeeded # HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD git bisect start f32e0bde8ff712363cbfb98e9d2f90cfe98b208e 1c163f4c7b3f621efff9b28a47abb36f7378d783 -- git bisect bad 086da5d945417d7f23267ba57285baf5f28db938 # 11:42 B 869 9 0 34 Merge 'linux-review/David-Ahern/selftests-rtnetlink-use-internal-netns-switch-for-ip-commands/20190301-033905' into devel-hourly-2019030702 git bisect good 41d8a6d69a8b740e03d7bf2bb8335da4da5fdba5 # 12:30 G 900 0 35 51 Merge 'linux-review/UPDATE-20190303-105904/Jan-Stancek/mm-memory-c-do_fault-avoid-usage-of-stale-vm_area_struct/20190303-093100' into devel-hourly-2019030702 git bisect bad b9a411fadefdb5d73d8eea17ce986179ad71840d # 12:50 B 148 1 10 10 Merge 'linux-review/Felix-Fietkau/mt76-rewrite-dma-descriptor-base-and-ring-size-on-queue-reset/20190302-050418' into devel-hourly-2019030702 git bisect bad 0a6be0079c3c20149485bc92250e45d84d075541 # 13:06 B 57 1 7 7 Merge 'linux-review/Heiner-Kallweit/net-dsa-mv8e6xxx-fix-number-of-internal-PHYs-for-88E6x90-family/20190302-202650' into devel-hourly-2019030702 git bisect good 821ec529ff50b8937708f47f094287f6e2b49e16 # 13:52 G 909 0 50 50 Merge 'linux-review/Chao-Yu/f2fs-fix-to-do-sanity-check-with-inode-i_inline_xattr_size/20190304-203228' into devel-hourly-2019030702 git bisect good 67af7dacace3a333b1d881b95dc689a2dd9e2589 # 14:30 G 905 0 52 52 Merge 'linux-review/Kimberly-Brown/Drivers-hv-vmbus-Expose-monitor-data-only-when-monitor-pages-are-used/20190302-231508' into devel-hourly-2019030702 git bisect good 46f2ee728daf6a85ca1e353d4fafd9be2ce7ddfd # 15:28 G 901 0 49 53 Merge 'linux-review/Yue-Haibing/net-sysfs-Fix-mem-leak-in-netdev_register_kobject/20190302-220141' into devel-hourly-2019030702 git bisect good 3f1a8f0976fe16a388c23feeb38a860caf826fa0 # 16:26 G 901 0 52 58 Merge 'linux-review/Yufen-Yu/hugetlbfs-fix-memory-leak-for-resv_map/20190302-214353' into devel-hourly-2019030702 git bisect good 8d8ae51f4bf9515ed07cb438037a129a0851bc60 # 17:22 G 901 0 49 58 Merge 'linux-review/Govind-Singh/ath10k-Modify-CE4-src-buffer-entries-to-2048-for-WCN3990/20190302-210221' into devel-hourly-2019030702 git bisect bad 36d329873d82094062917361129c8ef95addbb65 # 17:45 B 73 1 6 6 Merge 'peterz-queue/locking/core' into devel-hourly-2019030702 git bisect good 0614621d89c43ea5b28456c2baf6b0c0e00ca81e # 18:36 G 905 0 46 60 Merge branch 'linus' into locking/core, to pick up fixes git bisect good a0b0fd53e1e67639b303b15939b9c653dbe7a8c4 # 19:32 G 900 0 50 63 locking/lockdep: Free lock classes that are no longer in use git bisect good 108c14858b9ea224686e476c8f5ec345a0df9e27 # 20:31 G 908 0 43 53 locking/lockdep: Add support for dynamic keys git bisect bad f214737b75b0ee79763b5c058b9d5e83d711348d # 21:06 B 101 1 11 19 lockdep/lib/tests: Test dynamic key registration git bisect bad d93ac78bf7b37db36fa00225f8e9a14c7ed1b2ba # 21:53 B 44 1 3 3 lockdep/lib/tests: Fix run_tests.sh git bisect bad 669de8bda87b92ab9a2fc663b3f5743c2ad1ae9f # 22:31 B 155 3 12 28 kernel/workqueue: Use dynamic lockdep keys for workqueues # first bad commit: [669de8bda87b92ab9a2fc663b3f5743c2ad1ae9f] kernel/workqueue: Use dynamic lockdep keys for workqueues git bisect good 108c14858b9ea224686e476c8f5ec345a0df9e27 # 23:11 G 1002 0 9 62 locking/lockdep: Add support for dynamic keys # extra tests on HEAD of linux-devel/devel-hourly-2019030702 git bisect bad f32e0bde8ff712363cbfb98e9d2f90cfe98b208e # 23:11 B 10 2 0 1 0day head guard for 'devel-hourly-2019030702' # extra tests on tree/branch linus/master git bisect bad f90d64483ebd394958841f67f8794ab203b319a7 # 23:53 B 468 1 22 22 Merge tag 'usb-5.1-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb # extra tests with first bad commit reverted git bisect good f2abe7f085951f49dc69a634d74a4d027d77c9f7 # 12:42 G 907 0 55 55 Revert "kernel/workqueue: Use dynamic lockdep keys for workqueues" # extra tests on tree/branch linux-next/master git bisect bad cf08baa29613dd899954089e7cc7dba1d478b365 # 12:46 B 11 1 0 0 Add linux-next specific files for 20190306 --- 0-DAY kernel test infrastructure Open Source Technology Center https://lists.01.org/pipermail/lkp Intel Corporation