2020-11-13 07:24:14

by syzbot

[permalink] [raw]
Subject: general protection fault in tomoyo_socket_sendmsg_permission

Hello,

syzbot found the following issue on:

HEAD commit: 9dbc1c03 Merge tag 'xfs-5.10-fixes-3' of git://git.kernel...
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=10453034500000
kernel config: https://syzkaller.appspot.com/x/.config?x=1735b7978b1c3721
dashboard link: https://syzkaller.appspot.com/bug?extid=95ce4b142579611ef0a9
compiler: gcc (GCC) 10.1.0-syz 20200507
userspace arch: i386

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

general protection fault, probably for non-canonical address 0xdffffc0000000003: 0000 [#1] PREEMPT SMP KASAN
KASAN: null-ptr-deref in range [0x0000000000000018-0x000000000000001f]
CPU: 0 PID: 23364 Comm: vhci_tx Not tainted 5.10.0-rc2-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:tomoyo_socket_sendmsg_permission+0x80/0x340 security/tomoyo/network.c:762
Code: c7 40 0c f3 f3 f3 f3 65 48 8b 04 25 28 00 00 00 48 89 84 24 a0 00 00 00 31 c0 e8 0b 70 f1 fd 48 8d 7d 18 48 89 f8 48 c1 e8 03 <42> 80 3c 20 00 0f 85 7d 02 00 00 48 b8 00 00 00 00 00 fc ff df 4c
RSP: 0018:ffffc90016f77ad0 EFLAGS: 00010206
RAX: 0000000000000003 RBX: 1ffff92002deef5b RCX: ffffffff83b3789e
RDX: ffff8880186c8000 RSI: ffffffff837e9945 RDI: 0000000000000018
RBP: 0000000000000000 R08: 0000000000000030 R09: ffffc90016f77d97
R10: 0000000000000000 R11: 0000000000000000 R12: dffffc0000000000
R13: ffffc90016f77ce8 R14: ffffc90016f77ce8 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000562623b70868 CR3: 000000002af19000 CR4: 00000000001526f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
security_socket_sendmsg+0x50/0xb0 security/security.c:2140
sock_sendmsg+0x3f/0x120 net/socket.c:668
vhci_send_cmd_submit+0x897/0xf90 drivers/usb/usbip/vhci_tx.c:139
vhci_tx_loop+0xfc/0x370 drivers/usb/usbip/vhci_tx.c:241
kthread+0x3af/0x4a0 kernel/kthread.c:292
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:296
Modules linked in:
---[ end trace 535369ec3e6ef304 ]---
RIP: 0010:tomoyo_socket_sendmsg_permission+0x80/0x340 security/tomoyo/network.c:762
Code: c7 40 0c f3 f3 f3 f3 65 48 8b 04 25 28 00 00 00 48 89 84 24 a0 00 00 00 31 c0 e8 0b 70 f1 fd 48 8d 7d 18 48 89 f8 48 c1 e8 03 <42> 80 3c 20 00 0f 85 7d 02 00 00 48 b8 00 00 00 00 00 fc ff df 4c
RSP: 0018:ffffc90016f77ad0 EFLAGS: 00010206
RAX: 0000000000000003 RBX: 1ffff92002deef5b RCX: ffffffff83b3789e
RDX: ffff8880186c8000 RSI: ffffffff837e9945 RDI: 0000000000000018
RBP: 0000000000000000 R08: 0000000000000030 R09: ffffc90016f77d97
R10: 0000000000000000 R11: 0000000000000000 R12: dffffc0000000000
R13: ffffc90016f77ce8 R14: ffffc90016f77ce8 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f0c3a930740 CR3: 000000002af19000 CR4: 00000000001526f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at [email protected].

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.


2020-11-13 17:17:44

by Shuah Khan

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 11/13/20 5:00 AM, Hillf Danton wrote:
> Thu, 12 Nov 2020 23:21:26 -0800
>> syzbot found the following issue on:
>>
>> HEAD commit: 9dbc1c03 Merge tag 'xfs-5.10-fixes-3' of git://git.kernel...
>> git tree: upstream
>> console output: https://syzkaller.appspot.com/x/log.txt?x=10453034500000
>> kernel config: https://syzkaller.appspot.com/x/.config?x=1735b7978b1c3721
>> dashboard link: https://syzkaller.appspot.com/bug?extid=95ce4b142579611ef0a9
>> compiler: gcc (GCC) 10.1.0-syz 20200507
>> userspace arch: i386
>>
>> Unfortunately, I don't have any reproducer for this issue yet.
>>

I would like to see the reproducer for this. I just can't reproduce
this problem.

>
> Fix 96c2737716d5 ("usbip: move usbip kernel code out of staging")
> by closing the race between readers and writer of ud->tcp_socket on
> sock shutdown. To do that, add waitqueue for usbip device and make
> writer wait for all readers to go home before releasing the socket.
>
>
> --- a/drivers/usb/usbip/usbip_common.h
> +++ b/drivers/usb/usbip/usbip_common.h
> @@ -277,6 +277,9 @@ struct usbip_device {
> void (*reset)(struct usbip_device *);
> void (*unusable)(struct usbip_device *);
> } eh_ops;
> +
> + atomic_t sk_shutdown_count;
> + wait_queue_head_t sk_shutdown_waitq;
> };
>
> #define kthread_get_run(threadfn, data, namefmt, ...) \
> --- a/drivers/usb/usbip/vhci_hcd.c
> +++ b/drivers/usb/usbip/vhci_hcd.c
> @@ -1008,15 +1008,20 @@ static void vhci_shutdown_connection(str
>
> /* kill threads related to this sdev */
> if (vdev->ud.tcp_rx) {
> + atomic_inc(&ud->sk_shutdown_count);
> kthread_stop_put(vdev->ud.tcp_rx);
> vdev->ud.tcp_rx = NULL;
> }
> if (vdev->ud.tcp_tx) {
> + atomic_inc(&ud->sk_shutdown_count);
> kthread_stop_put(vdev->ud.tcp_tx);
> vdev->ud.tcp_tx = NULL;
> }
> pr_info("stop threads\n");
>
> + wait_event(ud->sk_shutdown_waitq,
> + !atomic_read(&ud->sk_shutdown_count));
> +
> /* active connection is closed */
> if (vdev->ud.tcp_socket) {
> sockfd_put(vdev->ud.tcp_socket);
> @@ -1104,6 +1109,8 @@ static void vhci_device_init(struct vhci
> vdev->ud.eh_ops.reset = vhci_device_reset;
> vdev->ud.eh_ops.unusable = vhci_device_unusable;
>
> + init_waitqueue_head(&vdev->ud.sk_shutdown_waitq);
> +
> usbip_start_eh(&vdev->ud);
> }
>
> --- a/drivers/usb/usbip/vhci_rx.c
> +++ b/drivers/usb/usbip/vhci_rx.c
> @@ -264,5 +264,8 @@ int vhci_rx_loop(void *data)
> vhci_rx_pdu(ud);
> }
>
> + if (atomic_dec_and_test(&ud->sk_shutdown_count))
> + wake_up(&ud->sk_shutdown_waitq);
> +
> return 0;
> }
> --- a/drivers/usb/usbip/vhci_tx.c
> +++ b/drivers/usb/usbip/vhci_tx.c
> @@ -252,5 +252,8 @@ int vhci_tx_loop(void *data)
> usbip_dbg_vhci_tx("pending urbs ?, now wake up\n");
> }
>
> + if (atomic_dec_and_test(&ud->sk_shutdown_count))
> + wake_up(&ud->sk_shutdown_waitq);
> +
> return 0;
> }
>


Without a reproducer, it is hard to verify the fix.

thanks,
-- Shuah

2021-01-28 06:12:27

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2020/11/14 2:14, Shuah Khan wrote:
> On 11/13/20 5:00 AM, Hillf Danton wrote:
>> Thu, 12 Nov 2020 23:21:26 -0800
>>> syzbot found the following issue on:
>>>
>>> HEAD commit:    9dbc1c03 Merge tag 'xfs-5.10-fixes-3' of git://git.kernel...
>>> git tree:       upstream
>>> console output: https://syzkaller.appspot.com/x/log.txt?x=10453034500000
>>> kernel config:  https://syzkaller.appspot.com/x/.config?x=1735b7978b1c3721
>>> dashboard link: https://syzkaller.appspot.com/bug?extid=95ce4b142579611ef0a9
>>> compiler:       gcc (GCC) 10.1.0-syz 20200507
>>> userspace arch: i386
>>>
>>> Unfortunately, I don't have any reproducer for this issue yet.
>>>
>
> I would like to see the reproducer for this. I just can't reproduce
> this problem.
>
>>
>> Fix 96c2737716d5 ("usbip: move usbip kernel code out of staging")
>> by closing the race between readers and writer of ud->tcp_socket on
>> sock shutdown. To do that, add waitqueue for usbip device and make
>> writer wait for all readers to go home before releasing the socket.

Worrysome part for me is vhci_device_reset() which resets ud->tcp_socket to NULL
without waiting for tx thread to terminate, though I don't know if
vhci_device_reset() can be called while tx thread is running.

I'd like to try below debug printk() patch on linx-next tree, for this bug is
reported on linux.git and linux-next.git trees. Which git tree can be used for
sending this to-be-removed patch to linux-next.git ? I wish there is a kernel
config for fuzzers in linux.git so that every git tree can carry debug printk()
patch for syzbot's reports...

