Results for igt@gem_persistent_relocs@forked-interruptible-faulting-reloc-thrashing

Result: dmesg-warn

git-log-oneline igt_runner34 run34 boot34 dmesg34 runtimes34

DetailValue
Duration 24.01 seconds
Hostname
shard-iclb3
Igt-Version
IGT-Version: 1.24-g99f04b14e (x86_64) (Linux: 5.4.0-rc6-CI-CI_DRM_7279+ x86_64)
Out
IGT-Version: 1.24-g99f04b14e (x86_64) (Linux: 5.4.0-rc6-CI-CI_DRM_7279+ x86_64)
Starting subtest: forked-interruptible-faulting-reloc-thrashing
Subtest forked-interruptible-faulting-reloc-thrashing: SUCCESS (24.012s)
Err
Starting subtest: forked-interruptible-faulting-reloc-thrashing
Subtest forked-interruptible-faulting-reloc-thrashing: SUCCESS (24.012s)
Dmesg-Warnings
<4> [222.130174]   intel_timeline_enter+0x64/0x150 [i915]
<4> [222.130268]   ____intel_wakeref_put_last+0x1c/0x70 [i915]
<4> [222.130314]   i915_sample+0x2e8/0x310 [i915]
<4> [222.130458]  #2: ffff88848696c0d8 (&(&timelines->lock)->rlock){-...}, at: intel_gt_retire_requests_timeout+0x180/0x540 [i915]
<4> [222.130591]                     intel_timeline_enter+0x64/0x150 [i915]
<4> [222.130676]                     ____intel_wakeref_put_last+0x1c/0x70 [i915]
<4> [222.130718]                     i915_sample+0x2e8/0x310 [i915]
<4> [222.130811]                    intel_timeline_enter+0x64/0x150 [i915]
<4> [222.130883]                    ____intel_wakeref_put_last+0x1c/0x70 [i915]
<4> [222.130920]                    intel_gt_resume+0x1fd/0x2c0 [i915]
<4> [222.130972]                    i915_gem_init+0x366/0x8d0 [i915]
<4> [222.131011]                    i915_driver_probe+0xb9d/0x15b0 [i915]
<4> [222.131059]                    i915_pci_probe+0x43/0x1b0 [i915]
<4> [222.131221]    intel_gt_retire_requests_timeout+0x1b9/0x540 [i915]
<4> [222.131266]    intel_gt_wait_for_idle+0x28/0x60 [i915]
<4> [222.131306]    i915_drop_caches_set+0x125/0x240 [i915]
<4> [222.131533]    intel_gt_retire_requests_timeout+0x1b9/0x540 [i915]
<4> [222.131576]    intel_gt_wait_for_idle+0x28/0x60 [i915]
<4> [222.131624]    i915_drop_caches_set+0x125/0x240 [i915]
<4> [222.131755]  intel_gt_retire_requests_timeout+0x1b9/0x540 [i915]
<4> [222.131791]  intel_gt_wait_for_idle+0x28/0x60 [i915]
<4> [222.131829]  i915_drop_caches_set+0x125/0x240 [i915]
Dmesg
<6> [222.027696] Console: switching to colour dummy device 80x25
<6> [222.027739] [IGT] gem_persistent_relocs: executing
<6> [222.090078] [IGT] gem_persistent_relocs: starting subtest forked-interruptible-faulting-reloc-thrashing
<5> [222.102661] Setting dangerous option prefault_disable - tainting kernel
<5> [222.107205] Setting dangerous option prefault_disable - tainting kernel
<5> [222.110301] Setting dangerous option prefault_disable - tainting kernel
<5> [222.116407] Setting dangerous option prefault_disable - tainting kernel
<5> [222.119776] Setting dangerous option prefault_disable - tainting kernel
<5> [222.126819] Setting dangerous option prefault_disable - tainting kernel
<5> [222.129956] Setting dangerous option prefault_disable - tainting kernel
<4> [222.129998] 
<4> [222.130003] =====================================================
<4> [222.130006] WARNING: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected
<4> [222.130010] 5.4.0-rc6-CI-CI_DRM_7279+ #1 Tainted: G     U           
<4> [222.130013] -----------------------------------------------------
<4> [222.130017] gem_persistent_/1321 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
<4> [222.130020] ffff888490deca30 (&(&lock->wait_lock)->rlock){+.+.}, at: __mutex_unlock_slowpath+0x18e/0x2b0
<4> [222.130030] 
and this task is already holding:
<4> [222.130032] ffff88848696c0d8 (&(&timelines->lock)->rlock){-...}, at: intel_gt_retire_requests_timeout+0x180/0x540 [i915]
<4> [222.130094] which would create a new lock dependency:
<4> [222.130097]  (&(&timelines->lock)->rlock){-...} -> (&(&lock->wait_lock)->rlock){+.+.}
<4> [222.130103] 
but this new dependency connects a HARDIRQ-irq-safe lock:
<4> [222.130107]  (&(&timelines->lock)->rlock){-...}
<4> [222.130108] 
... which became HARDIRQ-irq-safe at:
<4> [222.130118]   lock_acquire+0xa7/0x1c0
<4> [222.130122]   _raw_spin_lock_irqsave+0x33/0x50
<4> [222.130174]   intel_timeline_enter+0x64/0x150 [i915]
<4> [222.130223]   __engine_park+0x1ef/0x420 [i915]
<4> [222.130268]   ____intel_wakeref_put_last+0x1c/0x70 [i915]
<4> [222.130314]   i915_sample+0x2e8/0x310 [i915]
<4> [222.130319]   __hrtimer_run_queues+0x121/0x4a0
<4> [222.130322]   hrtimer_interrupt+0xea/0x250
<4> [222.130326]   smp_apic_timer_interrupt+0x96/0x280
<4> [222.130330]   apic_timer_interrupt+0xf/0x20
<4> [222.130334]   cpuidle_enter_state+0xb2/0x450
<4> [222.130338]   cpuidle_enter+0x24/0x40
<4> [222.130341]   do_idle+0x1e7/0x250
<4> [222.130345]   cpu_startup_entry+0x14/0x20
<4> [222.130349]   start_kernel+0x4d2/0x4f4
<4> [222.130353]   secondary_startup_64+0xa4/0xb0
<4> [222.130356] 
to a HARDIRQ-irq-unsafe lock:
<4> [222.130359]  (&(&lock->wait_lock)->rlock){+.+.}
<4> [222.130360] 
... which became HARDIRQ-irq-unsafe at:
<4> [222.130365] ...
<4> [222.130367]   lock_acquire+0xa7/0x1c0
<4> [222.130373]   _raw_spin_lock+0x2a/0x40
<4> [222.130376]   __mutex_lock+0x198/0x9d0
<4> [222.130380]   pipe_wait+0x8f/0xc0
<4> [222.130383]   pipe_read+0x235/0x310
<4> [222.130387]   new_sync_read+0x10f/0x1a0
<4> [222.130391]   vfs_read+0x96/0x160
<4> [222.130393]   ksys_read+0x9f/0xe0
<4> [222.130397]   do_syscall_64+0x4f/0x210
<4> [222.130400]   entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.130403] 
other info that might help us debug this:

<4> [222.130407]  Possible interrupt unsafe locking scenario:

<4> [222.130411]        CPU0                    CPU1
<4> [222.130414]        ----                    ----
<4> [222.130417]   lock(&(&lock->wait_lock)->rlock);
<4> [222.130420]                                local_irq_disable();
<4> [222.130424]                                lock(&(&timelines->lock)->rlock);
<4> [222.130428]                                lock(&(&lock->wait_lock)->rlock);
<4> [222.130432]   <Interrupt>
<4> [222.130434]     lock(&(&timelines->lock)->rlock);
<4> [222.130437] 
 *** DEADLOCK ***

<4> [222.130441] 3 locks held by gem_persistent_/1321:
<4> [222.130444]  #0: ffff88849d789408 (sb_writers#14){.+.+}, at: vfs_write+0x1a4/0x1d0
<4> [222.130451]  #1: ffff88848ce069b0 (&attr->mutex){+.+.}, at: simple_attr_write+0x36/0xd0
<4> [222.130458]  #2: ffff88848696c0d8 (&(&timelines->lock)->rlock){-...}, at: intel_gt_retire_requests_timeout+0x180/0x540 [i915]
<4> [222.130509] 
the dependencies between HARDIRQ-irq-safe lock and the holding lock:
<4> [222.130519] -> (&(&timelines->lock)->rlock){-...} ops: 1734 {
<4> [222.130525]    IN-HARDIRQ-W at:
<4> [222.130529]                     lock_acquire+0xa7/0x1c0
<4> [222.130533]                     _raw_spin_lock_irqsave+0x33/0x50
<4> [222.130591]                     intel_timeline_enter+0x64/0x150 [i915]
<4> [222.130634]                     __engine_park+0x1ef/0x420 [i915]
<4> [222.130676]                     ____intel_wakeref_put_last+0x1c/0x70 [i915]
<4> [222.130718]                     i915_sample+0x2e8/0x310 [i915]
<4> [222.130722]                     __hrtimer_run_queues+0x121/0x4a0
<4> [222.130725]                     hrtimer_interrupt+0xea/0x250
<4> [222.130729]                     smp_apic_timer_interrupt+0x96/0x280
<4> [222.130732]                     apic_timer_interrupt+0xf/0x20
<4> [222.130736]                     cpuidle_enter_state+0xb2/0x450
<4> [222.130740]                     cpuidle_enter+0x24/0x40
<4> [222.130743]                     do_idle+0x1e7/0x250
<4> [222.130747]                     cpu_startup_entry+0x14/0x20
<4> [222.130750]                     start_kernel+0x4d2/0x4f4
<4> [222.130753]                     secondary_startup_64+0xa4/0xb0
<4> [222.130756]    INITIAL USE at:
<4> [222.130759]                    lock_acquire+0xa7/0x1c0
<4> [222.130763]                    _raw_spin_lock_irqsave+0x33/0x50
<4> [222.130811]                    intel_timeline_enter+0x64/0x150 [i915]
<4> [222.130847]                    __engine_park+0x1ef/0x420 [i915]
<4> [222.130883]                    ____intel_wakeref_put_last+0x1c/0x70 [i915]
<4> [222.130920]                    intel_gt_resume+0x1fd/0x2c0 [i915]
<4> [222.130972]                    i915_gem_init+0x366/0x8d0 [i915]
<4> [222.131011]                    i915_driver_probe+0xb9d/0x15b0 [i915]
<4> [222.131059]                    i915_pci_probe+0x43/0x1b0 [i915]
<4> [222.131066]                    pci_device_probe+0x9e/0x120
<4> [222.131071]                    really_probe+0xea/0x420
<4> [222.131075]                    driver_probe_device+0x10b/0x120
<4> [222.131078]                    device_driver_attach+0x4a/0x50
<4> [222.131083]                    __driver_attach+0x97/0x130
<4> [222.131086]                    bus_for_each_dev+0x74/0xc0
<4> [222.131090]                    bus_add_driver+0x142/0x220
<4> [222.131094]                    driver_register+0x56/0xf0
<4> [222.131098]                    do_one_initcall+0x58/0x2ff
<4> [222.131103]                    do_init_module+0x56/0x1f8
<4> [222.131107]                    load_module+0x243e/0x29f0
<4> [222.131111]                    __do_sys_finit_module+0xe9/0x110
<4> [222.131115]                    do_syscall_64+0x4f/0x210
<4> [222.131119]                    entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131123]  }
<4> [222.131160]  ... key      at: [<ffffffffa04df990>] __key.70125+0x0/0xffffffffffeec670 [i915]
<4> [222.131166]  ... acquired at:
<4> [222.131171]    lock_acquire+0xa7/0x1c0
<4> [222.131176]    _raw_spin_lock+0x2a/0x40
<4> [222.131179]    __mutex_unlock_slowpath+0x18e/0x2b0
<4> [222.131221]    intel_gt_retire_requests_timeout+0x1b9/0x540 [i915]
<4> [222.131266]    intel_gt_wait_for_idle+0x28/0x60 [i915]
<4> [222.131306]    i915_drop_caches_set+0x125/0x240 [i915]
<4> [222.131310]    simple_attr_write+0xb0/0xd0
<4> [222.131315]    full_proxy_write+0x51/0x80
<4> [222.131318]    vfs_write+0xb9/0x1d0
<4> [222.131321]    ksys_write+0x9f/0xe0
<4> [222.131324]    do_syscall_64+0x4f/0x210
<4> [222.131328]    entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131331] 
<4> [222.131333] 
the dependencies between the lock to be acquired
<4> [222.131333]  and HARDIRQ-irq-unsafe lock:
<4> [222.131344] -> (&(&lock->wait_lock)->rlock){+.+.} ops: 866 {
<4> [222.131349]    HARDIRQ-ON-W at:
<4> [222.131353]                     lock_acquire+0xa7/0x1c0
<4> [222.131357]                     _raw_spin_lock+0x2a/0x40
<4> [222.131361]                     __mutex_lock+0x198/0x9d0
<4> [222.131365]                     pipe_wait+0x8f/0xc0
<4> [222.131368]                     pipe_read+0x235/0x310
<4> [222.131372]                     new_sync_read+0x10f/0x1a0
<4> [222.131376]                     vfs_read+0x96/0x160
<4> [222.131380]                     ksys_read+0x9f/0xe0
<4> [222.131383]                     do_syscall_64+0x4f/0x210
<4> [222.131387]                     entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131391]    SOFTIRQ-ON-W at:
<4> [222.131394]                     lock_acquire+0xa7/0x1c0
<4> [222.131399]                     _raw_spin_lock+0x2a/0x40
<4> [222.131403]                     __mutex_lock+0x198/0x9d0
<4> [222.131406]                     pipe_wait+0x8f/0xc0
<4> [222.131410]                     pipe_read+0x235/0x310
<4> [222.131414]                     new_sync_read+0x10f/0x1a0
<4> [222.131418]                     vfs_read+0x96/0x160
<4> [222.131421]                     ksys_read+0x9f/0xe0
<4> [222.131424]                     do_syscall_64+0x4f/0x210
<4> [222.131428]                     entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131432]    INITIAL USE at:
<4> [222.131435]                    lock_acquire+0xa7/0x1c0
<4> [222.131439]                    _raw_spin_lock+0x2a/0x40
<4> [222.131443]                    __mutex_lock+0x198/0x9d0
<4> [222.131447]                    pipe_wait+0x8f/0xc0
<4> [222.131450]                    pipe_read+0x235/0x310
<4> [222.131454]                    new_sync_read+0x10f/0x1a0
<4> [222.131458]                    vfs_read+0x96/0x160
<4> [222.131461]                    ksys_read+0x9f/0xe0
<4> [222.131465]                    do_syscall_64+0x4f/0x210
<4> [222.131469]                    entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131472]  }
<4> [222.131477]  ... key      at: [<ffffffff828389f0>] __key.18650+0x0/0x10
<4> [222.131480]  ... acquired at:
<4> [222.131484]    lock_acquire+0xa7/0x1c0
<4> [222.131487]    _raw_spin_lock+0x2a/0x40
<4> [222.131491]    __mutex_unlock_slowpath+0x18e/0x2b0
<4> [222.131533]    intel_gt_retire_requests_timeout+0x1b9/0x540 [i915]
<4> [222.131576]    intel_gt_wait_for_idle+0x28/0x60 [i915]
<4> [222.131624]    i915_drop_caches_set+0x125/0x240 [i915]
<4> [222.131628]    simple_attr_write+0xb0/0xd0
<4> [222.131632]    full_proxy_write+0x51/0x80
<4> [222.131635]    vfs_write+0xb9/0x1d0
<4> [222.131638]    ksys_write+0x9f/0xe0
<4> [222.131641]    do_syscall_64+0x4f/0x210
<4> [222.131645]    entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131648] 
<4> [222.131650] 
stack backtrace:
<4> [222.131654] CPU: 1 PID: 1321 Comm: gem_persistent_ Tainted: G     U            5.4.0-rc6-CI-CI_DRM_7279+ #1
<4> [222.131660] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP, BIOS ICLSFWR1.R00.3234.A01.1906141750 06/14/2019
<4> [222.131667] Call Trace:
<4> [222.131671]  dump_stack+0x67/0x9b
<4> [222.131676]  check_irq_usage+0x686/0x6a0
<4> [222.131681]  ? check_path+0x22/0x40
<4> [222.131684]  ? check_noncircular+0xec/0x1c0
<4> [222.131689]  ? __lock_acquire+0x133e/0x15d0
<4> [222.131693]  __lock_acquire+0x133e/0x15d0
<4> [222.131697]  lock_acquire+0xa7/0x1c0
<4> [222.131701]  ? __mutex_unlock_slowpath+0x18e/0x2b0
<4> [222.131706]  _raw_spin_lock+0x2a/0x40
<4> [222.131710]  ? __mutex_unlock_slowpath+0x18e/0x2b0
<4> [222.131714]  __mutex_unlock_slowpath+0x18e/0x2b0
<4> [222.131755]  intel_gt_retire_requests_timeout+0x1b9/0x540 [i915]
<4> [222.131791]  intel_gt_wait_for_idle+0x28/0x60 [i915]
<4> [222.131829]  i915_drop_caches_set+0x125/0x240 [i915]
<4> [222.131834]  simple_attr_write+0xb0/0xd0
<4> [222.131838]  full_proxy_write+0x51/0x80
<4> [222.131842]  vfs_write+0xb9/0x1d0
<4> [222.131846]  ksys_write+0x9f/0xe0
<4> [222.131849]  do_syscall_64+0x4f/0x210
<4> [222.131852]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [222.131856] RIP: 0033:0x7f2f525e6281
<4> [222.131861] Code: c3 0f 1f 84 00 00 00 00 00 48 8b 05 59 8d 20 00 c3 0f 1f 84 00 00 00 00 00 8b 05 8a d1 20 00 85 c0 75 16 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 41 54 55 49 89 d4 53
<4> [222.131869] RSP: 002b:00007ffd3b7699f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4> [222.131874] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f2f525e6281
<4> [222.131877] RDX: 0000000000000004 RSI: 00007ffd3b769a50 RDI: 0000000000000008
<4> [222.131880] RBP: 0000000000000004 R08: 0000000000000000 R09: 0000000000000000
<4> [222.131884] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffd3b769a50
<4> [222.131886] R13: 0000000000000008 R14: 00007ffd3b769a50 R15: 0000000000000000
<5> [222.133895] Setting dangerous option prefault_disable - tainting kernel
<7> [224.268072] [drm:edp_panel_vdd_off_sync [i915]] Turning [ENCODER:214:DDI A] VDD off
<7> [224.268324] [drm:edp_panel_vdd_off_sync [i915]] PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [224.268422] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [224.268519] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [224.268607] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<5> [242.776288] Setting dangerous option prefault_disable - tainting kernel
<5> [242.780887] Setting dangerous option prefault_disable - tainting kernel
<5> [242.865370] Setting dangerous option prefault_disable - tainting kernel
<5> [242.869697] Setting dangerous option prefault_disable - tainting kernel
<5> [243.298497] Setting dangerous option prefault_disable - tainting kernel
<5> [243.302774] Setting dangerous option prefault_disable - tainting kernel
<5> [245.786121] Setting dangerous option prefault_disable - tainting kernel
<5> [245.790132] Setting dangerous option prefault_disable - tainting kernel
<5> [245.870919] Setting dangerous option prefault_disable - tainting kernel
<5> [245.874914] Setting dangerous option prefault_disable - tainting kernel
<5> [246.021579] Setting dangerous option prefault_disable - tainting kernel
<5> [246.026351] Setting dangerous option prefault_disable - tainting kernel
<5> [246.029094] Setting dangerous option prefault_disable - tainting kernel
<5> [246.033468] Setting dangerous option prefault_disable - tainting kernel
<5> [246.086949] Setting dangerous option prefault_disable - tainting kernel
<5> [246.091900] Setting dangerous option prefault_disable - tainting kernel
<6> [246.102991] [IGT] gem_persistent_relocs: exiting, ret=0
<5> [246.103262] Setting dangerous option reset - tainting kernel
<6> [246.154125] Console: switching to colour frame buffer device 320x90
Created at 2019-11-08 12:05:35