Re: Lock inversion in ata_piix

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi

Am 03.02.21 um 13:22 schrieb Thomas Zimmermann:
Hi,

there's a possible lock inversion reported during boot-up. The rsp driver is ata_piix. The full error is below.

The fix [1] given in [2] solves the issue.

Tested-by: Thomas Zimmermann <tzimmermann@xxxxxxx>

[1] https://git.kernel.org/pub/scm/linux/kernel/git/pavel/linux-leds.git/commit/?id=9a5ad5c5b2d25508996f10ee6b428d5df91d9160 [2] https://lore.kernel.org/linux-ide/46bcf09c-c4ac-e96b-1813-1798d36cd93d@xxxxxxxxxx/T/#mbbccef9fd695a695eae14beda56b0bbb4e622c87


Best regards
Thomas


[   15.782834] ========================================================
[   15.789912] WARNING: possible irq lock inversion dependency detected
[   15.789915] 5.11.0-rc5-1-default+ #752 Tainted: G            E
[   15.789918] --------------------------------------------------------
[   15.789919] loadkeys/347 just changed the state of lock:
[   15.789922] ffff88810c289c18 (&host->lock){-...}-{2:2}, at: ata_bmdma_interrupt+0x22/0x2f0 [   15.789938] but this lock took another, HARDIRQ-READ-unsafe lock in the past:
[   15.789940]  (&trig->leddev_list_lock){.+.?}-{2:2}
[   15.834024]
[   15.834024]
[   15.834024] and interrupts could create inverse lock ordering between them.
[   15.834024]
[   15.834028]
[   15.834028] other info that might help us debug this:
[   15.834029]  Possible interrupt unsafe locking scenario:
[   15.834029]
[   15.834031]        CPU0                    CPU1
[   15.834032]        ----                    ----
[   15.834033]   lock(&trig->leddev_list_lock);
[   15.834037]                                local_irq_disable();
[   15.834038]                                lock(&host->lock);
[   15.834041] lock(&trig->leddev_list_lock);
[   15.834044]   <Interrupt>
[   15.834045]     lock(&host->lock);
[   15.834048]
[   15.834048]  *** DEADLOCK ***
[   15.834048]
[   15.834049] no locks held by loadkeys/347.
[   15.834051]
[   15.834051] the shortest dependencies between 2nd lock and 1st lock:
[   15.834064]  -> (&trig->leddev_list_lock){.+.?}-{2:2} {
[   15.834071]     HARDIRQ-ON-R at:
[   15.834074]                       __lock_acquire+0x2d7/0x930
[   15.834081]                       lock_acquire.part.0+0xf7/0x1e0
[   15.834085]                       _raw_read_lock+0x3d/0xa0
[   15.834090]                       led_trigger_event+0x25/0x80
[   15.834095]                       kbd_bh+0xd1/0x100
[   15.834100] tasklet_action_common.constprop.0+0x1b1/0x1d0
[   15.834105]                       __do_softirq+0x108/0x554
[   15.834109]                       run_ksoftirqd+0x3a/0x60
[   15.834112]                       smpboot_thread_fn+0x1b7/0x300
[   15.834115]                       kthread+0x1e4/0x210
[   15.834119]                       ret_from_fork+0x22/0x30
[   15.834124]     IN-SOFTIRQ-R at:
[   15.834126]                       __lock_acquire+0x2d7/0x930
[   15.834130]                       lock_acquire.part.0+0xf7/0x1e0
[   15.834133]                       _raw_read_lock+0x3d/0xa0
[   15.834137]                       led_trigger_event+0x25/0x80
[   15.834141]                       kbd_bh+0xd1/0x100
[   15.834144] tasklet_action_common.constprop.0+0x1b1/0x1d0
[   15.834148]                       __do_softirq+0x108/0x554
[   15.834151]                       run_ksoftirqd+0x3a/0x60
[   15.834154]                       smpboot_thread_fn+0x1b7/0x300
[   15.834157]                       kthread+0x1e4/0x210
[   15.834160]                       ret_from_fork+0x22/0x30
[   15.834164]     SOFTIRQ-ON-R at:
[   15.834166]                       __lock_acquire+0x2d7/0x930
[   15.834169]                       lock_acquire.part.0+0xf7/0x1e0
[   15.834173]                       _raw_read_lock+0x3d/0xa0
[   15.834177]                       led_trigger_event+0x25/0x80
[   15.834181]                       ledtrig_cpu+0xb1/0x110
[   15.834184]                       ledtrig_online_cpu+0xf/0x20
[   15.834188]                       cpuhp_invoke_callback+0xf9/0x5b0
[   15.834193]                       cpuhp_thread_fun+0x237/0x330
[   15.834197]                       smpboot_thread_fn+0x1b7/0x300
[   15.834200]                       kthread+0x1e4/0x210
[   15.834203]                       ret_from_fork+0x22/0x30
[   15.834207]     INITIAL USE at:
[   15.834209]                      __lock_acquire+0x2d7/0x930
[   15.834213]                      lock_acquire.part.0+0xf7/0x1e0
[   15.834216]                      _raw_write_lock_irqsave+0x4d/0x90
[   15.834221]                      led_trigger_set+0x224/0x470
[   15.834225] led_trigger_set_default.part.0+0xd1/0xf0
[   15.834229]                      led_classdev_register_ext+0x37a/0x440
[   15.834233]                      input_leds_connect+0x1e6/0x380
[   15.834236]                      input_attach_handler+0xb1/0xd0
[   15.834241]                      input_register_device.cold+0xd0/0x192
[   15.834245]                      atkbd_connect+0x3bb/0x460
[   15.834248]                      serio_driver_probe+0x56/0x70
[   15.834252]                      really_probe+0x185/0x6c0
[   15.834255]                      driver_probe_device+0x13f/0x1d0
[   15.834259]                      device_driver_attach+0x114/0x120
[   15.834262]                      __driver_attach+0xb0/0x1a0
[   15.834265]                      bus_for_each_dev+0xdd/0x120
[   15.834269]                      serio_handle_event+0x18f/0x3f0
[   15.834273]                      process_one_work+0x571/0xa40
[   15.834277]                      worker_thread+0x8b/0x620
[   15.834280]                      kthread+0x1e4/0x210
[   15.834283]                      ret_from_fork+0x22/0x30
[   15.834287]     INITIAL READ USE at:
[   15.834289]                           __lock_acquire+0x2d7/0x930
[   15.834292]                           lock_acquire.part.0+0xf7/0x1e0
[   15.834296]                           _raw_read_lock+0x3d/0xa0
[   15.834300]                           led_trigger_event+0x25/0x80
[   15.834304]                           kbd_bh+0xd1/0x100
[   15.834307] tasklet_action_common.constprop.0+0x1b1/0x1d0
[   15.834311]                           __do_softirq+0x108/0x554
[   15.834314]                           run_ksoftirqd+0x3a/0x60
[   15.834318]                           smpboot_thread_fn+0x1b7/0x300
[   15.834321]                           kthread+0x1e4/0x210
[   15.834323]                           ret_from_fork+0x22/0x30
[   15.834327]   }
[   15.834328]   ... key      at: [<ffffffff962167c0>] __key.0+0x0/0x40
[   15.834334]   ... acquired at:
[   15.834335]    __lock_acquire+0x54f/0x930
[   15.834339]    lock_acquire.part.0+0xf7/0x1e0
[   15.834342]    _raw_read_lock+0x3d/0xa0
[   15.834346]    led_trigger_blink_oneshot+0x34/0x90
[   15.834350]    ledtrig_disk_activity+0x67/0xc0
[   15.834354]    ata_qc_complete+0x3b/0x6d0
[   15.834357]    ata_sff_hsm_move+0x226/0x690
[   15.834361]    ata_sff_pio_task+0x265/0x290
[   15.834365]    process_one_work+0x571/0xa40
[   15.834368]    worker_thread+0x8b/0x620
[   15.834372]    kthread+0x1e4/0x210
[   15.834374]    ret_from_fork+0x22/0x30
[   15.834378]
[   15.834379] -> (&host->lock){-...}-{2:2} {
[   15.834385]    IN-HARDIRQ-W at:
[   15.834387]                     __lock_acquire+0x2d7/0x930
[   15.834391]                     lock_acquire.part.0+0xf7/0x1e0
[   15.834394]                     _raw_spin_lock_irqsave+0x4d/0x90
[   15.834398]                     ata_bmdma_interrupt+0x22/0x2f0
[   15.834402]                     __handle_irq_event_percpu+0x176/0x410
[   15.834406]                     handle_irq_event+0xb1/0x140
[   15.834409]                     handle_fasteoi_irq+0x100/0x390
[   15.834413]                     asm_call_irq_on_stack+0x12/0x20
[   15.834416]                     common_interrupt+0xee/0x190
[   15.834421]                     asm_common_interrupt+0x1e/0x40
[   15.834424]                     __orc_find+0x39/0xc0
[   15.834428]                     unwind_next_frame+0x107/0xa20
[   15.834431]                     arch_stack_walk+0x6c/0xb0
[   15.834435]                     stack_trace_save+0x81/0xa0
[   15.834439]                     kasan_save_stack+0x1b/0x40
[   15.834443]                     ____kasan_kmalloc.constprop.0+0x81/0xa0
[   15.834446]                     kmem_cache_alloc_trace+0x136/0x310
[   15.834451]                     vt_kdskbent+0x78/0x300
[   15.834455]                     vt_do_kdsk_ioctl+0xe5/0x1e0
[   15.834459]                     vt_k_ioctl+0x4dd/0x6f0
[   15.834462]                     vt_ioctl+0xc5/0x850
[   15.834465]                     tty_ioctl+0x472/0xab0
[   15.834471]                     __x64_sys_ioctl+0xb9/0xf0
[   15.834475]                     do_syscall_64+0x33/0x80
[   15.834478]                     entry_SYSCALL_64_after_hwframe+0x44/0xa9
[   15.834483]    INITIAL USE at:
[   15.834485]                    __lock_acquire+0x2d7/0x930
[   15.834489]                    lock_acquire.part.0+0xf7/0x1e0
[   15.834492]                    _raw_spin_lock_irqsave+0x4d/0x90
[   15.834496]                    ata_dev_init+0xb3/0x170
[   15.834500]                    ata_link_init+0xc7/0x140
[   15.834503]                    ata_port_alloc+0x2e7/0x300
[   15.834506]                    ata_host_alloc+0x136/0x180
[   15.834510]                    ata_host_alloc_pinfo+0x1e/0x190
[   15.834513]                    ata_pci_sff_prepare_host+0x3c/0xa0
[   15.834517]                    ata_pci_bmdma_prepare_host+0x10/0x30
[   15.834520]                    piix_init_one+0x47b/0x681 [ata_piix]
[   15.834532]                    local_pci_probe+0x74/0xc0
[   15.834535]                    pci_call_probe+0xb7/0x1d0
[   15.834538]                    pci_device_probe+0x102/0x140
[   15.834541]                    really_probe+0x185/0x6c0
[   15.834544]                    driver_probe_device+0x13f/0x1d0
[   15.834547]                    device_driver_attach+0x114/0x120
[   15.834550]                    __driver_attach+0xb0/0x1a0
[   15.834553]                    bus_for_each_dev+0xdd/0x120
[   15.834557]                    bus_add_driver+0x1fb/0x2e0
[   15.834560]                    driver_register+0x103/0x180
[   15.834563]                    piix_init+0x1f/0x1000 [ata_piix]
[   15.834572]                    do_one_initcall+0xbb/0x3a0
[   15.834576]                    do_init_module+0xfd/0x3c0
[   15.834580]                    load_module+0xbef/0xc70
[   15.834584]                    __do_sys_finit_module+0xff/0x180
[   15.834588]                    do_syscall_64+0x33/0x80
[   15.834591]                    entry_SYSCALL_64_after_hwframe+0x44/0xa9
[   15.834595]  }
[   15.834597]  ... key      at: [<ffffffff9620bec0>] __key.5+0x0/0x40
[   15.834601]  ... acquired at:
[   15.834603]    mark_lock_irq+0x151/0x360
[   15.834606]    mark_lock+0x309/0x4f0
[   15.834609]    mark_usage+0x185/0x1a0
[   15.834612]    __lock_acquire+0x2d7/0x930
[   15.834615]    lock_acquire.part.0+0xf7/0x1e0
[   15.834618]    _raw_spin_lock_irqsave+0x4d/0x90
[   15.834622]    ata_bmdma_interrupt+0x22/0x2f0
[   15.834626]    __handle_irq_event_percpu+0x176/0x410
[   15.834629]    handle_irq_event+0xb1/0x140
[   15.834632]    handle_fasteoi_irq+0x100/0x390
[   15.834635]    asm_call_irq_on_stack+0x12/0x20
[   15.834639]    common_interrupt+0xee/0x190
[   15.834642]    asm_common_interrupt+0x1e/0x40
[   15.834645]    __orc_find+0x39/0xc0
[   15.834648]    unwind_next_frame+0x107/0xa20
[   15.834651]    arch_stack_walk+0x6c/0xb0
[   15.834654]    stack_trace_save+0x81/0xa0
[   15.834657]    kasan_save_stack+0x1b/0x40
[   15.834660]    ____kasan_kmalloc.constprop.0+0x81/0xa0
[   15.834663]    kmem_cache_alloc_trace+0x136/0x310
[   15.834667]    vt_kdskbent+0x78/0x300
[   15.834670]    vt_do_kdsk_ioctl+0xe5/0x1e0
[   15.834674]    vt_k_ioctl+0x4dd/0x6f0
[   15.834677]    vt_ioctl+0xc5/0x850
[   15.834680]    tty_ioctl+0x472/0xab0
[   15.834684]    __x64_sys_ioctl+0xb9/0xf0
[   15.834687]    do_syscall_64+0x33/0x80
[   15.834690]    entry_SYSCALL_64_after_hwframe+0x44/0xa9
[   15.834695]
[   15.834695]
[   15.834695] stack backtrace:
[   15.834697] CPU: 1 PID: 347 Comm: loadkeys Tainted: G            E 5.11.0-rc5-1-default+ #752
[   15.834702] Hardware name: HP ProLiant DL120 G7, BIOS J01 04/21/2011
[   15.834705] Call Trace:
[   15.834707]  <IRQ>
[   15.834709]  dump_stack+0xae/0xe5
[   15.834715]  check_usage_forwards.cold+0x1f/0x4e
[   15.834722]  ? check_usage_backwards+0x2b0/0x2b0
[   15.834727]  ? stack_trace_save+0x81/0xa0
[   15.834731]  ? jhash.constprop.0+0x1e3/0x260
[   15.834737]  mark_lock_irq+0x151/0x360
[   15.834742]  mark_lock+0x309/0x4f0
[   15.834746]  mark_usage+0x185/0x1a0
[   15.834751]  __lock_acquire+0x2d7/0x930
[   15.834756]  ? check_prev_add+0x11e0/0x11e0
[   15.834760]  lock_acquire.part.0+0xf7/0x1e0
[   15.834764]  ? ata_bmdma_interrupt+0x22/0x2f0
[   15.834769]  ? rcu_read_unlock+0x40/0x40
[   15.834773]  ? lock_is_held_type+0xdc/0x110
[   15.834792]  ? rcu_read_lock_sched_held+0x3f/0x80
[   15.834797]  ? lock_acquire+0x74/0x190
[   15.834801]  ? ata_bmdma_interrupt+0x22/0x2f0
[   15.834806]  _raw_spin_lock_irqsave+0x4d/0x90
[   15.834811]  ? ata_bmdma_interrupt+0x22/0x2f0
[   15.834815]  ata_bmdma_interrupt+0x22/0x2f0
[   15.834819]  ? lock_is_held_type+0xdc/0x110
[   15.834824]  ? ata_bmdma_port_intr+0x180/0x180
[   15.834829]  __handle_irq_event_percpu+0x176/0x410
[   15.834834]  handle_irq_event+0xb1/0x140
[   15.834838]  ? handle_irq_event_percpu+0xd0/0xd0
[   15.834842]  ? handle_fasteoi_irq+0x4d/0x390
[   15.834847]  handle_fasteoi_irq+0x100/0x390
[   15.834853]  asm_call_irq_on_stack+0x12/0x20
[   15.834857]  </IRQ>
[   15.834858]  common_interrupt+0xee/0x190
[   15.834863]  asm_common_interrupt+0x1e/0x40
[   15.834867] RIP: 0010:__orc_find+0x39/0xc0
[   15.834871] Code: 6c 97 fc 41 54 55 53 48 83 ec 08 48 89 34 24 85 d2 74 7d 49 89 fc 4c 39 ef 0f 87 82 00 00 00 48 89 cb 48 89 fd 49 89 ff eb 0c <4d> 8d 7e 04 4c 89 f5 4d 39 fd 72 37 4c 89 e8 4c 29 f8 48 89 c1 48
[   15.834875] RSP: 0018:ffffc9000304f720 EFLAGS: 00000202
[   15.834879] RAX: ffffffff91494573 RBX: ffffffff9149457a RCX: dffffc0000000000 [   15.834882] RDX: 0000000000000007 RSI: ffffffff93e7301a RDI: ffffffff93b820dc [   15.834885] RBP: ffffffff93b820d8 R08: ffffffff910bbe28 R09: ffffffff93debf3b [   15.834888] R10: fffffbfff27bd7e7 R11: 0000000000000001 R12: ffffffff93b82090 [   15.834890] R13: ffffffff93b820dc R14: ffffffff93b820dc R15: ffffffff93b820dc
[   15.834894]  ? kasan_save_stack+0x1a/0x40
[   15.834898]  ? __orc_find+0x68/0xc0
[   15.834901]  ? kasan_save_stack+0x13/0x40
[   15.834908]  unwind_next_frame+0x107/0xa20
[   15.834912]  ? kasan_save_stack+0x1b/0x40
[   15.834915]  ? kasan_save_stack+0x1b/0x40
[   15.834919]  ? kasan_save_stack+0x1b/0x40
[   15.834922]  ? deref_stack_reg+0xb0/0xb0
[   15.834946]  ? __unwind_start.part.0+0x2c5/0x330
[   15.834949]  ? create_prof_cpu_mask+0x20/0x20
[   15.834954]  arch_stack_walk+0x6c/0xb0
[   15.834959]  ? kasan_save_stack+0x1b/0x40
[   15.834963]  stack_trace_save+0x81/0xa0
[   15.834967]  ? stack_trace_consume_entry+0x80/0x80
[   15.834971]  ? stack_trace_consume_entry+0x80/0x80
[   15.834975]  ? check_prev_add+0x11e0/0x11e0
[   15.834979]  kasan_save_stack+0x1b/0x40
[   15.834982]  ? kasan_save_stack+0x1b/0x40
[   15.834986]  ? __lock_acquire+0x572/0x930
[   15.834992]  ? lock_acquire.part.0+0xf7/0x1e0
[   15.834996]  ? sched_clock+0x5/0x10
[   15.835001]  ? sched_clock_cpu+0x18/0x110
[   15.835006]  ? __lock_release+0x12f/0x4f0
[   15.835011]  ? lock_downgrade+0xa0/0xa0
[   15.835014]  ? __lock_contended+0x490/0x490
[   15.835019]  ? cache_alloc_refill+0x2c8/0x310
[   15.835024]  ? do_raw_spin_unlock+0x86/0xf0
[   15.835029]  ? mark_held_locks+0x23/0x90
[   15.835033]  ? unpoison_range+0x3a/0x60
[   15.835037]  ____kasan_kmalloc.constprop.0+0x81/0xa0
[   15.835042]  kmem_cache_alloc_trace+0x136/0x310
[   15.835048]  vt_kdskbent+0x78/0x300
[   15.835053]  vt_do_kdsk_ioctl+0xe5/0x1e0
[   15.835058]  ? vt_do_kbkeycode_ioctl+0x230/0x230
[   15.835063]  ? check_prev_add+0x11e0/0x11e0
[   15.835067]  vt_k_ioctl+0x4dd/0x6f0
[   15.835071]  ? get_pid.part.0+0x50/0x50
[   15.835076]  ? apparmor_capable+0x9d/0x190
[   15.835081]  ? security_capable+0x4d/0x60
[   15.835086]  vt_ioctl+0xc5/0x850
[   15.835090]  ? complete_change_console+0x160/0x160
[   15.835096]  tty_ioctl+0x472/0xab0
[   15.835101]  ? tty_poll+0xd0/0xd0
[   15.835105]  ? lock_is_held_type+0xdc/0x110
[   15.835111]  ? do_vfs_ioctl+0x662/0x680
[   15.835115]  ? asm_sysvec_apic_timer_interrupt+0x12/0x20
[   15.835119]  ? ioctl_fiemap.isra.0+0x1a0/0x1a0
[   15.835123]  ? asm_sysvec_apic_timer_interrupt+0x12/0x20
[   15.835129]  __x64_sys_ioctl+0xb9/0xf0
[   15.835134]  do_syscall_64+0x33/0x80
[   15.835138]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[   15.835143] RIP: 0033:0x7f79989113cb
[   15.835146] Code: 89 d8 49 8d 3c 1c 48 f7 d8 49 39 c4 72 b5 e8 1c ff ff ff 85 c0 78 ba 4c 89 e0 5b 5d 41 5c c3 f3 0f 1e fa b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 75 ba 0c 00 f7 d8 64 89 01 48 [   15.835149] RSP: 002b:00007ffec2615b58 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 [   15.835153] RAX: ffffffffffffffda RBX: 000000000000004d RCX: 00007f79989113cb [   15.835156] RDX: 00007ffec2615bac RSI: 0000000000004b47 RDI: 0000000000000003 [   15.835158] RBP: 000000000000004d R08: 0000000000000000 R09: 0000558170402830 [   15.835161] R10: 00005581703dfc30 R11: 0000000000000246 R12: 0000000000000208 [   15.835163] R13: 0000000000000041 R14: 0000000000000041 R15: 00005581707dc2f0




--
Thomas Zimmermann
Graphics Driver Developer
SUSE Software Solutions Germany GmbH
Maxfeldstr. 5, 90409 Nürnberg, Germany
(HRB 36809, AG Nürnberg)
Geschäftsführer: Felix Imendörffer

Attachment: OpenPGP_signature
Description: OpenPGP digital signature


[Index of Archives]     [Linux Filesystems]     [Linux SCSI]     [Linux RAID]     [Git]     [Kernel Newbies]     [Linux Newbie]     [Security]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Samba]     [Device Mapper]

  Powered by Linux