Subject: [PATCH] usb: usbip: vhci_hcd: add printk() for debug

This is linux-next only patch for examining a bug reported at
https://syzkaller.appspot.com/bug?id=3e1d941a31361efc4ced2ba8b4af2044d4e43c59 .

Signed-off-by: Tetsuo Handa <[email protected]>
---
drivers/usb/usbip/stub_dev.c | 6 ++++++
drivers/usb/usbip/vhci_hcd.c | 11 +++++++++++
drivers/usb/usbip/vhci_sysfs.c | 4 ++++
drivers/usb/usbip/vhci_tx.c | 12 ++++++++++++
drivers/usb/usbip/vudc_dev.c | 6 ++++++
5 files changed, 39 insertions(+)

diff --git a/drivers/usb/usbip/stub_dev.c b/drivers/usb/usbip/stub_dev.c
index 2305d425e6c9..627f83c0ebc8 100644
--- a/drivers/usb/usbip/stub_dev.c
+++ b/drivers/usb/usbip/stub_dev.c
@@ -131,10 +131,14 @@ static void stub_shutdown_connection(struct usbip_device *ud)

/* 1. stop threads */
if (ud->tcp_rx) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: stop rx %p\n", __func__, ud->tcp_rx);
kthread_stop_put(ud->tcp_rx);
ud->tcp_rx = NULL;
}
if (ud->tcp_tx) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: stop tx %p\n", __func__, ud->tcp_tx);
kthread_stop_put(ud->tcp_tx);
ud->tcp_tx = NULL;
}
@@ -146,6 +150,8 @@ static void stub_shutdown_connection(struct usbip_device *ud)
* not touch NULL socket.
*/
if (ud->tcp_socket) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: close sock %p\n", __func__, ud->tcp_socket);
sockfd_put(ud->tcp_socket);
ud->tcp_socket = NULL;
ud->sockfd = -1;
diff --git a/drivers/usb/usbip/vhci_hcd.c b/drivers/usb/usbip/vhci_hcd.c
index 3209b5ddd30c..9e95bf9330f5 100644
--- a/drivers/usb/usbip/vhci_hcd.c
+++ b/drivers/usb/usbip/vhci_hcd.c
@@ -1016,10 +1016,14 @@ static void vhci_shutdown_connection(struct usbip_device *ud)

/* kill threads related to this sdev */
if (vdev->ud.tcp_rx) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: stop rx %p\n", __func__, vdev->ud.tcp_rx);
kthread_stop_put(vdev->ud.tcp_rx);
vdev->ud.tcp_rx = NULL;
}
if (vdev->ud.tcp_tx) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: stop tx %p\n", __func__, vdev->ud.tcp_tx);
kthread_stop_put(vdev->ud.tcp_tx);
vdev->ud.tcp_tx = NULL;
}
@@ -1027,6 +1031,8 @@ static void vhci_shutdown_connection(struct usbip_device *ud)

/* active connection is closed */
if (vdev->ud.tcp_socket) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: close sock %p\n", __func__, ud->tcp_socket);
sockfd_put(vdev->ud.tcp_socket);
vdev->ud.tcp_socket = NULL;
vdev->ud.sockfd = -1;
@@ -1074,6 +1080,11 @@ static void vhci_device_reset(struct usbip_device *ud)
vdev->udev = NULL;

if (ud->tcp_socket) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT)) {
+ pr_info("%s: close sock %p\n", __func__, ud->tcp_socket);
+ BUG_ON(vdev->ud.tcp_tx);
+ BUG_ON(vdev->ud.tcp_rx);
+ }
sockfd_put(ud->tcp_socket);
ud->tcp_socket = NULL;
ud->sockfd = -1;
diff --git a/drivers/usb/usbip/vhci_sysfs.c b/drivers/usb/usbip/vhci_sysfs.c
index be37aec250c2..b37e7770aa35 100644
--- a/drivers/usb/usbip/vhci_sysfs.c
+++ b/drivers/usb/usbip/vhci_sysfs.c
@@ -390,6 +390,10 @@ static ssize_t attach_store(struct device *dev, struct device_attribute *attr,

vdev->ud.tcp_rx = kthread_get_run(vhci_rx_loop, &vdev->ud, "vhci_rx");
vdev->ud.tcp_tx = kthread_get_run(vhci_tx_loop, &vdev->ud, "vhci_tx");
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT)) {
+ BUG_ON(IS_ERR(vdev->ud.tcp_rx));
+ BUG_ON(IS_ERR(vdev->ud.tcp_tx));
+ }

rh_port_connect(vdev, speed);

diff --git a/drivers/usb/usbip/vhci_tx.c b/drivers/usb/usbip/vhci_tx.c
index 0ae40a13a9fe..05da652e7bbe 100644
--- a/drivers/usb/usbip/vhci_tx.c
+++ b/drivers/usb/usbip/vhci_tx.c
@@ -63,6 +63,9 @@ static int vhci_send_cmd_submit(struct vhci_device *vdev)
int iovnum;
int err = -ENOMEM;
int i;
+#ifdef CONFIG_DEBUG_AID_FOR_SYZBOT
+ struct socket *socket = vdev->ud.tcp_socket;
+#endif

while ((priv = dequeue_from_priv_tx(vdev)) != NULL) {
int ret;
@@ -135,6 +138,11 @@ static int vhci_send_cmd_submit(struct vhci_device *vdev)
iovnum++;
txsize += len;
}
+#ifdef CONFIG_DEBUG_AID_FOR_SYZBOT
+ if (!socket || socket != vdev->ud.tcp_socket)
+ pr_err("%s: sock changed from %p to %p\n",
+ __func__, socket, vdev->ud.tcp_socket);
+#endif

ret = kernel_sendmsg(vdev->ud.tcp_socket, &msg, iov, iovnum,
txsize);
@@ -237,6 +245,8 @@ int vhci_tx_loop(void *data)
struct usbip_device *ud = data;
struct vhci_device *vdev = container_of(ud, struct vhci_device, ud);

+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: thread starting %p\n", __func__, vdev->ud.tcp_tx);
while (!kthread_should_stop()) {
if (vhci_send_cmd_submit(vdev) < 0)
break;
@@ -251,6 +261,8 @@ int vhci_tx_loop(void *data)

usbip_dbg_vhci_tx("pending urbs ?, now wake up\n");
}
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: thread exiting %p\n", __func__, vdev->ud.tcp_tx);

return 0;
}
diff --git a/drivers/usb/usbip/vudc_dev.c b/drivers/usb/usbip/vudc_dev.c
index c8eeabdd9b56..816cb4b5700b 100644
--- a/drivers/usb/usbip/vudc_dev.c
+++ b/drivers/usb/usbip/vudc_dev.c
@@ -437,15 +437,21 @@ static void vudc_shutdown(struct usbip_device *ud)
kernel_sock_shutdown(ud->tcp_socket, SHUT_RDWR);

if (ud->tcp_rx) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: stop rx %p\n", __func__, ud->tcp_rx);
kthread_stop_put(ud->tcp_rx);
ud->tcp_rx = NULL;
}
if (ud->tcp_tx) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: stop tx %p\n", __func__, ud->tcp_tx);
kthread_stop_put(ud->tcp_tx);
ud->tcp_tx = NULL;
}

if (ud->tcp_socket) {
+ if (IS_BUILTIN(CONFIG_DEBUG_AID_FOR_SYZBOT))
+ pr_info("%s: close sock %p\n", __func__, ud->tcp_socket);
sockfd_put(ud->tcp_socket);
ud->tcp_socket = NULL;
}
--
2.18.4

2021-01-29 05:55:05

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2021/01/29 4:05, Shuah Khan wrote:
> The reason I don't like adding printk's is this is a race condition
> and as a result time sensitive. Adding printks in the path will not
> help debug this issue. It will make it harder to reproduce the problem.

Not always. Adding printk() might make it easier to reproduce the problem.

>
> I am unable to reproduce the problem using the reproducer and running multiple instances of the reproducer.

Since syzkaller cannot find a reproducer for "general protection fault in
tomoyo_socket_sendmsg_permission", and you cannot reproduce other problem
using reproducer, trying to obtain some clue via printing messages by asking
syzkaller to try debug patch can be very helpful.

Since "general protection fault in tomoyo_socket_sendmsg_permission" is caused by
unexpectedly resetting ud->tcp_socket to NULL without waiting for tx thread to
terminate, tracing the ordering of events is worth knowing. Even adding
schedule_timeout_uninterruptible() to before kernel_sendmsg() might help.

2021-01-29 17:12:04

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2021/01/30 1:05, Shuah Khan wrote:
>> Since "general protection fault in tomoyo_socket_sendmsg_permission" is caused by
>> unexpectedly resetting ud->tcp_socket to NULL without waiting for tx thread to
>> terminate, tracing the ordering of events is worth knowing. Even adding
>> schedule_timeout_uninterruptible() to before kernel_sendmsg() might help.
>>
>
> What about the duplicate bug information that was in my email?
> Did you take a look at that?

I was not aware of the duplicate bugs. It is interesting that
"KASAN: null-ptr-deref Write in event_handler" says that vdev->ud.tcp_tx became NULL at

if (vdev->ud.tcp_tx) {

/* this location */

kthread_stop_put(vdev->ud.tcp_tx);
vdev->ud.tcp_tx = NULL;
}

