Bug 103730 - [CI] igt@drv_selftest@live_context - dmesg-warn - WARNING: possible circular locking dependency detected
Summary: [CI] igt@drv_selftest@live_context - dmesg-warn - WARNING: possible circular ...
Status: CLOSED DUPLICATE of bug 103830
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: medium normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
Depends on:
Blocks:
 
Reported: 2017-11-14 07:29 UTC by Marta Löfstedt
Modified: 2017-11-23 06:52 UTC (History)
1 user (show)

See Also:
i915 platform: HSW, SNB
i915 features:

Attachments

Description Marta Löfstedt 2017-11-14 07:29:32 UTC 
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3342/shard-snb5/igt@drv_selftest@live_contexts.html

[ 1366.741276] ======================================================
[ 1366.741277] WARNING: possible circular locking dependency detected
[ 1366.741278] 4.14.0-rc8-CI-CI_DRM_3342+ #1 Tainted: G     U         
[ 1366.741279] ------------------------------------------------------
[ 1366.741280] drv_selftest/18398 is trying to acquire lock:
[ 1366.741280]  (&dev->object_name_lock){+.+.}, at: [<ffffffff815f26a9>] drm_gem_handle_create+0x29/0x40
[ 1366.741285] 
               but task is already holding lock:
[ 1366.741286]  (&dev->struct_mutex){+.+.}, at: [<ffffffffa0347259>] igt_ctx_exec+0x69/0xd50 [i915]
[ 1366.741331] 
               which lock already depends on the new lock.

[ 1366.741332] 
               the existing dependency chain (in reverse order) is:
[ 1366.741333] 
               -> #2 (&dev->struct_mutex){+.+.}:
[ 1366.741337]        lock_acquire+0xb0/0x200
[ 1366.741341]        __mutex_lock+0x86/0x9b0
[ 1366.741343]        mutex_lock_interruptible_nested+0x1b/0x20
[ 1366.741344]        0xffffffffa0182131
[ 1366.741345]        0xffffffffa0187d2b
[ 1366.741348]        __do_fault+0x1e/0x80
[ 1366.741350]        __handle_mm_fault+0xa08/0xed0
[ 1366.741352]        handle_mm_fault+0x156/0x300
[ 1366.741354]        __do_page_fault+0x2d2/0x560
[ 1366.741355]        do_page_fault+0x28/0x250
[ 1366.741357]        page_fault+0x22/0x30
[ 1366.741358] 
               -> #1 (&mm->mmap_sem){++++}:
[ 1366.741362]        lock_acquire+0xb0/0x200
[ 1366.741364]        down_write+0x3b/0x70
[ 1366.741364]        0xffffffffa019a1ea
[ 1366.741365]        0xffffffffa019a3bd
[ 1366.741366]        0xffffffffa016bd3e
[ 1366.741368]        drm_gem_prime_handle_to_fd+0x18e/0x1c0
[ 1366.741370]        drm_prime_handle_to_fd_ioctl+0x44/0x60
[ 1366.741371]        drm_ioctl_kernel+0x69/0xb0
[ 1366.741372]        drm_ioctl+0x2f9/0x3d0
[ 1366.741375]        do_vfs_ioctl+0x94/0x670
[ 1366.741376]        SyS_ioctl+0x41/0x70
[ 1366.741379]        entry_SYSCALL_64_fastpath+0x1c/0xb1
[ 1366.741379] 
               -> #0 (&dev->object_name_lock){+.+.}:
[ 1366.741383]        __lock_acquire+0x1962/0x1b00
[ 1366.741384]        lock_acquire+0xb0/0x200
[ 1366.741386]        __mutex_lock+0x86/0x9b0
[ 1366.741388]        mutex_lock_nested+0x1b/0x20
[ 1366.741389]        drm_gem_handle_create+0x29/0x40
[ 1366.741431]        igt_ctx_exec+0x540/0xd50 [i915]
[ 1366.741480]        __i915_subtests+0x40/0xd0 [i915]
[ 1366.741523]        i915_gem_context_live_selftests+0x48/0x140 [i915]
[ 1366.741571]        __run_selftests+0x121/0x1c0 [i915]
[ 1366.741617]        i915_live_selftests+0x35/0x60 [i915]
[ 1366.741657]        i915_pci_probe+0x4a/0x90 [i915]
[ 1366.741661]        pci_device_probe+0xa8/0x130
[ 1366.741664]        driver_probe_device+0x29c/0x450
[ 1366.741666]        __driver_attach+0xe3/0xf0
[ 1366.741668]        bus_for_each_dev+0x62/0xa0
[ 1366.741669]        driver_attach+0x1e/0x20
[ 1366.741671]        bus_add_driver+0x173/0x270
[ 1366.741673]        driver_register+0x60/0xe0
[ 1366.741674]        __pci_register_driver+0x6b/0x70
[ 1366.741714]        i915_init+0x6f/0x78 [i915]
[ 1366.741720]        do_one_initcall+0x43/0x170
[ 1366.741723]        do_init_module+0x5f/0x206
[ 1366.741734]        load_module+0x2581/0x2dd0
[ 1366.741736]        SyS_finit_module+0xc1/0x100
[ 1366.741738]        entry_SYSCALL_64_fastpath+0x1c/0xb1
[ 1366.741740] 
               other info that might help us debug this:

[ 1366.741741] Chain exists of:
                 &dev->object_name_lock --> &mm->mmap_sem --> &dev->struct_mutex

[ 1366.741749]  Possible unsafe locking scenario:

[ 1366.741750]        CPU0                    CPU1
[ 1366.741753]        ----                    ----
[ 1366.741754]   lock(&dev->struct_mutex);
[ 1366.741760]                                lock(&mm->mmap_sem);
[ 1366.741764]                                lock(&dev->struct_mutex);
[ 1366.741768]   lock(&dev->object_name_lock);
[ 1366.741772] 
                *** DEADLOCK ***

[ 1366.741773] 3 locks held by drv_selftest/18398:
[ 1366.741774]  #0:  (&dev->mutex){....}, at: [<ffffffff81622adf>] __driver_attach+0x5f/0xf0
[ 1366.741783]  #1:  (&dev->mutex){....}, at: [<ffffffff81622aed>] __driver_attach+0x6d/0xf0
[ 1366.741791]  #2:  (&dev->struct_mutex){+.+.}, at: [<ffffffffa0347259>] igt_ctx_exec+0x69/0xd50 [i915]
[ 1366.741836] 
               stack backtrace:
[ 1366.741838] CPU: 5 PID: 18398 Comm: drv_selftest Tainted: G     U          4.14.0-rc8-CI-CI_DRM_3342+ #1
[ 1366.741840] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
[ 1366.741841] Call Trace:
[ 1366.741845]  dump_stack+0x68/0x9f
[ 1366.741849]  print_circular_bug.isra.18+0x1f6/0x2e0
[ 1366.741851]  __lock_acquire+0x1962/0x1b00
[ 1366.741855]  lock_acquire+0xb0/0x200
[ 1366.741858]  ? lock_acquire+0xb0/0x200
[ 1366.741860]  ? drm_gem_handle_create+0x29/0x40
[ 1366.741864]  __mutex_lock+0x86/0x9b0
[ 1366.741865]  ? drm_gem_handle_create+0x29/0x40
[ 1366.741867]  ? drm_gem_handle_create+0x29/0x40
[ 1366.741907]  ? i915_gem_object_init+0x185/0x190 [i915]
[ 1366.741912]  mutex_lock_nested+0x1b/0x20
[ 1366.741914]  ? mutex_lock_nested+0x1b/0x20
[ 1366.741917]  drm_gem_handle_create+0x29/0x40
[ 1366.741952]  igt_ctx_exec+0x540/0xd50 [i915]
[ 1366.741996]  __i915_subtests+0x40/0xd0 [i915]
[ 1366.742036]  i915_gem_context_live_selftests+0x48/0x140 [i915]
[ 1366.742079]  __run_selftests+0x121/0x1c0 [i915]
[ 1366.742118]  i915_live_selftests+0x35/0x60 [i915]
[ 1366.742154]  i915_pci_probe+0x4a/0x90 [i915]
[ 1366.742158]  pci_device_probe+0xa8/0x130
[ 1366.742161]  driver_probe_device+0x29c/0x450
[ 1366.742163]  __driver_attach+0xe3/0xf0
[ 1366.742166]  ? driver_probe_device+0x450/0x450
[ 1366.742168]  bus_for_each_dev+0x62/0xa0
[ 1366.742172]  driver_attach+0x1e/0x20
[ 1366.742175]  bus_add_driver+0x173/0x270
[ 1366.742178]  driver_register+0x60/0xe0
[ 1366.742180]  __pci_register_driver+0x6b/0x70
[ 1366.742217]  i915_init+0x6f/0x78 [i915]
[ 1366.742221]  ? 0xffffffffa04d7000
[ 1366.742223]  do_one_initcall+0x43/0x170
[ 1366.742227]  ? rcu_read_lock_sched_held+0x7a/0x90
[ 1366.742230]  ? kmem_cache_alloc_trace+0x270/0x2d0
[ 1366.742232]  do_init_module+0x5f/0x206
[ 1366.742235]  load_module+0x2581/0x2dd0
[ 1366.742237]  ? show_coresize+0x30/0x30
[ 1366.742240]  ? kernel_read+0x31/0x50
[ 1366.742244]  SyS_finit_module+0xc1/0x100
[ 1366.742246]  ? SyS_finit_module+0xc1/0x100
[ 1366.742249]  entry_SYSCALL_64_fastpath+0x1c/0xb1
[ 1366.742251] RIP: 0033:0x7f84dec3f9f9
[ 1366.742253] RSP: 002b:00007fff83c29e28 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[ 1366.742257] RAX: ffffffffffffffda RBX: ffffffff81492083 RCX: 00007f84dec3f9f9
[ 1366.742259] RDX: 0000000000000000 RSI: 000055c7c16ca030 RDI: 0000000000000006
[ 1366.742260] RBP: ffffc900005d7f88 R08: 0000000000000000 R09: 0000000000000000
[ 1366.742262] R10: 0000000000000006 R11: 0000000000000246 R12: 0000000000000000
[ 1366.742264] R13: 000055c7c16cefe0 R14: 0000000000000000 R15: 000055c7c16c6990
[ 1366.742267]  ? __this_cpu_preempt_check+0x13/0x20
[ 1367.828840] to colour frame buffer device 128x48
[ 1368.115825] i915: probe of 0000:00:02.0 failed with error -25
[ 1368.285804] to colour frame buffer device 128x48
Comment 1 Chris Wilson 2017-11-14 11:07:20 UTC 
What is this trace

               -> #1 (&mm->mmap_sem){++++}:
