Received-SPF: pass (google.com: domain of linux-bluetooth+bounces-771-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:45e3:2400::1 as permitted sender) client-ip=2604:1380:45e3:2400::1;
From: Neeraj Sanjay Kale <neeraj.sanjaykale@nxp.com>
To: marcel@holtmann.org,
	johan.hedberg@gmail.com,
	luiz.dentz@gmail.com
Cc: amitkumar.karwar@nxp.com,
	neeraj.sanjaykale@nxp.com,
	linux-bluetooth@vger.kernel.org,
	linux-kernel@vger.kernel.org,
	sherry.sun@nxp.com,
	rohit.fule@nxp.com
Subject: [PATCH v3] Bluetooth: btnxpuart: Resolve TX timeout error in power save stress test
Date: Wed, 27 Dec 2023 18:59:27 +0530
Message-Id: <20231227132927.3938396-1-neeraj.sanjaykale@nxp.com>
Content-Transfer-Encoding: 8bit
Content-Type: text/plain
Precedence: bulk
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0:
	=?us-ascii?Q?I4lEDDfiRlrILWfBwXt6bpeY5ALZbUq4e+77eN34E67WBYNj64MWvfmId7lU?=
 =?us-ascii?Q?0J0Rr2jIQ3qVLW6m6K1p8+AXCY1AC1GUYqWYZP4KAKyxxtTa2RWoLmGWSVmx?=
 =?us-ascii?Q?t6tL0m7SgfdqIuStzfgzxllR7Eeqo1m0kTgnOm+Z5febaEUKckIeFP+Z/49G?=
 =?us-ascii?Q?T4whtnAbpHxt/HAQ7uDTMco9v+wAUNNVViQaIa0XK1ezk4FTXCPdzEOuGCNO?=
 =?us-ascii?Q?1tZ8gmkT7cd2agAQYkTuUGiesG1P3YCPyhksaJuxRCfTL9NrP/WvO0spAvSZ?=
 =?us-ascii?Q?gKbcNjS8TLrhk5UqyfMMebNLM1bSJ5g1KrL4jLbwVat3Ha+m7LQIoH6IYgjF?=
 =?us-ascii?Q?jirQRDh/rVxIqYTsbD6I3dsKtD5t7dtbuYeuZ4bHmyQVkbJfIhMgmkgjFtOo?=
 =?us-ascii?Q?iSVlKYGVGZt3xss1EajTJdMql8XEGBZqzys4uMKZycxAJqkYFemkqmSsXh2+?=
 =?us-ascii?Q?dpmfC+h9WSW4MfHWafH52UR7SvFDKqCCWmbqAKZEIrxtBsyUbZrnDkF3TD9c?=
 =?us-ascii?Q?B6v9ETylATdK8bLI5nVgidR5aN87TL0/+baY+1ujNgrpCJPykXmEVFgUV7a6?=
 =?us-ascii?Q?fYme+tQRoWMttbW63cItKoMWckgktXczVUWEo/rtm6JwccqzOFHQe0YD54dJ?=
 =?us-ascii?Q?ncUcBF1nRhp5QbMd90NeI2JAvRiDiha5QnBpj7Pv1HLGgPs8+LBpVOfdvdNr?=
 =?us-ascii?Q?0clERzRQDrgcdg44VKfjKT/7CkP0+DcD+yaj0TFFcYR8F6JxVtqhb4LoKlpF?=
 =?us-ascii?Q?O+iY7vzK9vDWyU1u6fgjgA2kmKgbviVKGyV72uXpGCHqMK8vm0VHwkNAx+CU?=
 =?us-ascii?Q?3lnrl7tbOFIhmCPrfCOLaxAsBJoSyQx7nmSLTy0url3Ou8N7CeIKkQn65hm7?=
 =?us-ascii?Q?zyACKP2S3R1iozdm3x2bXGPa1f3H3EbZe1MBZaXTw6Jsx+6BmGNHy0bySj6H?=
 =?us-ascii?Q?w4QBR7jArgNZZZCQSR57L6lKVaaTSOH3YdlGi46C55SIpsxyXn6se5EVR/KK?=
 =?us-ascii?Q?TrB7COqkPAXXcTxPZH86O6wVmvtNLPy2CBnmEvFceVn8BHj5nrt0YVcjUWiJ?=
 =?us-ascii?Q?vKwTGvxt6aCNPoSa5UKztt9ef7DKzg7q69aDJ+5d+Pd9YZorDZtMwOFaHPkh?=
 =?us-ascii?Q?U230syHQj+MbPQQxXuBnnJf/7y88iGzLJUCoFpSe4+sdhOH3w2vOv3QgvBHy?=
 =?us-ascii?Q?FALSUcsKZxGSgvcB/7mmjyay/vY/Wxmp/B14r3lTcOxjZ5y5rbfXrTNS2Dq7?=
 =?us-ascii?Q?CIoRgqPMjmow56OfYqZL3/MTfzrI9NgW1DnrN+7HdqmduRrwMc19WRnjmWlR?=
 =?us-ascii?Q?6jiqmAf7hmux8N5gl/obgQVFaKhJkYFvJMVAf60Fb/I7fD6utNf3a9ZhjFYk?=
 =?us-ascii?Q?5iVCKLNx7Pcswu13h080yRXx5nOd5f96dToFsqin3AZRoi9wMq57vtZaLsPP?=
 =?us-ascii?Q?NUevpMFZLWtR5bIRJjp2e4NqNShHExv0qmgpMpetqILzp86OViP63wryDbOE?=
 =?us-ascii?Q?VFA/af5pA8WHCw7s509F9R0eQRIJbPxuVSM2C9i7G1iE0K9Yy0IUGXMF9Jgi?=
 =?us-ascii?Q?TSMC06dDMO0PgHr3pe6QL92aTNJuzxaCd6snBAsacLhuAngh7aVsaC1OqdAT?=
 =?us-ascii?Q?PA=3D=3D?=