which means that somebody else is unexpectedly resetting vdev->ud.tcp_tx to NULL.

If memset() from vhci_device_init() from vhci_start() were unexpectedly called,
all of tcp_socket, tcp_rx, tcp_tx etc. becomes NULL which can explain these bugs ?
I'm inclined to report not only tcp_socket but also other fields when kernel_sendmsg()
detected that tcp_socket is NULL...

2021-01-29 21:20:47

by Shuah Khan

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 1/29/21 10:08 AM, Tetsuo Handa wrote:
> On 2021/01/30 1:05, Shuah Khan wrote:
>>> Since "general protection fault in tomoyo_socket_sendmsg_permission" is caused by
>>> unexpectedly resetting ud->tcp_socket to NULL without waiting for tx thread to
>>> terminate, tracing the ordering of events is worth knowing. Even adding
>>> schedule_timeout_uninterruptible() to before kernel_sendmsg() might help.
>>>
>>
>> What about the duplicate bug information that was in my email?
>> Did you take a look at that?
>
> I was not aware of the duplicate bugs. It is interesting that
> "KASAN: null-ptr-deref Write in event_handler" says that vdev->ud.tcp_tx became NULL at
>
> if (vdev->ud.tcp_tx) {
>
> /* this location */
>
> kthread_stop_put(vdev->ud.tcp_tx);
> vdev->ud.tcp_tx = NULL;
> }
>
> which means that somebody else is unexpectedly resetting vdev->ud.tcp_tx to NULL.
>
> If memset() from vhci_device_init() from vhci_start() were unexpectedly called,
> all of tcp_socket, tcp_rx, tcp_tx etc. becomes NULL which can explain these bugs ?
> I'm inclined to report not only tcp_socket but also other fields when kernel_sendmsg()
> detected that tcp_socket is NULL...
>

In this console log:

06:57:50 executing program 1:
socketpair$tipc(0x1e, 0x2, 0x0, &(0x7f00000000c0)={<r0=>0xffffffffffffffff})
sendmsg$BATADV_CMD_GET_TRANSTABLE_LOCAL(r0,
&(0x7f00000002c0)={&(0x7f00000001c0), 0xc, &(0x7f0000000280)={0x0,
0xd001010000000000}}, 0x0)

