Received-SPF: pass (google.com: domain of linux-bluetooth+bounces-643-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:4601:e00::3 as permitted sender) client-ip=2604:1380:4601:e00::3;
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 v1] Bluetooth: btnxpuart: Resolve TX timeout error in power save stress test
Date: Mon, 18 Dec 2023 15:57:20 +0530
Message-Id: <20231218102720.3816166-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?eleRPweb290WHuRgujzONBPm4AVRu1Ruk8Bix5/9wISDq4nefuoxJssu9EDK?=
 =?us-ascii?Q?lhIow65qtG3amdktJorVv85pyKTUNvJt3QDRf+ZBz/iMtlW0pN7geoAvVWDX?=
 =?us-ascii?Q?K08W7ULBfu56uMIKTQvG0VSpLmd2eLk+yk6sjeWuOzluC4EzKaE2DzK/YYEy?=
 =?us-ascii?Q?q6FDIuNxBu7WVjKxXVcYOBKjfAV5b9Wek8Hsgxzd7PHJzuSQFN5fqT7Ui0R3?=
 =?us-ascii?Q?JS04fe8U9sozeN1hFkjgckuZjDtSSpwirJa1ccd9x+XjEaKI88eaQo6/8vJc?=
 =?us-ascii?Q?wOJN7dTAdejpMxyk4xCwsBD4t/thsdfhJkOznaXkMvEhwBXRr9HTaofpY4RI?=
 =?us-ascii?Q?F4dywfHH9S5fukjnXsxkt9Se2Wk4MpnDii7ni1d8SdVLjNHgqdawzRmJZSw5?=
 =?us-ascii?Q?pKJXXj42g85dCjQlk4nNAC3p3dWzkip4GEXtDg7z2CB1jKwlZHw8oQFc8R1O?=
 =?us-ascii?Q?pL7qT3ZeJdlFScBoZKHPqmrIF26GTFXsN4E+sDO8Jhv/d0xqHXFHG7/QVBzv?=
 =?us-ascii?Q?v/+XwjLUnhtFUlZr897H9RiFU3D1TcIudiMWf2rWdrPFNdy5TB05OuNr7+JI?=
 =?us-ascii?Q?60y/6qV0df9plchBDRjzB14rhkB70PnjgpNT9ee/35vPrqQj+3CLSwdXLcXx?=
 =?us-ascii?Q?lDqG6YbI152Ua2vlnm3ZDOAut/N0jcrTSQA7uzeRE3/l2jhAH4Vrdn5uhej8?=
 =?us-ascii?Q?DddrAw/JGJBYtQDSoOeRgYncYHjchoA09WVFlJpX1UcpHWW74L2goPWMsJJv?=
 =?us-ascii?Q?U/+IxBATRg+ohARzFa3Oa83bwsZmuNT5ia8F4y85mLbrd7R+Zyw42FSe6c7G?=
 =?us-ascii?Q?CSQf+VZn1FCO3iBOGp2/OD8q80k5M8g/FIPnnAoHdA9TVx1IWjqlQZo2e/Hz?=
 =?us-ascii?Q?XapZC7grg5hblgE6eLdmoSBAr8wyTPhxNSJCQP0+GzX0NI7XjkvKHSPETJrx?=
 =?us-ascii?Q?1zE3Nl4hMT7y4NaYxnZwxIPp9heDnCJgJ6BMNk1dOTB+rBHWaN8kcv19C/Vt?=
 =?us-ascii?Q?HDQYRk3szVnb+8a+tIOGYUs9kBImKEEJbC6sctcJQHCWTA16RV45GXnsjTnE?=
 =?us-ascii?Q?0LgSdxhZ5recf69+rXZtHQvqaG80CvTc42LTcIjFCw6+CpnRZ2r2+HuOkPCI?=
 =?us-ascii?Q?kS9LwX/mKeDcuwL+wyBrgVYK0/7LpMR3Ebl/889igCUXCwe9rVPfoWjdrxHH?=
 =?us-ascii?Q?QLVcUrmKt+a0jmFgJxaStkyZqegpu+NTJbqN+iMg81pgDfaPfhhhOf99xaOt?=
 =?us-ascii?Q?JunKlKy1kPsW+YuiahVQ6jVn6JExQzR1XRDZvIIAZJJG0toBR0ToHx25eTkv?=
 =?us-ascii?Q?lFjZ6XRU14Ki8kjXFYItW+PEVL1LlvCRs0b4g8LzyZKKEAu/ho8QXf/SXlZQ?=
 =?us-ascii?Q?6TumgI/JYrqeEq3XjzaUt2TUwkA4qM4jZf02qBrfOeOs2p70Sv0HU88F1FqL?=
 =?us-ascii?Q?4l6XCoLFcdd60EcELOXS/Q8ld7h5QlVJWYjHIi9toEGuiyLV7kySp+xxLCtt?=
 =?us-ascii?Q?ZLRPoeQGpXMdXYCD3PlCxbMo+nG4o8IJ49UTZwPa+yoQJmZUn+oyv54+yOcc?=
 =?us-ascii?Q?+PCubN280v3ivVmKnEXznjryLD6IkG1BPqrrno4I0eV8RbIcFg1VH8yS3NDj?=
 =?us-ascii?Q?qA=3D=3D?=