X-OriginatorOrg: nxp.com
X-MS-Exchange-CrossTenant-Network-Message-Id: ef3dc570-c2ff-4639-7227-08dc06dfb5af
X-MS-Exchange-CrossTenant-AuthSource: AM9PR04MB7668.eurprd04.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 27 Dec 2023 13:28:27.8389
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 686ea1d3-bc2b-4c6f-a92c-d99c5c301635
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: CKPfHBVUu8o9bUM+Qc+9L8rQnwBrub8SKY6yTeGyNxoQYnqrhfZ2shQFmk2+qbYGmFpxhTyYok6mGSfSAyzVqAva9zg2sssXLEzPHuSC6ho=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DBAPR04MB7287

This fixes the tx timeout issue seen while running a stress test on
btnxpuart for couple of hours, such that the interval between two HCI
commands coincide with the power save timeout value of 2 seconds.

Test procedure using bash script:
<load btnxpuart.ko>
hciconfig hci0 up
//Enable Power Save feature
hcitool -i hci0 cmd 3f 23 02 00 00
while (true)
do
    hciconfig hci0 leadv
    sleep 2
    hciconfig hci0 noleadv
    sleep 2
done

Error log, after adding few more debug prints:
Bluetooth: btnxpuart_queue_skb(): 01 0A 20 01 00
Bluetooth: hci0: Set UART break: on, status=0
Bluetooth: hci0: btnxpuart_tx_wakeup() tx_work scheduled
Bluetooth: hci0: btnxpuart_tx_work() dequeue: 01 0A 20 01 00
Can't set advertise mode on hci0: Connection timed out (110)
Bluetooth: hci0: command 0x200a tx timeout

When the power save mechanism turns on UART break, and btnxpuart_tx_work()
is scheduled simultaneously, psdata->ps_state is read as PS_STATE_AWAKE,
which prevents the psdata->work from being scheduled, which is responsible
to turn OFF UART break.

This issue is fixed by adding a ps_lock mutex around UART break on/off as
well as around ps_state read/write.
btnxpuart_tx_wakeup() will now read updated ps_state value. If ps_state is
PS_STATE_SLEEP, it will first schedule psdata->work, and then it will
reschedule itself once UART break has been turned off and ps_state is
PS_STATE_AWAKE.

Tested above script for 50,000 iterations and TX timeout error was not
observed anymore.

Signed-off-by: Neeraj Sanjay Kale <neeraj.sanjaykale@nxp.com>
---
v2: Add 20msec delay after enabling UART break, cancel ps_work when ps_timer is restarted.
v3: Fix build error. Keep a common delay of 20msec for UART break enable/disable.
---
 drivers/bluetooth/btnxpuart.c | 24 +++++++++++++++++++++---
 1 file changed, 21 insertions(+), 3 deletions(-)