[ 1151.090883][T23361] vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(4)
[ 1151.097445][T23361] vhci_hcd vhci_hcd.0: devid(0) speed(1)
speed_str(low-speed)
06:57:50 executing program 0:
r0 = syz_open_dev$binderN(&(0x7f0000000680)='/dev/binder#\x00', 0x0, 0x0)
ioctl$BINDER_WRITE_READ(r0, 0xc0306201, &(0x7f0000000cc0)={0x88, 0x0,
&(0x7f0000000b80)=[@transaction={0x40406300, {0x2, 0x0, 0x0, 0x0, 0x0,
0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}, @transaction={0x40406300, {0x0, 0x0,
0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}], 0x0, 0x0, 0x0})

[ 1151.164402][T23363] vhci_hcd: connection closed
[ 1151.167346][ T240] vhci_hcd: stop threads


[ 1151.178329][T26761] usb 17-1: new low-speed USB device number 2 using
vhci_hcd


SK: Looking at the console log, it looks like while connection is being
torn down,


[ 1151.181245][ T240] vhci_hcd: release socket


Can you share your your test code for this program:
"executing program 1"

Also your setup? Do you run usbip_host and vhci_hcd both?

thanks,
-- Shuah


2021-01-30 09:39:48

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2021/01/30 6:18, Shuah Khan wrote:
> In this console log:

It seems "this console log" refers to https://syzkaller.appspot.com/x/log.txt?x=10453034500000 .

>
> 06:57:50 executing program 1:
> socketpair$tipc(0x1e, 0x2, 0x0, &(0x7f00000000c0)={<r0=>0xffffffffffffffff})
> sendmsg$BATADV_CMD_GET_TRANSTABLE_LOCAL(r0, &(0x7f00000002c0)={&(0x7f00000001c0), 0xc, &(0x7f0000000280)={0x0, 0xd001010000000000}}, 0x0)
>
> [ 1151.090883][T23361] vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(4)
> [ 1151.097445][T23361] vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)
> 06:57:50 executing program 0:
> r0 = syz_open_dev$binderN(&(0x7f0000000680)='/dev/binder#\x00', 0x0, 0x0)
> ioctl$BINDER_WRITE_READ(r0, 0xc0306201, &(0x7f0000000cc0)={0x88, 0x0, &(0x7f0000000b80)=[@transaction={0x40406300, {0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}, @transaction={0x40406300, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}], 0x0, 0x0, 0x0})
>
> [ 1151.164402][T23363] vhci_hcd: connection closed
> [ 1151.167346][  T240] vhci_hcd: stop threads
>
>
> [ 1151.178329][T26761] usb 17-1: new low-speed USB device number 2 using vhci_hcd
>
>
> SK: Looking at the console log, it looks like while connection is being
>     torn down,

Excuse me, but it looks like (what comes here) while connection is being torn down ?
I'm not familiar with driver code.

>
>
> [ 1151.181245][  T240] vhci_hcd: release socket
>
>
> Can you share your your test code for this program:
> "executing program 1"

I don't think program 1 is relevant. I think program 4

06:57:50 executing program 4:
r0 = socket$tipc(0x1e, 0x2, 0x0)
syz_usbip_server_init(0x1)
close_range(r0, 0xffffffffffffffff, 0x0)

which calls syz_usbip_server_init() as with other duplicates is relevant.

>
> Also your setup? Do you run usbip_host and vhci_hcd both?

Who are you referring to with "you/your" ? I'm not running syzkaller in my setup
and I don't have test code.

I'm just proposing printing more messages in order to confirm the ordering of
events and member values in structures.

2021-02-10 18:29:34

by Shuah Khan

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 1/29/21 7:25 PM, Tetsuo Handa wrote:
> On 2021/01/30 6:18, Shuah Khan wrote:
>> In this console log:
>
> It seems "this console log" refers to https://syzkaller.appspot.com/x/log.txt?x=10453034500000 .
>
>>
>> 06:57:50 executing program 1:
>> socketpair$tipc(0x1e, 0x2, 0x0, &(0x7f00000000c0)={<r0=>0xffffffffffffffff})
>> sendmsg$BATADV_CMD_GET_TRANSTABLE_LOCAL(r0, &(0x7f00000002c0)={&(0x7f00000001c0), 0xc, &(0x7f0000000280)={0x0, 0xd001010000000000}}, 0x0)
>>
>> [ 1151.090883][T23361] vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(4)
>> [ 1151.097445][T23361] vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)
>> 06:57:50 executing program 0:
>> r0 = syz_open_dev$binderN(&(0x7f0000000680)='/dev/binder#\x00', 0x0, 0x0)
>> ioctl$BINDER_WRITE_READ(r0, 0xc0306201, &(0x7f0000000cc0)={0x88, 0x0, &(0x7f0000000b80)=[@transaction={0x40406300, {0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}, @transaction={0x40406300, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}], 0x0, 0x0, 0x0})
>>
>> [ 1151.164402][T23363] vhci_hcd: connection closed
>> [ 1151.167346][  T240] vhci_hcd: stop threads
>>
>>
>> [ 1151.178329][T26761] usb 17-1: new low-speed USB device number 2 using vhci_hcd
>>
>>
>> SK: Looking at the console log, it looks like while connection is being
>>     torn down,
>
> Excuse me, but it looks like (what comes here) while connection is being torn down ?
> I'm not familiar with driver code.
>
>>
>>
>> [ 1151.181245][  T240] vhci_hcd: release socket
>>
>>
>> Can you share your your test code for this program:
>> "executing program 1"
>
> I don't think program 1 is relevant. I think program 4
>
> 06:57:50 executing program 4:
> r0 = socket$tipc(0x1e, 0x2, 0x0)
> syz_usbip_server_init(0x1)
> close_range(r0, 0xffffffffffffffff, 0x0)
>
> which calls syz_usbip_server_init() as with other duplicates is relevant.
>
>>
>> Also your setup? Do you run usbip_host and vhci_hcd both?
>
> Who are you referring to with "you/your" ? I'm not running syzkaller in my setup
> and I don't have test code.
>
> I'm just proposing printing more messages in order to confirm the ordering of
> events and member values in structures.
>

I am looking to understand the syzbot configuration and a reproducer
to be able to debug and fix the problem. How is syzbot triggering the
vhci_hcd attach and detach sequence?

This helps me determine all these fix suggestions that are coming in
are fixes or papering over a real problem.

thanks,
-- Shuah

2021-02-10 19:10:41

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2021/02/11 3:17, Shuah Khan wrote:
> I am looking to understand the syzbot configuration and a reproducer
> to be able to debug and fix the problem. How is syzbot triggering the
> vhci_hcd attach and detach sequence?

I don't know. I'm waiting for syzbot to reproduce the problem on linux-next
with https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/drivers/usb/usbip?id=f1bdf414e7dd0cbc26460425719fc3ea479947a2 .

>
> This helps me determine all these fix suggestions that are coming in
> are fixes or papering over a real problem.

What are these fix suggestions?

"general protection fault in tomoyo_socket_sendmsg_permission" is a NULL pointer
dereference which can happen if vhci_device_reset() and/or vhci_device_init()
(which does vdev->ud.tcp_socket = NULL;) were unexpectedly called. There is no
reproducer, and (as far as I know) no fix suggestion.

"KASAN: null-ptr-deref Write in vhci_shutdown_connection" is an ERR_PTR(-EINTR)
pointer dereference which can happen if kthread_create() was SIGKILLed. There is
a reproducer, and https://lkml.kernel.org/r/[email protected]
is a fix suggestion.

2021-02-10 19:31:22

by Shuah Khan

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2/10/21 12:07 PM, Tetsuo Handa wrote:
> On 2021/02/11 3:17, Shuah Khan wrote:
>> I am looking to understand the syzbot configuration and a reproducer
>> to be able to debug and fix the problem. How is syzbot triggering the
>> vhci_hcd attach and detach sequence?
>
> I don't know. I'm waiting for syzbot to reproduce the problem on linux-next
> with https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/drivers/usb/usbip?id=f1bdf414e7dd0cbc26460425719fc3ea479947a2 .
>
>>
>> This helps me determine all these fix suggestions that are coming in
>> are fixes or papering over a real problem.
>
> What are these fix suggestions?
>
> "general protection fault in tomoyo_socket_sendmsg_permission" is a NULL pointer
> dereference which can happen if vhci_device_reset() and/or vhci_device_init()
> (which does vdev->ud.tcp_socket = NULL;) were unexpectedly called. There is no
> reproducer, and (as far as I know) no fix suggestion.
>
Right. I would like to get a clear understanding of how this condition
is triggered. I am not saying this isn't a problem. Understanding how
it is triggered helps find the best fix.

> "KASAN: null-ptr-deref Write in vhci_shutdown_connection" is an ERR_PTR(-EINTR)
> pointer dereference which can happen if kthread_create() was SIGKILLed. There is
> a reproducer, and https://lkml.kernel.org/r/[email protected]
> is a fix suggestion.
>

This is a good find. I already replied to the thread to send a complete
fix.

thanks,
-- Shuah

2021-02-11 01:19:19

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

(Dropping LSM ML because this is not a TOMOYO's bug.)

On 2021/02/11 4:29, Shuah Khan wrote:
> This is a good find. I already replied to the thread to send a complete
> fix.

As I said at https://lkml.kernel.org/r/[email protected] ,
the as-is patch is effectively a complete fix. And applying the as-is patch should help spending
syzbot resources for reproducing "general protection fault in tomoyo_socket_sendmsg_permission"
with debug printk() patch applied, which in turn will help you in

> Right. I would like to get a clear understanding of how this condition
> is triggered. I am not saying this isn't a problem. Understanding how
> it is triggered helps find the best fix.

part. Therefore, I strongly expect you to apply this version now.

2021-02-12 01:37:01

by Shuah Khan

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2/10/21 6:14 PM, Tetsuo Handa wrote:
> (Dropping LSM ML because this is not a TOMOYO's bug.)
>
> On 2021/02/11 4:29, Shuah Khan wrote:
>> This is a good find. I already replied to the thread to send a complete
>> fix.
>
> As I said at https://lkml.kernel.org/r/[email protected] ,
> the as-is patch is effectively a complete fix. And applying the as-is patch should help spending
> syzbot resources for reproducing "general protection fault in tomoyo_socket_sendmsg_permission"
> with debug printk() patch applied, which in turn will help you in
>
>> Right. I would like to get a clear understanding of how this condition
>> is triggered. I am not saying this isn't a problem. Understanding how
>> it is triggered helps find the best fix.
>
> part. Therefore, I strongly expect you to apply this version now.
>

Is there a reproducer for this problem?

thanks,
-- Shuah

2021-02-12 02:24:33

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2021/02/12 10:34, Shuah Khan wrote:
> On 2/10/21 6:14 PM, Tetsuo Handa wrote:
>> (Dropping LSM ML because this is not a TOMOYO's bug.)
>>
>> On 2021/02/11 4:29, Shuah Khan wrote:
>>> This is a good find. I already replied to the thread to send a complete
>>> fix.
>>
>> As I said at https://lkml.kernel.org/r/[email protected] ,
>> the as-is patch is effectively a complete fix. And applying the as-is patch should help spending
>> syzbot resources for reproducing "general protection fault in tomoyo_socket_sendmsg_permission"
>> with debug printk() patch applied, which in turn will help you in
>>
>>> Right. I would like to get a clear understanding of how this condition
>>> is triggered. I am not saying this isn't a problem. Understanding how
>>> it is triggered helps find the best fix.
>>
>> part. Therefore, I strongly expect you to apply this version now.
>>
>
> Is there a reproducer for this problem?

There is no reproducer for "general protection fault in tomoyo_socket_sendmsg_permission" problem, but
the race condition is explained at https://lkml.kernel.org/r/[email protected] .

2021-02-12 05:01:28

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2021/02/12 11:22, Tetsuo Handa wrote:
> On 2021/02/12 10:34, Shuah Khan wrote:
>> On 2/10/21 6:14 PM, Tetsuo Handa wrote:
>>> (Dropping LSM ML because this is not a TOMOYO's bug.)
>>>
>>> On 2021/02/11 4:29, Shuah Khan wrote:
>>>> This is a good find. I already replied to the thread to send a complete
>>>> fix.
>>>
>>> As I said at https://lkml.kernel.org/r/[email protected] ,
>>> the as-is patch is effectively a complete fix. And applying the as-is patch should help spending
>>> syzbot resources for reproducing "general protection fault in tomoyo_socket_sendmsg_permission"
>>> with debug printk() patch applied, which in turn will help you in
>>>
>>>> Right. I would like to get a clear understanding of how this condition
>>>> is triggered. I am not saying this isn't a problem. Understanding how
>>>> it is triggered helps find the best fix.
>>>
>>> part. Therefore, I strongly expect you to apply this version now.
>>>
>>
>> Is there a reproducer for this problem?
>
> There is no reproducer for "general protection fault in tomoyo_socket_sendmsg_permission" problem, but
> the race condition is explained at https://lkml.kernel.org/r/[email protected] .
>

Here is a race window widening patch, and I locally reproduced "general protection fault in tomoyo_socket_sendmsg_permission".

diff --git a/drivers/usb/usbip/usbip_common.h b/drivers/usb/usbip/usbip_common.h
index 8be857a4fa13..a7c68097aa1d 100644
--- a/drivers/usb/usbip/usbip_common.h
+++ b/drivers/usb/usbip/usbip_common.h
@@ -286,6 +286,8 @@ struct usbip_device {
if (!IS_ERR(__k)) { \
get_task_struct(__k); \
wake_up_process(__k); \
+ } else { \
+ __k = NULL; \
} \
__k; \
})
diff --git a/drivers/usb/usbip/vhci_sysfs.c b/drivers/usb/usbip/vhci_sysfs.c
index be37aec250c2..93e1271d0f5d 100644
--- a/drivers/usb/usbip/vhci_sysfs.c
+++ b/drivers/usb/usbip/vhci_sysfs.c
@@ -389,8 +389,12 @@ static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
/* end the lock */

vdev->ud.tcp_rx = kthread_get_run(vhci_rx_loop, &vdev->ud, "vhci_rx");
- vdev->ud.tcp_tx = kthread_get_run(vhci_tx_loop, &vdev->ud, "vhci_tx");
+ {
+ struct task_struct *tx = kthread_get_run(vhci_tx_loop, &vdev->ud, "vhci_tx");

+ schedule_timeout_uninterruptible(HZ);
+ vdev->ud.tcp_tx = tx;
+ }
rh_port_connect(vdev, speed);

return count;


[ 134.880383][ T7879] vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(6)
[ 134.883465][ T7879] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 134.904750][ T74] vhci_hcd: vhci_device speed not set
[ 134.933053][ T7873] vhci_hcd: connection closed
[ 134.933212][ T7870] vhci_hcd: connection closed
[ 134.933415][ T4488] vhci_hcd: stop threads
[ 134.942970][ T4488] vhci_hcd: release socket
[ 134.944949][ T14] vhci_hcd: vhci_device speed not set
[ 134.947063][ T4488] vhci_hcd: disconnect device
[ 134.951508][ T4488] vhci_hcd: stop threads
[ 134.953861][ T4488] vhci_hcd: release socket
[ 134.957113][ T4488] vhci_hcd: disconnect device
[ 135.014433][ T56] usb 15-1: enqueue for inactive port 0
[ 135.065119][ T7877] vhci_hcd: connection closed
[ 135.065205][ T7880] vhci_hcd: connection closed
[ 135.065370][ T4480] vhci_hcd: stop threads
[ 135.072854][ T4480] vhci_hcd: release socket
[ 135.076490][ T4480] vhci_hcd: disconnect device
[ 135.079535][ T4480] vhci_hcd: stop threads
[ 135.084024][ T4480] vhci_hcd: release socket
[ 135.087979][ T4480] vhci_hcd: disconnect device
[ 135.134526][ T6820] vhci_hcd: vhci_device speed not set
[ 135.314959][ T6821] vhci_hcd: vhci_device speed not set
[ 135.621271][ T7884] vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
[ 135.621290][ T7885] vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
[ 135.625072][ T7884] vhci_hcd vhci_hcd.0: devid(0) speed(5) speed_str(super-speed)
[ 135.628665][ T7885] vhci_hcd vhci_hcd.0: devid(0) speed(5) speed_str(super-speed)
[ 135.630109][ T7887] vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
[ 135.630116][ T7887] vhci_hcd vhci_hcd.0: devid(0) speed(5) speed_str(super-speed)
[ 135.672834][ T7895] vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(6)
[ 135.672863][ T7894] vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(6)
[ 135.675986][ T7895] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 135.678963][ T7894] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 135.681093][ T7896] vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(6)
[ 135.681100][ T7896] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 135.710416][ T7904] vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
[ 135.713445][ T7904] vhci_hcd vhci_hcd.0: devid(0) speed(5) speed_str(super-speed)
[ 135.761360][ T7907] vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(6)
[ 135.764612][ T7907] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 135.780607][ T7911] vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
[ 135.783674][ T7911] vhci_hcd vhci_hcd.0: devid(0) speed(5) speed_str(super-speed)
[ 135.832151][ T7914] vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(6)
[ 135.835065][ T6821] vhci_hcd: vhci_device speed not set
[ 135.835457][ T7914] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 135.855511][ T14] vhci_hcd: vhci_device speed not set
[ 135.873043][ T7892] vhci_hcd: connection closed
[ 135.873092][ T7899] vhci_hcd: connection closed
[ 135.873331][ T4482] vhci_hcd: stop threads
[ 135.876115][ T7897] vhci_hcd: connection closed
[ 135.876272][ T7888] vhci_hcd: connection closed
[ 135.878623][ T7890] vhci_hcd: connection closed
[ 135.878927][ T7901] vhci_hcd: connection closed
[ 135.878971][ T4482] vhci_hcd: release socket
[ 135.878999][ T4482] vhci_hcd: disconnect device
[ 135.879077][ T4482] vhci_hcd: stop threads
[ 135.879084][ T4482] vhci_hcd: release socket
[ 135.879104][ T4482] vhci_hcd: disconnect device
[ 135.879262][ T4482] vhci_hcd: stop threads
[ 135.904625][ T6821] usb 14-1: new full-speed USB device number 5 using vhci_hcd
[ 135.905231][ T4482] vhci_hcd: release socket
[ 135.907733][ T7902] vhci_hcd: sendmsg failed!, ret=-32 for 48
[ 135.910718][ T4482] vhci_hcd: disconnect device
[ 135.924520][ T4482] vhci_hcd: stop threads
[ 135.924602][ T14] usb 6-1: new full-speed USB device number 4 using vhci_hcd
[ 135.927400][ T4482] vhci_hcd: release socket
[ 135.927444][ T4482] vhci_hcd: disconnect device
[ 135.927612][ T4482] vhci_hcd: stop threads
[ 135.927616][ T4482] vhci_hcd: release socket
[ 135.927637][ T4482] vhci_hcd: disconnect device
[ 135.927783][ T4482] vhci_hcd: stop threads
[ 135.931827][ T14] usb 6-1: enqueue for inactive port 0
[ 135.931837][ T14] usb 6-1: enqueue for inactive port 0
[ 135.931844][ T14] usb 6-1: enqueue for inactive port 0
[ 135.949977][ T7918] vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
[ 135.950493][ T4482] vhci_hcd: release socket
[ 135.953289][ T7918] vhci_hcd vhci_hcd.0: devid(0) speed(5) speed_str(super-speed)
[ 135.956713][ T4482] vhci_hcd: disconnect device
[ 135.962382][ T7908] vhci_hcd: connection closed
[ 135.962570][ T7905] vhci_hcd: connection closed
[ 135.963301][ T4482] vhci_hcd: stop threads
[ 135.963305][ T4482] vhci_hcd: release socket
[ 135.963329][ T4482] vhci_hcd: disconnect device
[ 135.964679][ T66] usb 17-1: enqueue for inactive port 0
[ 135.967048][ T4488] vhci_hcd: stop threads
[ 135.967055][ T4488] vhci_hcd: release socket
[ 135.996537][ T4488] vhci_hcd: disconnect device
[ 136.001837][ T7921] vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(6)
[ 136.005729][ T7921] vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
[ 136.009523][ T14] vhci_hcd: vhci_device speed not set
[ 136.033302][ T7912] vhci_hcd: connection closed
[ 136.033417][ T7915] vhci_hcd: connection closed
[ 136.041456][ T4479] vhci_hcd: stop threads
[ 136.053100][ T4479] vhci_hcd: release socket
[ 136.057791][ T4479] vhci_hcd: disconnect device
[ 136.061453][ T4479] vhci_hcd: stop threads
[ 136.064363][ T4479] vhci_hcd: release socket
[ 136.067801][ T4479] vhci_hcd: disconnect device
[ 136.193586][ T7922] vhci_hcd: connection closed
[ 136.193753][ T7919] vhci_hcd: connection closed
[ 136.193834][ T4479] vhci_hcd: stop threads
[ 136.194633][ T6805] usb 11-1: SetAddress Request (6) to port 0
[ 136.194650][ T6805] usb 11-1: new SuperSpeed Gen 1 USB device number 6 using vhci_hcd
[ 136.209426][ T4479] vhci_hcd: release socket
[ 136.211891][ T4479] vhci_hcd: disconnect device
[ 136.214638][ T4479] vhci_hcd: stop threads
[ 136.214638][ T66] usb 17-1: enqueue for inactive port 0
[ 136.220796][ T4479] vhci_hcd: release socket
[ 136.223414][ T4479] vhci_hcd: disconnect device
[ 136.226214][ T7920] BUG: kernel NULL pointer dereference, address: 0000000000000018
[ 136.229703][ T7920] #PF: supervisor read access in kernel mode
[ 136.250275][ T7920] #PF: error_code(0x0000) - not-present page
[ 136.254738][ T7920] PGD 0 P4D 0
[ 136.258410][ T7920] Oops: 0000 [#1] PREEMPT SMP
[ 136.263059][ T7920] CPU: 5 PID: 7920 Comm: vhci_tx Not tainted 5.11.0-rc7+ #8
[ 136.269087][ T7920] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 02/27/2020
[ 136.278990][ T7920] RIP: 0010:tomoyo_socket_sendmsg_permission+0x2b/0x120
[ 136.283875][ T7920] Code: 48 89 e5 41 57 49 89 f7 41 56 41 55 41 54 53 48 89 fb 48 83 ec 38 65 48 8b 04 25 28 00 00 00 48 89 45 d0 31 c0 e8 85 7a 5e ff <4c> 8b 73 18 45 0f b6 66 10 41 80 fc 02 77 32 45 84 e4 75 36 45 31
[ 136.297600][ T7920] RSP: 0018:ffffc9001425fc60 EFLAGS: 00010293
[ 136.302027][ T7920] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 136.306816][ T7920] RDX: ffff8881305ee280 RSI: ffffffff81d7fe1b RDI: 0000000000000000
[ 136.311669][ T7920] RBP: ffffc9001425fcc0 R08: 0000000000000030 R09: 0000000000000000
[ 136.315802][ T7920] R10: ffff88813432eb80 R11: 0000000000000000 R12: 0000000000000000
[ 136.320276][ T7920] R13: ffffc9001425fdd0 R14: 0000000000000030 R15: ffffc9001425fdd0
[ 136.324546][ T7920] FS: 0000000000000000(0000) GS:ffff888236f40000(0000) knlGS:0000000000000000
[ 136.329094][ T7920] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 136.333203][ T7920] CR2: 0000000000000018 CR3: 0000000129054005 CR4: 00000000003706e0
[ 136.337599][ T7920] Call Trace:
[ 136.340429][ T7920] ? __this_cpu_preempt_check+0x1d/0x30
[ 136.344165][ T7920] tomoyo_socket_sendmsg+0x26/0x30
[ 136.347801][ T7920] security_socket_sendmsg+0x40/0x70
[ 136.351378][ T7920] sock_sendmsg+0x26/0xd0
[ 136.354702][ T7920] kernel_sendmsg+0x44/0x50
[ 136.358078][ T7920] vhci_send_cmd_submit+0x269/0x520
[ 136.361674][ T7920] ? _raw_spin_unlock_irqrestore+0x5a/0x70
[ 136.365796][ T7920] vhci_tx_loop+0x52/0x180
[ 136.369274][ T7920] ? finish_wait+0x90/0x90
[ 136.372657][ T7920] kthread+0x18d/0x1c0
[ 136.376299][ T7920] ? vhci_send_cmd_unlink+0x220/0x220
[ 136.380052][ T7920] ? kthread_insert_work_sanity_check+0x90/0x90
[ 136.384729][ T7920] ret_from_fork+0x22/0x30
[ 136.388347][ T7920] Modules linked in:
[ 136.391571][ T7920] CR2: 0000000000000018
[ 136.394835][ T7920] ---[ end trace 66ee501d798fb2fa ]---
[ 136.398442][ T7920] RIP: 0010:tomoyo_socket_sendmsg_permission+0x2b/0x120
[ 136.403062][ T7920] Code: 48 89 e5 41 57 49 89 f7 41 56 41 55 41 54 53 48 89 fb 48 83 ec 38 65 48 8b 04 25 28 00 00 00 48 89 45 d0 31 c0 e8 85 7a 5e ff <4c> 8b 73 18 45 0f b6 66 10 41 80 fc 02 77 32 45 84 e4 75 36 45 31
[ 136.415061][ T2899] usb 9-1: device descriptor read/8, error -110
[ 136.415245][ T7920] RSP: 0018:ffffc9001425fc60 EFLAGS: 00010293
[ 136.422520][ T7920] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 136.426912][ T7920] RDX: ffff8881305ee280 RSI: ffffffff81d7fe1b RDI: 0000000000000000
[ 136.431943][ T7920] RBP: ffffc9001425fcc0 R08: 0000000000000030 R09: 0000000000000000
[ 136.434304][ T66] kobject: '17-1' (000000000e8a79ee): kobject_cleanup, parent 0000000000000000
[ 136.436148][ T7920] R10: ffff88813432eb80 R11: 0000000000000000 R12: 0000000000000000
[ 136.436153][ T7920] R13: ffffc9001425fdd0 R14: 0000000000000030 R15: ffffc9001425fdd0
[ 136.436157][ T7920] FS: 0000000000000000(0000) GS:ffff888236f40000(0000) knlGS:0000000000000000
[ 136.436161][ T7920] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 136.436165][ T7920] CR2: 0000000000000018 CR3: 0000000129054005 CR4: 00000000003706e0
[ 136.436189][ T7920] Kernel panic - not syncing: Fatal exception
[ 137.608838][ T7920] Shutting down cpus with NMI
[ 149.797229][ T7920] Kernel Offset: disabled
[ 149.800911][ T7920] Rebooting in 86400 seconds..

