[BUG] Bluetooth: cmd_work queued into draining workqueue in hci_cmd_timeout()

[Yang Guikun]

Hi,

hci_cmd_timeout() queues hdev->cmd_work unconditionally, without checking
HCI_CMD_DRAIN_WORKQUEUE.  When it fires while hci_dev_close_sync() is
inside drain_workqueue(), __queue_work() sees __WQ_DRAINING and warns:

  workqueue: cannot queue hci_cmd_timeout on wq hci1

Call trace from the crash:

  __queue_work kernel/workqueue.c:2304
  call_timer_fn kernel/time/timer.c:1748
  expire_timers kernel/time/timer.c:1794
  run_timer_softirq kernel/time/timer.c:2405
  ...
  touch_wq_lockdep_map kernel/workqueue.c:4037
  __flush_workqueue kernel/workqueue.c:4079
  drain_workqueue kernel/workqueue.c:4243
  hci_dev_close_sync net/bluetooth/hci_sync.c:5436
  hci_dev_do_close net/bluetooth/hci_core.c:499
  hci_rfkill_set_block net/bluetooth/hci_core.c:890
  rfkill_set_block net/rfkill/core.c:360
  rfkill_fop_write net/rfkill/core.c:1316
  vfs_write
  ksys_write

hci_dev_close_sync() sets HCI_CMD_DRAIN_WORKQUEUE before draining:

  hci_dev_set_flag(hdev, HCI_CMD_DRAIN_WORKQUEUE);
  synchronize_rcu();
  ...
  drain_workqueue(hdev->workqueue);

but hdev->cmd_timer is cancelled only after drain_workqueue(), in the
"Drop last sent command" block.  A cmd_timer that expires during the drain
therefore reaches hci_cmd_timeout() and queues cmd_work into the draining
workqueue.

Three producers already honour the flag: hci_cmd_work() (hci_core.c:4121),
handle_cmd_cnt_and_timer() (hci_event.c:3766) and hci_sched_tx()
(hci_core.c:3292, added by 6610c6fe4b89).  hci_cmd_timeout() is the
remaining one.

hci_cmd_timeout() runs from timer softirq, so unlike the tx_work producers
fixed by 6610c6fe4b89 it is not serialised against the close path by any
socket lock.

Reproducer: with an HCI device up and a command outstanding (cmd_timer
pending), write a "block" event to /dev/rfkill.  The rfkill handler
invokes hci_dev_do_close() -> hci_dev_close_sync(); the pending cmd_timer
expires during drain_workqueue().

Still present on current mainline.  hci_cmd_timeout() at
net/bluetooth/hci_core.c:1444 in d135ab453a74 is unchanged:

  atomic_set(&hdev->cmd_cnt, 1);
  queue_work(hdev->workqueue, &hdev->cmd_work);

The same code is in net (2cffcf1aeabb) and net-next (734bef548a96).

A fix in line with hci_sched_tx():

  atomic_set(&hdev->cmd_cnt, 1);
  rcu_read_lock();
  if (!hci_dev_test_flag(hdev, HCI_CMD_DRAIN_WORKQUEUE))
      queue_work(hdev->workqueue, &hdev->cmd_work);
  rcu_read_unlock();

The effect is a dropped cmd_work and a WARNING; the work item is not
re-queued and nothing is freed twice.

Regards,
Yang Guikun