From patchwork Thu Feb 18 14:00:37 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Jiri Slaby X-Patchwork-Id: 584707 X-Patchwork-Delegate: davem@davemloft.net Return-Path: X-Original-To: patchwork-incoming@ozlabs.org Delivered-To: patchwork-incoming@ozlabs.org Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by ozlabs.org (Postfix) with ESMTP id E6371140213 for ; Fri, 19 Feb 2016 01:01:00 +1100 (AEDT) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1425769AbcBROAo (ORCPT ); Thu, 18 Feb 2016 09:00:44 -0500 Received: from mail-wm0-f46.google.com ([74.125.82.46]:37183 "EHLO mail-wm0-f46.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1425388AbcBROAl (ORCPT ); Thu, 18 Feb 2016 09:00:41 -0500 Received: by mail-wm0-f46.google.com with SMTP id g62so26838057wme.0; Thu, 18 Feb 2016 06:00:40 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:subject:to:references:cc:from:message-id:date :user-agent:mime-version:in-reply-to:content-type; bh=xD9Vpl9JzIg/7G+pe4H+3zul4XD++nr5nYjjGQG1724=; b=IFrT0sjXYO3MWCkJx8aYqFTI1c/rP9sRo1m6XmH9bnXJ4DpxaAfAkgnmr30YQuYEna sqcpZdr5jl9J00/oDqPoMxGZmRPXl5O7kBOVb3HwoME3pESzwkGZZcevhg6i36t8+OXV jyFmpwPr3JeNia41IhgocjYH7Mb7Ln+XRCYQqCgB6q1wFlA9BySFcTCgKdWMYkZL06au Kjh+EVxyy1djCZz7nW8H3XpxqiphCV1gPZnDwkWQEHkldL58jJKSVF1q0wbQruM7mWAt l5cqxWbrpv27UesVRmjGl0/sF4+pqYuWlIDWdTnYUX3YcQCwFfJ8o2chrdb2bk5zlCvC b4Lw== X-Gm-Message-State: AG10YOSOqGF4oDwSuigxox+3wRya+S9S1DNEwcaNauLbomNkDhnM7gf9m25hleByEz0fww== X-Received: by 10.194.58.12 with SMTP id m12mr8742545wjq.22.1455804039436; Thu, 18 Feb 2016 06:00:39 -0800 (PST) Received: from ?IPv6:2a01:4240:2e27:ad85::19f? (f.9.1.0.0.0.0.0.0.0.0.0.0.0.0.0.5.8.d.a.7.2.e.2.0.4.2.4.1.0.a.2.v6.cust.nbox.cz. [2a01:4240:2e27:ad85::19f]) by smtp.gmail.com with ESMTPSA id u132sm2048235wmd.1.2016.02.18.06.00.37 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Thu, 18 Feb 2016 06:00:38 -0800 (PST) Subject: Re: net/bluetooth: workqueue destruction WARNING in hci_unregister_dev To: Dmitry Vyukov , Marcel Holtmann , Gustavo Padovan , Johan Hedberg , "David S. Miller" , linux-bluetooth@vger.kernel.org, netdev , LKML References: Cc: syzkaller , Kostya Serebryany , Alexander Potapenko , Sasha Levin , Eric Dumazet , Tejun Heo , Takashi Iwai From: Jiri Slaby X-Enigmail-Draft-Status: N1110 Message-ID: <56C5CE85.6090808@suse.cz> Date: Thu, 18 Feb 2016 15:00:37 +0100 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Thunderbird/38.5.1 MIME-Version: 1.0 In-Reply-To: Sender: netdev-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: netdev@vger.kernel.org Cc Tejun (workqueues), Takashi (debug patch) On 01/26/2016, 12:53 PM, Dmitry Vyukov wrote: > Hello, > > I've hit the following warning while running syzkaller fuzzer: Hi, I am hitting it over and over again using syzkaller. > WARNING: CPU: 2 PID: 17409 at kernel/workqueue.c:3968 > destroy_workqueue+0x172/0x550() Which of the warnings is it in your case? I hit "(pwq != wq->dfl_pwq) && (pwq->refcnt > 1)". So I have this in the code: if (WARN_ON((pwq != wq->dfl_pwq) && (pwq->refcnt > 1))) { pr_info("%s: pwq=%p wq->dfl_pwq=%p pwq->refcnt=%d\n", __func__, pwq, wq->dfl_pwq, pwq->refcnt); mutex_unlock(&wq->mutex); return; } if (WARN_ON(pwq->nr_active)) { ... And the values are: pwq=ffff88006e271500 wq->dfl_pwq=ffff88006e272400 pwq->refcnt=2 pwq=ffff88002ec48300 wq->dfl_pwq=ffff88002ec4bc00 pwq->refcnt=2 pwq=ffff880020f76400 wq->dfl_pwq=ffff880020f75500 pwq->refcnt=2 pwq=ffff88002a908f00 wq->dfl_pwq=ffff88002a90bc00 pwq->refcnt=1 pwq=ffff8800348e0300 wq->dfl_pwq=ffff8800348e0000 pwq->refcnt=2 pwq=ffff88006e276400 wq->dfl_pwq=ffff88006e275800 pwq->refcnt=2 Note the single "pwq->refcnt=1" in there. So this is perhaps a race? Takashi also provided me with a debug patch included in the attached patch. It did not trigger though. > CPU: 2 PID: 17409 Comm: syz-executor Not tainted 4.5.0-rc1+ #283 > Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011 > 00000000ffffffff ffff88003665f8a0 ffffffff8299a06d 0000000000000000 > ffff88003599c740 ffffffff8643f0c0 ffff88003665f8e0 ffffffff8134fcf9 > ffffffff8139d4c2 ffffffff8643f0c0 0000000000000f80 ffff8800630c5ae8 > Call Trace: > [< inline >] __dump_stack lib/dump_stack.c:15 > [] dump_stack+0x6f/0xa2 lib/dump_stack.c:50 > [] warn_slowpath_common+0xd9/0x140 kernel/panic.c:482 > [] warn_slowpath_null+0x29/0x30 kernel/panic.c:515 > [] destroy_workqueue+0x172/0x550 kernel/workqueue.c:3968 > [] hci_unregister_dev+0x264/0x700 > net/bluetooth/hci_core.c:3162 > [] vhci_release+0x76/0xe0 drivers/bluetooth/hci_vhci.c:341 > [] __fput+0x236/0x780 fs/file_table.c:208 > [] ____fput+0x15/0x20 fs/file_table.c:244 > [] task_work_run+0x170/0x210 kernel/task_work.c:115 > [< inline >] exit_task_work include/linux/task_work.h:21 > [] do_exit+0x8b5/0x2c60 kernel/exit.c:748 > [] do_group_exit+0x108/0x330 kernel/exit.c:878 > [] get_signal+0x5e4/0x14f0 kernel/signal.c:2307 > [] do_signal+0x83/0x1c90 arch/x86/kernel/signal.c:712 > [] exit_to_usermode_loop+0x1a5/0x210 > arch/x86/entry/common.c:247 > [< inline >] prepare_exit_to_usermode arch/x86/entry/common.c:282 > [] syscall_return_slowpath+0x2ba/0x340 > arch/x86/entry/common.c:344 > [] int_ret_from_sys_call+0x25/0x9f > arch/x86/entry/entry_64.S:281 > ---[ end trace f627386faee7426f ]--- > > Unfortunately I cannot reproduce it in a controlled environment, but > I've hit it twice in different VMs. So maybe if you see something > obvious there. Is it possible that something is submitted into the > workqueue between it is drained and destroyed in hci_unregister_dev? > > On commit 92e963f50fc74041b5e9e744c330dca48e04f08d (Jan 24). > thanks, --- include/linux/workqueue.h | 1 + kernel/workqueue.c | 23 ++++++++++++++++++++--- net/bluetooth/hci_core.c | 19 +++++++++++++++++++ 3 files changed, 40 insertions(+), 3 deletions(-) --- a/include/linux/workqueue.h +++ b/include/linux/workqueue.h @@ -312,6 +312,7 @@ enum { __WQ_DRAINING = 1 << 16, /* internal: workqueue is draining */ __WQ_ORDERED = 1 << 17, /* internal: workqueue is ordered */ __WQ_LEGACY = 1 << 18, /* internal: create*_workqueue() */ + __WQ_DESTROYING = 1 << 19, WQ_MAX_ACTIVE = 512, /* I like 512, better ideas? */ WQ_MAX_UNBOUND_PER_CPU = 4, /* 4 * #cpus for unbound wq */ --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -1366,6 +1366,9 @@ static void __queue_work(int cpu, struct unsigned int work_flags; unsigned int req_cpu = cpu; + if (WARN_ON(wq->flags & __WQ_DESTROYING)) + return; + /* * While a work item is PENDING && off queue, a task trying to * steal the PENDING will busy-loop waiting for it to either get @@ -4010,6 +4013,7 @@ void destroy_workqueue(struct workqueue_ int node; /* drain it before proceeding with destruction */ + wq->flags |= __WQ_DESTROYING; drain_workqueue(wq); /* sanity checks */ @@ -4024,9 +4028,22 @@ void destroy_workqueue(struct workqueue_ } } - if (WARN_ON((pwq != wq->dfl_pwq) && (pwq->refcnt > 1)) || - WARN_ON(pwq->nr_active) || - WARN_ON(!list_empty(&pwq->delayed_works))) { + if (WARN_ON((pwq != wq->dfl_pwq) && (pwq->refcnt > 1))) { + pr_info("%s: pwq=%p wq->dfl_pwq=%p pwq->refcnt=%d\n", + __func__, pwq, wq->dfl_pwq, + pwq->refcnt); + mutex_unlock(&wq->mutex); + return; + } + + if (WARN_ON(pwq->nr_active)) { + pr_info("%s: %ps\n", __func__, wq); + mutex_unlock(&wq->mutex); + return; + } + + if (WARN_ON(!list_empty(&pwq->delayed_works))) { + pr_info("%s: %ps\n", __func__, wq); mutex_unlock(&wq->mutex); return; } --- a/net/bluetooth/hci_core.c +++ b/net/bluetooth/hci_core.c @@ -2467,6 +2467,8 @@ static void hci_cmd_timeout(struct work_ struct hci_dev *hdev = container_of(work, struct hci_dev, cmd_timer.work); + if (WARN_ON(hci_dev_test_flag(hdev, HCI_UNREGISTER))) + return; if (hdev->sent_cmd) { struct hci_command_hdr *sent = (void *) hdev->sent_cmd->data; u16 opcode = __le16_to_cpu(sent->opcode); @@ -3225,6 +3227,11 @@ int hci_recv_frame(struct hci_dev *hdev, return -ENXIO; } + if (WARN_ON(hci_dev_test_flag(hdev, HCI_UNREGISTER))) { + kfree_skb(skb); + return -ENXIO; + } + if (hci_skb_pkt_type(skb) != HCI_EVENT_PKT && hci_skb_pkt_type(skb) != HCI_ACLDATA_PKT && hci_skb_pkt_type(skb) != HCI_SCODATA_PKT) { @@ -3248,6 +3255,9 @@ EXPORT_SYMBOL(hci_recv_frame); /* Receive diagnostic message from HCI drivers */ int hci_recv_diag(struct hci_dev *hdev, struct sk_buff *skb) { + if (WARN_ON(hci_dev_test_flag(hdev, HCI_UNREGISTER))) + return -ENXIO; + /* Mark as diagnostic packet */ hci_skb_pkt_type(skb) = HCI_DIAG_PKT; @@ -3326,6 +3336,9 @@ int hci_send_cmd(struct hci_dev *hdev, _ { struct sk_buff *skb; + if (WARN_ON(hci_dev_test_flag(hdev, HCI_UNREGISTER))) + return -ENXIO; + BT_DBG("%s opcode 0x%4.4x plen %d", hdev->name, opcode, plen); skb = hci_prepare_cmd(hdev, opcode, plen, param); @@ -3461,6 +3474,9 @@ void hci_send_acl(struct hci_chan *chan, { struct hci_dev *hdev = chan->conn->hdev; + if (WARN_ON(hci_dev_test_flag(hdev, HCI_UNREGISTER))) + return; + BT_DBG("%s chan %p flags 0x%4.4x", hdev->name, chan, flags); hci_queue_acl(chan, &chan->data_q, skb, flags); @@ -3474,6 +3490,9 @@ void hci_send_sco(struct hci_conn *conn, struct hci_dev *hdev = conn->hdev; struct hci_sco_hdr hdr; + if (WARN_ON(hci_dev_test_flag(hdev, HCI_UNREGISTER))) + return; + BT_DBG("%s len %d", hdev->name, skb->len); hdr.handle = cpu_to_le16(conn->handle);