2021-02-12 20:05:05

by Shuah Khan

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On 2/11/21 9:58 PM, Tetsuo Handa wrote:
> On 2021/02/12 11:22, Tetsuo Handa wrote:
>> On 2021/02/12 10:34, Shuah Khan wrote:
>>> On 2/10/21 6:14 PM, Tetsuo Handa wrote:
>>>> (Dropping LSM ML because this is not a TOMOYO's bug.)
>>>>
>>>> On 2021/02/11 4:29, Shuah Khan wrote:
>>>>> This is a good find. I already replied to the thread to send a complete
>>>>> fix.
>>>>
>>>> As I said at https://lkml.kernel.org/r/[email protected] ,
>>>> the as-is patch is effectively a complete fix. And applying the as-is patch should help spending
>>>> syzbot resources for reproducing "general protection fault in tomoyo_socket_sendmsg_permission"
>>>> with debug printk() patch applied, which in turn will help you in
>>>>
>>>>> Right. I would like to get a clear understanding of how this condition
>>>>> is triggered. I am not saying this isn't a problem. Understanding how
>>>>> it is triggered helps find the best fix.
>>>>
>>>> part. Therefore, I strongly expect you to apply this version now.
>>>>
>>>
>>> Is there a reproducer for this problem?
>>
>> There is no reproducer for "general protection fault in tomoyo_socket_sendmsg_permission" problem, but
>> the race condition is explained at https://lkml.kernel.org/r/[email protected] .
>>
>
> Here is a race window widening patch, and I locally reproduced "general protection fault in tomoyo_socket_sendmsg_permission".
>
> diff --git a/drivers/usb/usbip/usbip_common.h b/drivers/usb/usbip/usbip_common.h
> index 8be857a4fa13..a7c68097aa1d 100644
> --- a/drivers/usb/usbip/usbip_common.h
> +++ b/drivers/usb/usbip/usbip_common.h
> @@ -286,6 +286,8 @@ struct usbip_device {
> if (!IS_ERR(__k)) { \
> get_task_struct(__k); \
> wake_up_process(__k); \
> + } else { \
> + __k = NULL; \
> } \
> __k; \
> })
> diff --git a/drivers/usb/usbip/vhci_sysfs.c b/drivers/usb/usbip/vhci_sysfs.c
> index be37aec250c2..93e1271d0f5d 100644
> --- a/drivers/usb/usbip/vhci_sysfs.c
> +++ b/drivers/usb/usbip/vhci_sysfs.c
> @@ -389,8 +389,12 @@ static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
> /* end the lock */
>
> vdev->ud.tcp_rx = kthread_get_run(vhci_rx_loop, &vdev->ud, "vhci_rx");
> - vdev->ud.tcp_tx = kthread_get_run(vhci_tx_loop, &vdev->ud, "vhci_tx");
> + {
> + struct task_struct *tx = kthread_get_run(vhci_tx_loop, &vdev->ud, "vhci_tx");
>
> + schedule_timeout_uninterruptible(HZ);
> + vdev->ud.tcp_tx = tx;
> + }
> rh_port_connect(vdev, speed);
>
> return count;
>

