lkml.org 
[lkml]   [2018]   [Apr]   [8]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    From
    Subject[PATCH AUTOSEL for 4.14 161/161] irqchip/gic-v3: Change pr_debug message to pr_devel
    Date
    From: Mark Salter <msalter@redhat.com>

    [ Upstream commit b6dd4d83dc2f78cebc9a7e6e7e4bc2be4d29b94d ]

    The pr_debug() in gic-v3 gic_send_sgi() can trigger a circular locking
    warning:

    GICv3: CPU10: ICC_SGI1R_EL1 5000400
    ======================================================
    WARNING: possible circular locking dependency detected
    4.15.0+ #1 Tainted: G W
    ------------------------------------------------------
    dynamic_debug01/1873 is trying to acquire lock:
    ((console_sem).lock){-...}, at: [<0000000099c891ec>] down_trylock+0x20/0x4c

    but task is already holding lock:
    (&rq->lock){-.-.}, at: [<00000000842e1587>] __task_rq_lock+0x54/0xdc

    which lock already depends on the new lock.

    the existing dependency chain (in reverse order) is:

    -> #2 (&rq->lock){-.-.}:
    __lock_acquire+0x3b4/0x6e0
    lock_acquire+0xf4/0x2a8
    _raw_spin_lock+0x4c/0x60
    task_fork_fair+0x3c/0x148
    sched_fork+0x10c/0x214
    copy_process.isra.32.part.33+0x4e8/0x14f0
    _do_fork+0xe8/0x78c
    kernel_thread+0x48/0x54
    rest_init+0x34/0x2a4
    start_kernel+0x45c/0x488

    -> #1 (&p->pi_lock){-.-.}:
    __lock_acquire+0x3b4/0x6e0
    lock_acquire+0xf4/0x2a8
    _raw_spin_lock_irqsave+0x58/0x70
    try_to_wake_up+0x48/0x600
    wake_up_process+0x28/0x34
    __up.isra.0+0x60/0x6c
    up+0x60/0x68
    __up_console_sem+0x4c/0x7c
    console_unlock+0x328/0x634
    vprintk_emit+0x25c/0x390
    dev_vprintk_emit+0xc4/0x1fc
    dev_printk_emit+0x88/0xa8
    __dev_printk+0x58/0x9c
    _dev_info+0x84/0xa8
    usb_new_device+0x100/0x474
    hub_port_connect+0x280/0x92c
    hub_event+0x740/0xa84
    process_one_work+0x240/0x70c
    worker_thread+0x60/0x400
    kthread+0x110/0x13c
    ret_from_fork+0x10/0x18

    -> #0 ((console_sem).lock){-...}:
    validate_chain.isra.34+0x6e4/0xa20
    __lock_acquire+0x3b4/0x6e0
    lock_acquire+0xf4/0x2a8
    _raw_spin_lock_irqsave+0x58/0x70
    down_trylock+0x20/0x4c
    __down_trylock_console_sem+0x3c/0x9c
    console_trylock+0x20/0xb0
    vprintk_emit+0x254/0x390
    vprintk_default+0x58/0x90
    vprintk_func+0xbc/0x164
    printk+0x80/0xa0
    __dynamic_pr_debug+0x84/0xac
    gic_raise_softirq+0x184/0x18c
    smp_cross_call+0xac/0x218
    smp_send_reschedule+0x3c/0x48
    resched_curr+0x60/0x9c
    check_preempt_curr+0x70/0xdc
    wake_up_new_task+0x310/0x470
    _do_fork+0x188/0x78c
    SyS_clone+0x44/0x50
    __sys_trace_return+0x0/0x4

    other info that might help us debug this:

    Chain exists of:
    (console_sem).lock --> &p->pi_lock --> &rq->lock

    Possible unsafe locking scenario:

    CPU0 CPU1
    ---- ----
    lock(&rq->lock);
    lock(&p->pi_lock);
    lock(&rq->lock);
    lock((console_sem).lock);

    *** DEADLOCK ***

    2 locks held by dynamic_debug01/1873:
    #0: (&p->pi_lock){-.-.}, at: [<000000001366df53>] wake_up_new_task+0x40/0x470
    #1: (&rq->lock){-.-.}, at: [<00000000842e1587>] __task_rq_lock+0x54/0xdc

    stack backtrace:
    CPU: 10 PID: 1873 Comm: dynamic_debug01 Tainted: G W 4.15.0+ #1
    Hardware name: GIGABYTE R120-T34-00/MT30-GS2-00, BIOS T48 10/02/2017
    Call trace:
    dump_backtrace+0x0/0x188
    show_stack+0x24/0x2c
    dump_stack+0xa4/0xe0
    print_circular_bug.isra.31+0x29c/0x2b8
    check_prev_add.constprop.39+0x6c8/0x6dc
    validate_chain.isra.34+0x6e4/0xa20
    __lock_acquire+0x3b4/0x6e0
    lock_acquire+0xf4/0x2a8
    _raw_spin_lock_irqsave+0x58/0x70
    down_trylock+0x20/0x4c
    __down_trylock_console_sem+0x3c/0x9c
    console_trylock+0x20/0xb0
    vprintk_emit+0x254/0x390
    vprintk_default+0x58/0x90
    vprintk_func+0xbc/0x164
    printk+0x80/0xa0
    __dynamic_pr_debug+0x84/0xac
    gic_raise_softirq+0x184/0x18c
    smp_cross_call+0xac/0x218
    smp_send_reschedule+0x3c/0x48
    resched_curr+0x60/0x9c
    check_preempt_curr+0x70/0xdc
    wake_up_new_task+0x310/0x470
    _do_fork+0x188/0x78c
    SyS_clone+0x44/0x50
    __sys_trace_return+0x0/0x4
    GICv3: CPU0: ICC_SGI1R_EL1 12000

    This could be fixed with printk_deferred() but that might lessen its
    usefulness for debugging. So change it to pr_devel to keep it out of
    production kernels. Developers working on gic-v3 can enable it as
    needed in their kernels.

    Signed-off-by: Mark Salter <msalter@redhat.com>
    Signed-off-by: Marc Zyngier <marc.zyngier@arm.com>
    Signed-off-by: Sasha Levin <alexander.levin@microsoft.com>
    ---
    drivers/irqchip/irq-gic-v3.c | 2 +-
    1 file changed, 1 insertion(+), 1 deletion(-)

    diff --git a/drivers/irqchip/irq-gic-v3.c b/drivers/irqchip/irq-gic-v3.c
    index ae9ff72e83ee..4d4d46dc1a6d 100644
    --- a/drivers/irqchip/irq-gic-v3.c
    +++ b/drivers/irqchip/irq-gic-v3.c
    @@ -645,7 +645,7 @@ static void gic_send_sgi(u64 cluster_id, u16 tlist, unsigned int irq)
    MPIDR_TO_SGI_AFFINITY(cluster_id, 1) |
    tlist << ICC_SGI1R_TARGET_LIST_SHIFT);

    - pr_debug("CPU%d: ICC_SGI1R_EL1 %llx\n", smp_processor_id(), val);
    + pr_devel("CPU%d: ICC_SGI1R_EL1 %llx\n", smp_processor_id(), val);
    gic_write_sgi1r(val);
    }

    --
    2.15.1
    \
     
     \ /
      Last update: 2018-04-09 04:50    [W:4.368 / U:0.172 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site