Re: [PATCH] Bluetooth: avoid killing an already killed socket

From: Marcel Holtmann
Date: Mon Jul 16 2018 - 09:15:58 EST


Hi Sudip,

> slub debug reported:
>
> [ 440.648642] =============================================================================
> [ 440.648649] BUG kmalloc-1024 (Tainted: G BU O ): Poison overwritten
> [ 440.648651] -----------------------------------------------------------------------------
>
> [ 440.648655] INFO: 0xe70f4bec-0xe70f4bec. First byte 0x6a instead of 0x6b
> [ 440.648665] INFO: Allocated in sk_prot_alloc+0x6b/0xc6 age=33155 cpu=1 pid=1047
> [ 440.648671] ___slab_alloc.constprop.24+0x1fc/0x292
> [ 440.648675] __slab_alloc.isra.18.constprop.23+0x1c/0x25
> [ 440.648677] __kmalloc+0xb6/0x17f
> [ 440.648680] sk_prot_alloc+0x6b/0xc6
> [ 440.648683] sk_alloc+0x1e/0xa1
> [ 440.648700] sco_sock_alloc.constprop.6+0x26/0xaf [bluetooth]
> [ 440.648716] sco_connect_cfm+0x166/0x281 [bluetooth]
> [ 440.648731] hci_conn_request_evt.isra.53+0x258/0x281 [bluetooth]
> [ 440.648746] hci_event_packet+0x28b/0x2326 [bluetooth]
> [ 440.648759] hci_rx_work+0x161/0x291 [bluetooth]
> [ 440.648764] process_one_work+0x163/0x2b2
> [ 440.648767] worker_thread+0x1a9/0x25c
> [ 440.648770] kthread+0xf8/0xfd
> [ 440.648774] ret_from_fork+0x2e/0x38
> [ 440.648779] INFO: Freed in __sk_destruct+0xd3/0xdf age=3815 cpu=1 pid=1047
> [ 440.648782] __slab_free+0x4b/0x27a
> [ 440.648784] kfree+0x12e/0x155
> [ 440.648787] __sk_destruct+0xd3/0xdf
> [ 440.648790] sk_destruct+0x27/0x29
> [ 440.648793] __sk_free+0x75/0x91
> [ 440.648795] sk_free+0x1c/0x1e
> [ 440.648810] sco_sock_kill+0x5a/0x5f [bluetooth]
> [ 440.648825] sco_conn_del+0x8e/0xba [bluetooth]
> [ 440.648840] sco_disconn_cfm+0x3a/0x41 [bluetooth]
> [ 440.648855] hci_event_packet+0x45e/0x2326 [bluetooth]
> [ 440.648868] hci_rx_work+0x161/0x291 [bluetooth]
> [ 440.648872] process_one_work+0x163/0x2b2
> [ 440.648875] worker_thread+0x1a9/0x25c
> [ 440.648877] kthread+0xf8/0xfd
> [ 440.648880] ret_from_fork+0x2e/0x38
> [ 440.648884] INFO: Slab 0xf4718580 objects=27 used=27 fp=0x (null) flags=0x40008100
> [ 440.648886] INFO: Object 0xe70f4b88 @offset=19336 fp=0xe70f54f8
>
> When KASAN was enabled, it reported:
>
> [ 210.096613] ==================================================================
> [ 210.096634] BUG: KASAN: use-after-free in ex_handler_refcount+0x5b/0x127
> [ 210.096641] Write of size 4 at addr ffff880107e17160 by task kworker/u9:1/2040
>
> [ 210.096651] CPU: 1 PID: 2040 Comm: kworker/u9:1 Tainted: G U O 4.14.47-20180606+ #2
> [ 210.096654] Hardware name: , BIOS 2017.01-00087-g43e04de 08/30/2017
> [ 210.096693] Workqueue: hci0 hci_rx_work [bluetooth]
> [ 210.096698] Call Trace:
> [ 210.096711] dump_stack+0x46/0x59
> [ 210.096722] print_address_description+0x6b/0x23b
> [ 210.096729] ? ex_handler_refcount+0x5b/0x127
> [ 210.096736] kasan_report+0x220/0x246
> [ 210.096744] ex_handler_refcount+0x5b/0x127
> [ 210.096751] ? ex_handler_clear_fs+0x85/0x85
> [ 210.096757] fixup_exception+0x8c/0x96
> [ 210.096766] do_trap+0x66/0x2c1
> [ 210.096773] do_error_trap+0x152/0x180
> [ 210.096781] ? fixup_bug+0x78/0x78
> [ 210.096817] ? hci_debugfs_create_conn+0x244/0x26a [bluetooth]
> [ 210.096824] ? __schedule+0x113b/0x1453
> [ 210.096830] ? sysctl_net_exit+0xe/0xe
> [ 210.096837] ? __wake_up_common+0x343/0x343
> [ 210.096843] ? insert_work+0x107/0x163
> [ 210.096850] invalid_op+0x1b/0x40
> [ 210.096888] RIP: 0010:hci_debugfs_create_conn+0x244/0x26a [bluetooth]
> [ 210.096892] RSP: 0018:ffff880094a0f970 EFLAGS: 00010296
> [ 210.096898] RAX: 0000000000000000 RBX: ffff880107e170e8 RCX: ffff880107e17160
> [ 210.096902] RDX: 000000000000002f RSI: ffff88013b80ed40 RDI: ffffffffa058b940
> [ 210.096906] RBP: ffff88011b2b0578 R08: 00000000852f0ec9 R09: ffffffff81cfcf9b
> [ 210.096909] R10: 00000000d21bdad7 R11: 0000000000000001 R12: ffff8800967b0488
> [ 210.096913] R13: ffff880107e17168 R14: 0000000000000068 R15: ffff8800949c0008
> [ 210.096920] ? __sk_destruct+0x2c6/0x2d4
> [ 210.096959] hci_event_packet+0xff5/0x7de2 [bluetooth]
> [ 210.096969] ? __local_bh_enable_ip+0x43/0x5b
> [ 210.097004] ? l2cap_sock_recv_cb+0x158/0x166 [bluetooth]
> [ 210.097039] ? hci_le_meta_evt+0x2bb3/0x2bb3 [bluetooth]
> [ 210.097075] ? l2cap_ertm_init+0x94e/0x94e [bluetooth]
> [ 210.097093] ? xhci_urb_enqueue+0xbd8/0xcf5 [xhci_hcd]
> [ 210.097102] ? __accumulate_pelt_segments+0x24/0x33
> [ 210.097109] ? __accumulate_pelt_segments+0x24/0x33
> [ 210.097115] ? __update_load_avg_se.isra.2+0x217/0x3a4
> [ 210.097122] ? set_next_entity+0x7c3/0x12cd
> [ 210.097128] ? pick_next_entity+0x25e/0x26c
> [ 210.097135] ? pick_next_task_fair+0x2ca/0xc1a
> [ 210.097141] ? switch_mm_irqs_off+0x346/0xb4f
> [ 210.097147] ? __switch_to+0x769/0xbc4
> [ 210.097153] ? compat_start_thread+0x66/0x66
> [ 210.097188] ? hci_conn_check_link_mode+0x1cd/0x1cd [bluetooth]
> [ 210.097195] ? finish_task_switch+0x392/0x431
> [ 210.097228] ? hci_rx_work+0x154/0x487 [bluetooth]
> [ 210.097260] hci_rx_work+0x154/0x487 [bluetooth]
> [ 210.097269] process_one_work+0x579/0x9e9
> [ 210.097277] worker_thread+0x68f/0x804
> [ 210.097285] kthread+0x31c/0x32b
> [ 210.097292] ? rescuer_thread+0x70c/0x70c
> [ 210.097299] ? kthread_create_on_node+0xa3/0xa3
> [ 210.097306] ret_from_fork+0x35/0x40
>
> [ 210.097314] Allocated by task 2040:
> [ 210.097323] kasan_kmalloc.part.1+0x51/0xc7
> [ 210.097328] __kmalloc+0x17f/0x1b6
> [ 210.097335] sk_prot_alloc+0xf2/0x1a3
> [ 210.097340] sk_alloc+0x22/0x297
> [ 210.097375] sco_sock_alloc.constprop.7+0x23/0x202 [bluetooth]
> [ 210.097410] sco_connect_cfm+0x2d0/0x566 [bluetooth]
> [ 210.097443] hci_conn_request_evt.isra.53+0x6d3/0x762 [bluetooth]
> [ 210.097476] hci_event_packet+0x85e/0x7de2 [bluetooth]
> [ 210.097507] hci_rx_work+0x154/0x487 [bluetooth]
> [ 210.097512] process_one_work+0x579/0x9e9
> [ 210.097517] worker_thread+0x68f/0x804
> [ 210.097523] kthread+0x31c/0x32b
> [ 210.097529] ret_from_fork+0x35/0x40
>
> [ 210.097533] Freed by task 2040:
> [ 210.097539] kasan_slab_free+0xb3/0x15e
> [ 210.097544] kfree+0x103/0x1a9
> [ 210.097549] __sk_destruct+0x2c6/0x2d4
> [ 210.097584] sco_conn_del.isra.1+0xba/0x10e [bluetooth]
> [ 210.097617] hci_event_packet+0xff5/0x7de2 [bluetooth]
> [ 210.097648] hci_rx_work+0x154/0x487 [bluetooth]
> [ 210.097653] process_one_work+0x579/0x9e9
> [ 210.097658] worker_thread+0x68f/0x804
> [ 210.097663] kthread+0x31c/0x32b
> [ 210.097670] ret_from_fork+0x35/0x40
>
> [ 210.097676] The buggy address belongs to the object at ffff880107e170e8
> which belongs to the cache kmalloc-1024 of size 1024
> [ 210.097681] The buggy address is located 120 bytes inside of
> 1024-byte region [ffff880107e170e8, ffff880107e174e8)
> [ 210.097683] The buggy address belongs to the page:
> [ 210.097689] page:ffffea00041f8400 count:1 mapcount:0 mapping: (null) index:0xffff880107e15b68 compound_mapcount: 0
> [ 210.110194] flags: 0x8000000000008100(slab|head)
> [ 210.115441] raw: 8000000000008100 0000000000000000 ffff880107e15b68 0000000100170016
> [ 210.115448] raw: ffffea0004a47620 ffffea0004b48e20 ffff88013b80ed40 0000000000000000
> [ 210.115451] page dumped because: kasan: bad access detected
>
> [ 210.115454] Memory state around the buggy address:
> [ 210.115460] ffff880107e17000: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
> [ 210.115465] ffff880107e17080: fc fc fc fc fc fc fc fc fc fc fc fc fc fb fb fb
> [ 210.115469] >ffff880107e17100: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 210.115472] ^
> [ 210.115477] ffff880107e17180: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 210.115481] ffff880107e17200: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 210.115483] ==================================================================
>
> And finally when BT_DBG() and ftrace was enabled it showed:
>
> <...>-14979 [001] .... 186.104191: sco_sock_kill <-sco_sock_close
> <...>-14979 [001] .... 186.104191: sco_sock_kill <-sco_sock_release
> <...>-14979 [001] .... 186.104192: sco_sock_kill: sk ef0497a0 state 9
> <...>-14979 [001] .... 186.104193: bt_sock_unlink <-sco_sock_kill
> kworker/u9:2-792 [001] .... 186.104246: sco_sock_kill <-sco_conn_del
> kworker/u9:2-792 [001] .... 186.104248: sco_sock_kill: sk ef0497a0 state 9
> kworker/u9:2-792 [001] .... 186.104249: bt_sock_unlink <-sco_sock_kill
> kworker/u9:2-792 [001] .... 186.104250: sco_sock_destruct <-__sk_destruct
> kworker/u9:2-792 [001] .... 186.104250: sco_sock_destruct: sk ef0497a0
> kworker/u9:2-792 [001] .... 186.104860: hci_conn_del <-hci_event_packet
> kworker/u9:2-792 [001] .... 186.104864: hci_conn_del: hci0 hcon ef0484c0 handle 266
>
> Only in the failed case, sco_sock_kill() gets called with the same sock
> pointer two times. Add a check for SOCK_DEAD to avoid continue killing
> a socket which has already been killed.
>
> Signed-off-by: Sudip Mukherjee <sudipm.mukherjee@xxxxxxxxx>
> ---
> net/bluetooth/sco.c | 3 ++-
> 1 file changed, 2 insertions(+), 1 deletion(-)

patch has been applied to bluetooth-next tree.

Regards

Marcel