Thank you. This is helpful. I will try to reproduce the problem with
this test code.

thanks,
-- Shuah

2021-02-13 10:10:40

by Tetsuo Handa

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

Greg, will you queue https://lkml.kernel.org/r/[email protected] (which can
close a report which is wasting syzbot's resource with 5300+ crashes) for 5.12 ? The change shown below will be
too large to test before merge window for 5.12 opens.

The patch for fixing "general protection fault in tomoyo_socket_sendmsg_permission" will kill kthread_get_run().
Closing frequently crashing bug now is the better.

On 2021/02/11 22:40, Tetsuo Handa wrote:
> I guess that we need to serialize attach operation and reset/detach operations, for
> it seems there is a race window that might result in "general protection fault in
> tomoyo_socket_sendmsg_permission". Details follows...

Here is untested diff that is expected to be complete.

(1) Handle kthread_create() failure (which avoids "KASAN: null-ptr-deref Write in vhci_shutdown_connection")
by grouping socket lookup, SOCK_STREAM check and kthread_get_run() into usbip_prepare_threads() function.

(2) Serialize usbip_sockfd_store(), detach_store(), attach_store(), usbip_sockfd_store() and
ud->eh_ops.shutdown()/ud->eh_ops.reset()/ud->eh_ops.unusable() operations using usbip_store_mutex mutex
(which avoids "general protection fault in tomoyo_socket_sendmsg_permission").

(3) Don't reset ud->tcp_socket to NULL in vhci_device_reset(). Since tx_thread/rx_thread depends on
ud->tcp_socket != NULL whereas tcp_socket and tx_thread/rx_thread are assigned at the same time,
it is never safe to reset only ud->tcp_socket from ud->eh_ops.reset(). And actually nobody is
calling ud->eh_ops.reset() without ud->eh_ops.shutdown().

(4) usbip_sockfd_store() must perform {sdev,udc}->ud.status != SDEV_ST_AVAILABLE && {sdev,udc}->ud.status = SDEV_ST_USED
exclusively, or multiple tx_thread/rx_thread can be created when concurrently called. Although (2) will already
serialize this action, (1) will make it possible to perform within one spinlock section.

drivers/usb/usbip/stub_dev.c | 56 ++++++++++++++++++--------------
drivers/usb/usbip/usbip_common.c | 55 +++++++++++++++++++++++++++++++
drivers/usb/usbip/usbip_common.h | 13 ++++++++
drivers/usb/usbip/usbip_event.c | 9 +++++
drivers/usb/usbip/vhci_hcd.c | 7 +---
drivers/usb/usbip/vhci_sysfs.c | 50 ++++++++++++++++++++--------
drivers/usb/usbip/vudc_sysfs.c | 50 ++++++++++++++++------------
7 files changed, 175 insertions(+), 65 deletions(-)

diff --git a/drivers/usb/usbip/stub_dev.c b/drivers/usb/usbip/stub_dev.c
index 2305d425e6c9..522d58826049 100644
--- a/drivers/usb/usbip/stub_dev.c
+++ b/drivers/usb/usbip/stub_dev.c
@@ -39,12 +39,11 @@ static DEVICE_ATTR_RO(usbip_status);
* is used to transfer usbip requests by kernel threads. -1 is a magic number
* by which usbip connection is finished.
*/
-static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *attr,
- const char *buf, size_t count)
+static ssize_t __usbip_sockfd_store(struct device *dev, struct device_attribute *attr,
+ const char *buf, size_t count)
{
struct stub_device *sdev = dev_get_drvdata(dev);
int sockfd = 0;
- struct socket *socket;
int rv;

if (!sdev) {
@@ -57,7 +56,12 @@ static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *a
return -EINVAL;

if (sockfd != -1) {
- int err;
+ struct usbip_thread_info uti;
+ int err = usbip_prepare_threads(&uti, &sdev->ud, sockfd,
+ stub_tx_loop, "stub_tx", stub_rx_loop, "stub_rx");
+
+ if (err)
+ return err;

dev_info(dev, "stub up\n");

@@ -65,44 +69,46 @@ static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *a

if (sdev->ud.status != SDEV_ST_AVAILABLE) {
dev_err(dev, "not ready\n");
- goto err;
+ spin_unlock_irq(&sdev->ud.lock);
+ usbip_unprepare_threads(&uti);
+ return -EINVAL;
}

- socket = sockfd_lookup(sockfd, &err);
- if (!socket)
- goto err;
-
- sdev->ud.tcp_socket = socket;
+ sdev->ud.tcp_socket = uti.tcp_socket;
sdev->ud.sockfd = sockfd;
-
- spin_unlock_irq(&sdev->ud.lock);
-
- sdev->ud.tcp_rx = kthread_get_run(stub_rx_loop, &sdev->ud,
- "stub_rx");
- sdev->ud.tcp_tx = kthread_get_run(stub_tx_loop, &sdev->ud,
- "stub_tx");
-
- spin_lock_irq(&sdev->ud.lock);
+ sdev->ud.tcp_rx = uti.tcp_rx;
+ sdev->ud.tcp_tx = uti.tcp_tx;
sdev->ud.status = SDEV_ST_USED;
spin_unlock_irq(&sdev->ud.lock);

+ wake_up_process(sdev->ud.tcp_rx);
+ wake_up_process(sdev->ud.tcp_tx);
} else {
dev_info(dev, "stub down\n");

spin_lock_irq(&sdev->ud.lock);
- if (sdev->ud.status != SDEV_ST_USED)
- goto err;
-
+ if (sdev->ud.status != SDEV_ST_USED) {
+ spin_unlock_irq(&sdev->ud.lock);
+ return -EINVAL;
+ }
spin_unlock_irq(&sdev->ud.lock);

usbip_event_add(&sdev->ud, SDEV_EVENT_DOWN);
}

return count;
+}

-err:
- spin_unlock_irq(&sdev->ud.lock);
- return -EINVAL;
+static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *attr,
+ const char *buf, size_t count)
+{
+ ssize_t ret;
+
+ if (mutex_lock_killable(&usbip_store_mutex))
+ return -EINTR;
+ ret = __usbip_sockfd_store(dev, attr, buf, count);
+ mutex_unlock(&usbip_store_mutex);
+ return ret;
}
static DEVICE_ATTR_WO(usbip_sockfd);