diff --git a/drivers/bluetooth/btnxpuart.c b/drivers/bluetooth/btnxpuart.c
index b7e66b7ac570..9131615b6f76 100644
--- a/drivers/bluetooth/btnxpuart.c
+++ b/drivers/bluetooth/btnxpuart.c
@@ -126,6 +126,7 @@ struct ps_data {
 	struct hci_dev *hdev;
 	struct work_struct work;
 	struct timer_list ps_timer;
+	struct mutex ps_lock;
 };
 
 struct wakeup_cmd_payload {
@@ -317,6 +318,9 @@ static void ps_start_timer(struct btnxpuart_dev *nxpdev)
 
 	if (psdata->cur_psmode == PS_MODE_ENABLE)
 		mod_timer(&psdata->ps_timer, jiffies + msecs_to_jiffies(psdata->h2c_ps_interval));
+
+	if (psdata->ps_state == PS_STATE_AWAKE && psdata->ps_cmd == PS_CMD_ENTER_PS)
+		cancel_work_sync(&psdata->work);
 }
 
 static void ps_cancel_timer(struct btnxpuart_dev *nxpdev)
@@ -337,6 +341,7 @@ static void ps_control(struct hci_dev *hdev, u8 ps_state)
 	    !test_bit(BTNXPUART_SERDEV_OPEN, &nxpdev->tx_state))
 		return;
 
+	mutex_lock(&psdata->ps_lock);
 	switch (psdata->cur_h2c_wakeupmode) {
 	case WAKEUP_METHOD_DTR:
 		if (ps_state == PS_STATE_AWAKE)
@@ -350,12 +355,15 @@ static void ps_control(struct hci_dev *hdev, u8 ps_state)
 			status = serdev_device_break_ctl(nxpdev->serdev, 0);
 		else
 			status = serdev_device_break_ctl(nxpdev->serdev, -1);
+		msleep(20); /* Allow chip to detect UART-break and enter sleep */
 		bt_dev_dbg(hdev, "Set UART break: %s, status=%d",
 			   str_on_off(ps_state == PS_STATE_SLEEP), status);
 		break;
 	}
 	if (!status)
 		psdata->ps_state = ps_state;
+	mutex_unlock(&psdata->ps_lock);
+
 	if (ps_state == PS_STATE_AWAKE)
 		btnxpuart_tx_wakeup(nxpdev);
 }
@@ -391,17 +399,25 @@ static void ps_setup(struct hci_dev *hdev)
 
 	psdata->hdev = hdev;
 	INIT_WORK(&psdata->work, ps_work_func);
+	mutex_init(&psdata->ps_lock);
 	timer_setup(&psdata->ps_timer, ps_timeout_func, 0);
 }
 
-static void ps_wakeup(struct btnxpuart_dev *nxpdev)
+static bool ps_wakeup(struct btnxpuart_dev *nxpdev)
 {
 	struct ps_data *psdata = &nxpdev->psdata;
+	u8 ps_state;
 
-	if (psdata->ps_state != PS_STATE_AWAKE) {
+	mutex_lock(&psdata->ps_lock);
+	ps_state = psdata->ps_state;
+	mutex_unlock(&psdata->ps_lock);
+
+	if (ps_state != PS_STATE_AWAKE) {
 		psdata->ps_cmd = PS_CMD_EXIT_PS;
 		schedule_work(&psdata->work);
+		return true;
 	}
+	return false;
 }
 
 static int send_ps_cmd(struct hci_dev *hdev, void *data)
@@ -1171,7 +1187,6 @@ static struct sk_buff *nxp_dequeue(void *data)
 {
 	struct btnxpuart_dev *nxpdev = (struct btnxpuart_dev *)data;
 
-	ps_wakeup(nxpdev);
 	ps_start_timer(nxpdev);
 	return skb_dequeue(&nxpdev->txq);
 }
@@ -1186,6 +1201,9 @@ static void btnxpuart_tx_work(struct work_struct *work)
 	struct sk_buff *skb;
 	int len;
 
+	if (ps_wakeup(nxpdev))
+		return;
+
 	while ((skb = nxp_dequeue(nxpdev))) {
 		len = serdev_device_write_buf(serdev, skb->data, skb->len);
 		hdev->stat.byte_tx += len;
-- 
2.34.1