lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:   Fri, 08 Mar 2019 12:48:07 +0800
From:   kernel test robot <lkp@...el.com>
To:     Bart Van Assche <bvanassche@....org>
Cc:     LKP <lkp@...org>, linux-kernel@...r.kernel.org,
        "Peter Zijlstra (Intel)" <peterz@...radead.org>,
        Ingo Molnar <mingo@...nel.org>
Subject: 669de8bda8 ("kernel/workqueue: Use dynamic lockdep keys for .."):  WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:995 lockdep_register_key

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 <bvanassche@....org>
AuthorDate: Thu Feb 14 15:00:54 2019 -0800
Commit:     Ingo Molnar <mingo@...nel.org>
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 <bvanassche@....org>
    Signed-off-by: Peter Zijlstra (Intel) <peterz@...radead.org>
    Cc: Andrew Morton <akpm@...ux-foundation.org>
    Cc: Johannes Berg <johannes.berg@...el.com>
    Cc: Linus Torvalds <torvalds@...ux-foundation.org>
    Cc: Paul E. McKenney <paulmck@...ux.vnet.ibm.com>
    Cc: Peter Zijlstra <peterz@...radead.org>
    Cc: Tejun Heo <tj@...nel.org>
    Cc: Thomas Gleixner <tglx@...utronix.de>
    Cc: Waiman Long <longman@...hat.com>
    Cc: Will Deacon <will.deacon@....com>
    Link: https://lkml.kernel.org/r/20190214230058.196511-20-bvanassche@acm.org
    [ Reworked the changelog a bit. ]
    Signed-off-by: Ingo Molnar <mingo@...nel.org>

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

Download attachment "dmesg-openwrt-vm-openwrt-111:20190307222808:i386-randconfig-s1-201909:5.0.0-rc8-00054-g669de8b:496.gz" of type "application/gzip" (13512 bytes)

Download attachment "dmesg-openwrt-vm-openwrt-216:20190307195050:i386-randconfig-s1-201909:5.0.0-rc8-00053-g108c148:480.gz" of type "application/gzip" (14298 bytes)

View attachment "reproduce-openwrt-vm-openwrt-111:20190307222808:i386-randconfig-s1-201909:5.0.0-rc8-00054-g669de8b:496" of type "text/plain" (912 bytes)

View attachment "config-5.0.0-rc8-00054-g669de8b" of type "text/plain" (99920 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