diff --git a/drivers/usb/usbip/usbip_common.c b/drivers/usb/usbip/usbip_common.c
index 2ab99244bc31..f86e49fc89a7 100644
--- a/drivers/usb/usbip/usbip_common.c
+++ b/drivers/usb/usbip/usbip_common.c
@@ -748,6 +748,61 @@ int usbip_recv_xbuff(struct usbip_device *ud, struct urb *urb)
}
EXPORT_SYMBOL_GPL(usbip_recv_xbuff);

+int usbip_prepare_threads(struct usbip_thread_info *uti,
+ struct usbip_device *ud, int sockfd,
+ int (*tx_fn)(void *data), const char *tx_name,
+ int (*rx_fn)(void *data), const char *rx_name)
+{
+ int err;
+ struct socket *socket;
+ struct task_struct *tx;
+ struct task_struct *rx;
+
+ /* Extract socket from fd. */
+ socket = sockfd_lookup(sockfd, &err);
+ if (!socket)
+ return -EINVAL;
+ /* Verify that this is a stream socket. */
+ if (socket->type != SOCK_STREAM) {
+ err = -EINVAL;
+ goto out_socket;
+ }
+ /* Create threads for this socket. */
+ rx = kthread_create(rx_fn, ud, rx_name);
+ if (IS_ERR(rx)) {
+ err = PTR_ERR(rx);
+ goto out_socket;
+ }
+ tx = kthread_create(tx_fn, ud, tx_name);
+ if (IS_ERR(tx)) {
+ err = PTR_ERR(rx);
+ goto out_rx;
+ }
+ uti->tcp_socket = socket;
+ get_task_struct(rx);
+ uti->tcp_rx = rx;
+ get_task_struct(rx);
+ uti->tcp_tx = tx;
+ return 0;
+ out_rx:
+ kthread_stop(rx);
+ out_socket:
+ sockfd_put(socket);
+ return err;
+}
+EXPORT_SYMBOL_GPL(usbip_prepare_threads);
+
+void usbip_unprepare_threads(struct usbip_thread_info *uti)
+{
+ kthread_stop_put(uti->tcp_rx);
+ uti->tcp_rx = NULL;
+ kthread_stop_put(uti->tcp_rx);
+ uti->tcp_rx = NULL;
+ sockfd_put(uti->tcp_socket);
+ uti->tcp_socket = NULL;
+}
+EXPORT_SYMBOL_GPL(usbip_unprepare_threads);
+
static int __init usbip_core_init(void)
{
return usbip_init_eh();
diff --git a/drivers/usb/usbip/usbip_common.h b/drivers/usb/usbip/usbip_common.h
index 8be857a4fa13..fba1827e719b 100644
--- a/drivers/usb/usbip/usbip_common.h
+++ b/drivers/usb/usbip/usbip_common.h
@@ -309,6 +309,19 @@ void usbip_header_correct_endian(struct usbip_header *pdu, int send);
struct usbip_iso_packet_descriptor*
usbip_alloc_iso_desc_pdu(struct urb *urb, ssize_t *bufflen);

+struct usbip_thread_info {
+ struct socket *tcp_socket;
+ struct task_struct *tcp_tx;
+ struct task_struct *tcp_rx;
+};
+
+extern struct mutex usbip_store_mutex;
+int usbip_prepare_threads(struct usbip_thread_info *uti,
+ struct usbip_device *ud, int sockfd,
+ int (*tx_fn)(void *data), const char *tx_name,
+ int (*rx_fn)(void *data), const char *rx_name);
+void usbip_unprepare_threads(struct usbip_thread_info *uti);
+
/* some members of urb must be substituted before. */
int usbip_recv_iso(struct usbip_device *ud, struct urb *urb);
void usbip_pad_iso(struct usbip_device *ud, struct urb *urb);
diff --git a/drivers/usb/usbip/usbip_event.c b/drivers/usb/usbip/usbip_event.c
index 5d88917c9631..d4f7dd366102 100644
--- a/drivers/usb/usbip/usbip_event.c
+++ b/drivers/usb/usbip/usbip_event.c
@@ -19,6 +19,9 @@ struct usbip_event {
static DEFINE_SPINLOCK(event_lock);
static LIST_HEAD(event_list);

+DEFINE_MUTEX(usbip_store_mutex);
+EXPORT_SYMBOL_GPL(usbip_store_mutex);
+
static void set_event(struct usbip_device *ud, unsigned long event)
{
unsigned long flags;
@@ -75,19 +78,25 @@ static void event_handler(struct work_struct *work)
* Shutdown the device.
*/
if (ud->event & USBIP_EH_SHUTDOWN) {
+ mutex_lock(&usbip_store_mutex);
ud->eh_ops.shutdown(ud);
+ mutex_unlock(&usbip_store_mutex);
unset_event(ud, USBIP_EH_SHUTDOWN);
}

/* Reset the device. */
if (ud->event & USBIP_EH_RESET) {
+ mutex_lock(&usbip_store_mutex);
ud->eh_ops.reset(ud);
+ mutex_unlock(&usbip_store_mutex);
unset_event(ud, USBIP_EH_RESET);
}

/* Mark the device as unusable. */
if (ud->event & USBIP_EH_UNUSABLE) {
+ mutex_lock(&usbip_store_mutex);
ud->eh_ops.unusable(ud);
+ mutex_unlock(&usbip_store_mutex);
unset_event(ud, USBIP_EH_UNUSABLE);
}

diff --git a/drivers/usb/usbip/vhci_hcd.c b/drivers/usb/usbip/vhci_hcd.c
index 3209b5ddd30c..eaae6fa8cff4 100644
--- a/drivers/usb/usbip/vhci_hcd.c
+++ b/drivers/usb/usbip/vhci_hcd.c
@@ -1072,12 +1072,7 @@ static void vhci_device_reset(struct usbip_device *ud)

usb_put_dev(vdev->udev);
vdev->udev = NULL;
-
- if (ud->tcp_socket) {
- sockfd_put(ud->tcp_socket);
- ud->tcp_socket = NULL;
- ud->sockfd = -1;
- }
+ ud->sockfd = -1;
ud->status = VDEV_ST_NULL;

spin_unlock_irqrestore(&ud->lock, flags);
diff --git a/drivers/usb/usbip/vhci_sysfs.c b/drivers/usb/usbip/vhci_sysfs.c
index be37aec250c2..5f282dc54626 100644
--- a/drivers/usb/usbip/vhci_sysfs.c
+++ b/drivers/usb/usbip/vhci_sysfs.c
@@ -225,8 +225,8 @@ static int valid_port(__u32 *pdev_nr, __u32 *rhport)
return 1;
}

-static ssize_t detach_store(struct device *dev, struct device_attribute *attr,
- const char *buf, size_t count)
+static ssize_t __detach_store(struct device *dev, struct device_attribute *attr,
+ const char *buf, size_t count)
{
__u32 port = 0, pdev_nr = 0, rhport = 0;
struct usb_hcd *hcd;
@@ -263,6 +263,17 @@ static ssize_t detach_store(struct device *dev, struct device_attribute *attr,

return count;
}
+static ssize_t detach_store(struct device *dev, struct device_attribute *attr,
+ const char *buf, size_t count)
+{
+ ssize_t ret;
+
+ if (mutex_lock_killable(&usbip_store_mutex))
+ return -EINTR;
+ ret = __detach_store(dev, attr, buf, count);
+ mutex_unlock(&usbip_store_mutex);
+ return ret;
+}
static DEVICE_ATTR_WO(detach);

static int valid_args(__u32 *pdev_nr, __u32 *rhport,
@@ -300,10 +311,10 @@ static int valid_args(__u32 *pdev_nr, __u32 *rhport,
*
* write() returns 0 on success, else negative errno.
*/
-static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
- const char *buf, size_t count)
+static ssize_t __attach_store(struct device *dev, struct device_attribute *attr,
+ const char *buf, size_t count)
{
- struct socket *socket;
+ struct usbip_thread_info uti;
int sockfd = 0;
__u32 port = 0, pdev_nr = 0, rhport = 0, devid = 0, speed = 0;
struct usb_hcd *hcd;
@@ -347,10 +358,10 @@ static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
else
vdev = &vhci->vhci_hcd_hs->vdev[rhport];

- /* Extract socket from fd. */
- socket = sockfd_lookup(sockfd, &err);
- if (!socket)
- return -EINVAL;
+ err = usbip_prepare_threads(&uti, &vdev->ud, sockfd,
+ vhci_tx_loop, "vhci_tx", vhci_rx_loop, "vhci_rx");
+ if (err)
+ return err;

/* now need lock until setting vdev status as used */

@@ -363,7 +374,7 @@ static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
spin_unlock(&vdev->ud.lock);
spin_unlock_irqrestore(&vhci->lock, flags);

- sockfd_put(socket);
+ usbip_unprepare_threads(&uti);

dev_err(dev, "port %d already used\n", rhport);
/*
@@ -381,20 +392,33 @@ static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
vdev->devid = devid;
vdev->speed = speed;
vdev->ud.sockfd = sockfd;
- vdev->ud.tcp_socket = socket;
+ vdev->ud.tcp_socket = uti.tcp_socket;
+ vdev->ud.tcp_rx = uti.tcp_rx;
+ vdev->ud.tcp_rx = uti.tcp_tx;
vdev->ud.status = VDEV_ST_NOTASSIGNED;

spin_unlock(&vdev->ud.lock);
spin_unlock_irqrestore(&vhci->lock, flags);
/* end the lock */

- vdev->ud.tcp_rx = kthread_get_run(vhci_rx_loop, &vdev->ud, "vhci_rx");
- vdev->ud.tcp_tx = kthread_get_run(vhci_tx_loop, &vdev->ud, "vhci_tx");
+ wake_up_process(vdev->ud.tcp_rx);
+ wake_up_process(vdev->ud.tcp_tx);

rh_port_connect(vdev, speed);

return count;
}
+static ssize_t attach_store(struct device *dev, struct device_attribute *attr,
+ const char *buf, size_t count)
+{
+ ssize_t ret;
+
+ if (mutex_lock_killable(&usbip_store_mutex))
+ return -EINTR;
+ ret = __attach_store(dev, attr, buf, count);
+ mutex_unlock(&usbip_store_mutex);
+ return ret;
+}
static DEVICE_ATTR_WO(attach);

#define MAX_STATUS_NAME 16
diff --git a/drivers/usb/usbip/vudc_sysfs.c b/drivers/usb/usbip/vudc_sysfs.c
index 100f680c572a..de5df1c7f32f 100644
--- a/drivers/usb/usbip/vudc_sysfs.c
+++ b/drivers/usb/usbip/vudc_sysfs.c
@@ -90,14 +90,13 @@ static ssize_t dev_desc_read(struct file *file, struct kobject *kobj,
}
static BIN_ATTR_RO(dev_desc, sizeof(struct usb_device_descriptor));

-static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *attr,
- const char *in, size_t count)
+static ssize_t __usbip_sockfd_store(struct device *dev, struct device_attribute *attr,
+ const char *in, size_t count)
{
struct vudc *udc = (struct vudc *) dev_get_drvdata(dev);
int rv;
int sockfd = 0;
- int err;
- struct socket *socket;
+ struct usbip_thread_info uti = { };
unsigned long flags;
int ret;

@@ -109,6 +108,14 @@ static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *a
dev_err(dev, "no device");
return -ENODEV;
}
+
+ if (sockfd != -1) {
+ ret = usbip_prepare_threads(&uti, &udc->ud, sockfd,
+ v_tx_loop, "vudc_tx", v_rx_loop, "vudc_rx");
+ if (ret)
+ return ret;
+ }
+
spin_lock_irqsave(&udc->lock, flags);
/* Don't export what we don't have */
if (!udc->driver || !udc->pullup) {
@@ -130,28 +137,17 @@ static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *a
ret = -EINVAL;
goto unlock_ud;
}
-
- socket = sockfd_lookup(sockfd, &err);
- if (!socket) {
- dev_err(dev, "failed to lookup sock");
- ret = -EINVAL;
- goto unlock_ud;
- }
-
- udc->ud.tcp_socket = socket;
-
+ udc->ud.tcp_socket = uti.tcp_socket;
+ udc->ud.tcp_rx = uti.tcp_rx;
+ udc->ud.tcp_tx = uti.tcp_tx;
+ udc->ud.status = SDEV_ST_USED;
spin_unlock_irq(&udc->ud.lock);
spin_unlock_irqrestore(&udc->lock, flags);

- udc->ud.tcp_rx = kthread_get_run(&v_rx_loop,
- &udc->ud, "vudc_rx");
- udc->ud.tcp_tx = kthread_get_run(&v_tx_loop,
- &udc->ud, "vudc_tx");
+ wake_up_process(udc->ud.tcp_rx);
+ wake_up_process(udc->ud.tcp_tx);

spin_lock_irqsave(&udc->lock, flags);
- spin_lock_irq(&udc->ud.lock);
- udc->ud.status = SDEV_ST_USED;
- spin_unlock_irq(&udc->ud.lock);

ktime_get_ts64(&udc->start_time);
v_start_timer(udc);
@@ -181,7 +177,19 @@ static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *a
spin_unlock_irq(&udc->ud.lock);
unlock:
spin_unlock_irqrestore(&udc->lock, flags);
+ if (uti.tcp_socket)
+ usbip_unprepare_threads(&uti);
+ return ret;
+}
+static ssize_t usbip_sockfd_store(struct device *dev, struct device_attribute *attr,
+ const char *in, size_t count)
+{
+ ssize_t ret;

+ if (mutex_lock_killable(&usbip_store_mutex))
+ return -EINTR;
+ ret = __usbip_sockfd_store(dev, attr, in, count);
+ mutex_unlock(&usbip_store_mutex);
return ret;
}
static DEVICE_ATTR_WO(usbip_sockfd);
--
2.18.4


2021-02-13 10:12:35

by Greg KH

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On Sat, Feb 13, 2021 at 07:02:22PM +0900, Tetsuo Handa wrote:
> Greg, will you queue https://lkml.kernel.org/r/[email protected] (which can
> close a report which is wasting syzbot's resource with 5300+ crashes) for 5.12 ? The change shown below will be
> too large to test before merge window for 5.12 opens.
>
> The patch for fixing "general protection fault in tomoyo_socket_sendmsg_permission" will kill kthread_get_run().
> Closing frequently crashing bug now is the better.
>
> On 2021/02/11 22:40, Tetsuo Handa wrote:
> > I guess that we need to serialize attach operation and reset/detach operations, for
> > it seems there is a race window that might result in "general protection fault in
> > tomoyo_socket_sendmsg_permission". Details follows...
>
> Here is untested diff that is expected to be complete.

Please work and test this and get it merged in a normal manner, there is
no "rush" here at all. Submit it properly and all will be fine.

thanks,

greg k-h

2021-02-13 10:14:52

by Greg KH

[permalink] [raw]
Subject: Re: general protection fault in tomoyo_socket_sendmsg_permission

On Sat, Feb 13, 2021 at 07:02:22PM +0900, Tetsuo Handa wrote:
> Greg, will you queue https://lkml.kernel.org/r/[email protected] (which can
> close a report which is wasting syzbot's resource with 5300+ crashes) for 5.12 ? The change shown below will be
> too large to test before merge window for 5.12 opens.
>
> The patch for fixing "general protection fault in tomoyo_socket_sendmsg_permission" will kill kthread_get_run().
> Closing frequently crashing bug now is the better.
>
> On 2021/02/11 22:40, Tetsuo Handa wrote:
> > I guess that we need to serialize attach operation and reset/detach operations, for
> > it seems there is a race window that might result in "general protection fault in
> > tomoyo_socket_sendmsg_permission". Details follows...
>
> Here is untested diff that is expected to be complete.
>
> (1) Handle kthread_create() failure (which avoids "KASAN: null-ptr-deref Write in vhci_shutdown_connection")
> by grouping socket lookup, SOCK_STREAM check and kthread_get_run() into usbip_prepare_threads() function.
>
> (2) Serialize usbip_sockfd_store(), detach_store(), attach_store(), usbip_sockfd_store() and
> ud->eh_ops.shutdown()/ud->eh_ops.reset()/ud->eh_ops.unusable() operations using usbip_store_mutex mutex
> (which avoids "general protection fault in tomoyo_socket_sendmsg_permission").
>
> (3) Don't reset ud->tcp_socket to NULL in vhci_device_reset(). Since tx_thread/rx_thread depends on
> ud->tcp_socket != NULL whereas tcp_socket and tx_thread/rx_thread are assigned at the same time,
> it is never safe to reset only ud->tcp_socket from ud->eh_ops.reset(). And actually nobody is
> calling ud->eh_ops.reset() without ud->eh_ops.shutdown().
>
> (4) usbip_sockfd_store() must perform {sdev,udc}->ud.status != SDEV_ST_AVAILABLE && {sdev,udc}->ud.status = SDEV_ST_USED
> exclusively, or multiple tx_thread/rx_thread can be created when concurrently called. Although (2) will already
> serialize this action, (1) will make it possible to perform within one spinlock section.

Shouldn't this be 4 different patches?

thanks,

greg k-h