X-OriginatorOrg: nxp.com
X-MS-Exchange-CrossTenant-Network-Message-Id: 6ed82c13-29dd-4eec-c1f0-08dbffb3c8b8
X-MS-Exchange-CrossTenant-AuthSource: AM9PR04MB7668.eurprd04.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 18 Dec 2023 10:26:23.7770
 (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: Ez7hILKzhChI059og8nxbIHTg/s2VGzWriaE/ikfRBgWkyi9JwM4MgHuICTrrbk4MXqUyUt+CW0crOE+g467jdAKhs++LYeLiQtJ2/Ure+s=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DU2PR04MB9050

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:
[ 2206.497227] Bluetooth: btnxpuart_queue_skb(): 01 0A 20 01 00
[ 2206.498239] Bluetooth: hci0: Set UART break: on, status=0
[ 2206.503283] Bluetooth: hci0: btnxpuart_tx_wakeup() tx_work scheduled
[ 2206.503299] Bluetooth: hci0: btnxpuart_tx_work() dequeue: 01 0A 20 01 00
Can't set advertise mode on hci0: Connection timed out (110)
[ 2208.514238] 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>
---
 drivers/bluetooth/btnxpuart.c | 22 +++++++++++++++++++---
 1 file changed, 19 insertions(+), 3 deletions(-)

diff --git a/drivers/bluetooth/btnxpuart.c b/drivers/bluetooth/btnxpuart.c
index b7e66b7ac570..a68d10771c99 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 {
@@ -337,6 +338,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)
@@ -356,6 +358,8 @@ static void ps_control(struct hci_dev *hdev, u8 ps_state)
 	}
 	if (!status)
 		psdata->ps_state = ps_state;
+	mutex_unlock(&psdata->ps_lock);
+
 	if (ps_state == PS_STATE_AWAKE)
 		btnxpuart_tx_wakeup(nxpdev);
 }
@@ -391,17 +395,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;
+
+	mutex_lock(&psdata->ps_lock);
+	ps_state = psdata->ps_state;
+	mutex_unlock(&psdata->ps_lock);
 
-	if (psdata->ps_state != PS_STATE_AWAKE) {
+	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 +1183,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 +1197,11 @@ static void btnxpuart_tx_work(struct work_struct *work)
 	struct sk_buff *skb;
 	int len;
 
+	if (ps_wakeup(nxpdev)) {
+		schedule_work(&nxpdev->tx_work);
+		return;
+	}
+
 	while ((skb = nxp_dequeue(nxpdev))) {
 		len = serdev_device_write_buf(serdev, skb->data, skb->len);
 		hdev->stat.byte_tx += len;
-- 
2.34.1