[ 1366.741362]        lock_acquire+0xb0/0x200
[ 1366.741364]        down_write+0x3b/0x70
[ 1366.741364]        0xffffffffa019a1ea
[ 1366.741365]        0xffffffffa019a3bd
[ 1366.741366]        0xffffffffa016bd3e
[ 1366.741368]        drm_gem_prime_handle_to_fd+0x18e/0x1c0
[ 1366.741370]        drm_prime_handle_to_fd_ioctl+0x44/0x60
[ 1366.741371]        drm_ioctl_kernel+0x69/0xb0
[ 1366.741372]        drm_ioctl+0x2f9/0x3d0
[ 1366.741375]        do_vfs_ioctl+0x94/0x670
[ 1366.741376]        SyS_ioctl+0x41/0x70
[ 1366.741379]        entry_SYSCALL_64_fastpath+0x1c/0xb1

? That makes no sense (we never need the write lock on mmap_sem inside handle_to_fd, afaik). I do believe lockdep has lost track its marbles, possibly due to a hash conflict due to the many module reloads.
Comment 2 Marta Löfstedt 2017-11-15 07:21:31 UTC 
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3347/shard-hsw5/igt@drv_selftest@live_contexts.html

<4>[ 1203.737243] ======================================================
<4>[ 1203.737244] WARNING: possible circular locking dependency detected
<4>[ 1203.737245] 4.14.0-CI-CI_DRM_3347+ #1 Tainted: G     U         
<4>[ 1203.737245] ------------------------------------------------------
<4>[ 1203.737246] drv_selftest/21936 is trying to acquire lock:
<4>[ 1203.737246]  (&dev->object_name_lock){+.+.}, at: [<ffffffff815f44b9>] drm_gem_handle_create+0x29/0x40
<4>[ 1203.737249] 
                  but task is already holding lock:
<4>[ 1203.737249]  (&dev->struct_mutex){+.+.}, at: [<ffffffffa0352276>] igt_ctx_exec+0x76/0xd20 [i915]
<4>[ 1203.737270] 
                  which lock already depends on the new lock.

<4>[ 1203.737271] 
                  the existing dependency chain (in reverse order) is:
<4>[ 1203.737271] 
                  -> #2 (&dev->struct_mutex){+.+.}:
<4>[ 1203.737273]        lock_acquire+0xb0/0x200
<4>[ 1203.737275]        __mutex_lock+0x86/0x9b0
<4>[ 1203.737275]        mutex_lock_interruptible_nested+0x1b/0x20
<4>[ 1203.737276]        0xffffffffa01be1b1
<4>[ 1203.737276]        0xffffffffa01c3e0b
<4>[ 1203.737278]        __do_fault+0x1e/0x80
<4>[ 1203.737279]        __handle_mm_fault+0x81f/0xed0
<4>[ 1203.737279]        handle_mm_fault+0x156/0x300
<4>[ 1203.737280]        __do_page_fault+0x2d2/0x560
<4>[ 1203.737281]        do_page_fault+0x28/0x250
<4>[ 1203.737282]        page_fault+0x22/0x30
<4>[ 1203.737282] 
                  -> #1 (&mm->mmap_sem){++++}:
<4>[ 1203.737284]        lock_acquire+0xb0/0x200
<4>[ 1203.737284]        down_write+0x3b/0x70
<4>[ 1203.737285]        0xffffffffa01bd31a
<4>[ 1203.737286]        0xffffffffa01bd4ed
<4>[ 1203.737286]        0xffffffffa018ed1e
<4>[ 1203.737287]        drm_gem_prime_handle_to_fd+0x18e/0x1c0
<4>[ 1203.737288]        drm_prime_handle_to_fd_ioctl+0x44/0x60
<4>[ 1203.737289]        drm_ioctl_kernel+0x69/0xb0
<4>[ 1203.737289]        drm_ioctl+0x2f9/0x3d0
<4>[ 1203.737291]        do_vfs_ioctl+0x94/0x670
<4>[ 1203.737293]        SyS_ioctl+0x41/0x70
<4>[ 1203.737294]        entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[ 1203.737294] 
                  -> #0 (&dev->object_name_lock){+.+.}:
<4>[ 1203.737295]        __lock_acquire+0x1962/0x1b00
<4>[ 1203.737296]        lock_acquire+0xb0/0x200
<4>[ 1203.737297]        __mutex_lock+0x86/0x9b0
<4>[ 1203.737297]        mutex_lock_nested+0x1b/0x20
<4>[ 1203.737298]        drm_gem_handle_create+0x29/0x40
<4>[ 1203.737316]        igt_ctx_exec+0x54e/0xd20 [i915]
<4>[ 1203.737339]        __i915_subtests+0x40/0xd0 [i915]
<4>[ 1203.737359]        i915_gem_context_live_selftests+0x48/0x140 [i915]
<4>[ 1203.737382]        __run_selftests+0x121/0x1c0 [i915]
<4>[ 1203.737408]        i915_live_selftests+0x35/0x60 [i915]
<4>[ 1203.737433]        i915_pci_probe+0x4a/0x90 [i915]
<4>[ 1203.737436]        pci_device_probe+0xa8/0x130
<4>[ 1203.737438]        driver_probe_device+0x29c/0x450
<4>[ 1203.737440]        __driver_attach+0xe3/0xf0
<4>[ 1203.737441]        bus_for_each_dev+0x62/0xa0
<4>[ 1203.737443]        driver_attach+0x1e/0x20
<4>[ 1203.737444]        bus_add_driver+0x173/0x270
<4>[ 1203.737446]        driver_register+0x60/0xe0
<4>[ 1203.737448]        __pci_register_driver+0x6b/0x70
<4>[ 1203.737474]        i915_init+0x6f/0x78 [i915]
<4>[ 1203.737475]        do_one_initcall+0x43/0x170
<4>[ 1203.737477]        do_init_module+0x5f/0x206
<4>[ 1203.737478]        load_module+0x2581/0x2dd0
<4>[ 1203.737480]        SyS_finit_module+0xc1/0x100
<4>[ 1203.737481]        entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[ 1203.737482] 
                  other info that might help us debug this:

<4>[ 1203.737482] Chain exists of:
                    &dev->object_name_lock --> &mm->mmap_sem --> &dev->struct_mutex

<4>[ 1203.737485]  Possible unsafe locking scenario:

<4>[ 1203.737485]        CPU0                    CPU1
<4>[ 1203.737485]        ----                    ----
<4>[ 1203.737486]   lock(&dev->struct_mutex);
<4>[ 1203.737487]                                lock(&mm->mmap_sem);
<4>[ 1203.737488]                                lock(&dev->struct_mutex);
<4>[ 1203.737488]   lock(&dev->object_name_lock);
<4>[ 1203.737489] 
                   *** DEADLOCK ***

<4>[ 1203.737490] 3 locks held by drv_selftest/21936:
<4>[ 1203.737490]  #0:  (&dev->mutex){....}, at: [<ffffffff816248ef>] __driver_attach+0x5f/0xf0
<4>[ 1203.737493]  #1:  (&dev->mutex){....}, at: [<ffffffff816248fd>] __driver_attach+0x6d/0xf0
<4>[ 1203.737496]  #2:  (&dev->struct_mutex){+.+.}, at: [<ffffffffa0352276>] igt_ctx_exec+0x76/0xd20 [i915]
<4>[ 1203.737524] 
                  stack backtrace:
<4>[ 1203.737525] CPU: 5 PID: 21936 Comm: drv_selftest Tainted: G     U          4.14.0-CI-CI_DRM_3347+ #1
<4>[ 1203.737526] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 1203.737527] Call Trace:
<4>[ 1203.737529]  dump_stack+0x68/0x9f
<4>[ 1203.737531]  print_circular_bug.isra.18+0x1f6/0x2e0
<4>[ 1203.737533]  __lock_acquire+0x1962/0x1b00
<4>[ 1203.737536]  lock_acquire+0xb0/0x200
<4>[ 1203.737537]  ? lock_acquire+0xb0/0x200
<4>[ 1203.737539]  ? drm_gem_handle_create+0x29/0x40
<4>[ 1203.737540]  __mutex_lock+0x86/0x9b0
<4>[ 1203.737541]  ? drm_gem_handle_create+0x29/0x40
<4>[ 1203.737543]  ? drm_gem_handle_create+0x29/0x40
<4>[ 1203.737570]  ? i915_gem_object_init+0x185/0x190 [i915]
<4>[ 1203.737572]  mutex_lock_nested+0x1b/0x20
<4>[ 1203.737573]  ? mutex_lock_nested+0x1b/0x20
<4>[ 1203.737574]  drm_gem_handle_create+0x29/0x40
<4>[ 1203.737599]  igt_ctx_exec+0x54e/0xd20 [i915]
<4>[ 1203.737630]  __i915_subtests+0x40/0xd0 [i915]
<4>[ 1203.737657]  i915_gem_context_live_selftests+0x48/0x140 [i915]
<4>[ 1203.737687]  __run_selftests+0x121/0x1c0 [i915]
<4>[ 1203.737713]  i915_live_selftests+0x35/0x60 [i915]
<4>[ 1203.737738]  i915_pci_probe+0x4a/0x90 [i915]
<4>[ 1203.737741]  pci_device_probe+0xa8/0x130
<4>[ 1203.737743]  driver_probe_device+0x29c/0x450
<4>[ 1203.737745]  __driver_attach+0xe3/0xf0
<4>[ 1203.737746]  ? driver_probe_device+0x450/0x450
<4>[ 1203.737747]  bus_for_each_dev+0x62/0xa0
<4>[ 1203.737749]  driver_attach+0x1e/0x20
<4>[ 1203.737750]  bus_add_driver+0x173/0x270
<4>[ 1203.737752]  driver_register+0x60/0xe0
<4>[ 1203.737754]  __pci_register_driver+0x6b/0x70
<4>[ 1203.737776]  i915_init+0x6f/0x78 [i915]
<4>[ 1203.737777]  ? 0xffffffffa04e2000
<4>[ 1203.737778]  do_one_initcall+0x43/0x170
<4>[ 1203.737779]  ? rcu_read_lock_sched_held+0x7a/0x90
<4>[ 1203.737780]  ? kmem_cache_alloc_trace+0x270/0x2d0
<4>[ 1203.737782]  do_init_module+0x5f/0x206
<4>[ 1203.737783]  load_module+0x2581/0x2dd0
<4>[ 1203.737784]  ? show_coresize+0x30/0x30
<4>[ 1203.737785]  ? kernel_read+0x31/0x50
<4>[ 1203.737787]  SyS_finit_module+0xc1/0x100
<4>[ 1203.737788]  ? SyS_finit_module+0xc1/0x100
<4>[ 1203.737790]  entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[ 1203.737791] RIP: 0033:0x7feea7eac9f9
<4>[ 1203.737792] RSP: 002b:00007fff7ae23f68 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
<4>[ 1203.737793] RAX: ffffffffffffffda RBX: ffffffff814920c3 RCX: 00007feea7eac9f9
<4>[ 1203.737794] RDX: 0000000000000000 RSI: 000055ed5808d750 RDI: 0000000000000006
<4>[ 1203.737795] RBP: ffffc90000637f88 R08: 0000000000000000 R09: 0000000000000000
<4>[ 1203.737795] R10: 0000000000000006 R11: 0000000000000246 R12: 0000000000000000
<4>[ 1203.737796] R13: 000055ed5808d7a0 R14: 0000000000000000 R15: 000055ed580849e0
<4>[ 1203.737798]  ? __this_cpu_preempt_check+0x13/0x20
Comment 3 Chris Wilson 2017-11-23 00:16:59 UTC 

*** This bug has been marked as a duplicate of bug 103830 ***

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.