RE: [REGRESSION] Freeze on resume from S3 (bisected)

[Ping-Ke Shih <pkshih@realtek.com>]

[-- Attachment #1: Type: text/plain, Size: 2054 bytes --]

Hi Mathew,

Forty Five <mathewegeorge@gmail.com> wrote:
> 
> Mathew George <mathewegeorge@gmail.com> writes:
> 
> > When I am back at my system, I will reproduce the issue a few more times with
> > this kernel, and attach the logs. In the meantime, you could have a look at the logs
> > linked in my first mail. There are logs for most of the bad commits encountered in the
> > bisection.
> 
> I've attached more logs.

Thanks for the logs, which you met two kinds of problems. One is firmware gets
wrong during system resumes, and the other is to close a disappear netdev. 
However I still can't dig why it gets wrong. I will focus on latter one first.

The behavior between no commit [1] and the latest tree + [2] is the time waiting
for ACK from scan abort firmware command. The former one is longer, and latter
one is shorter. 

I also enable kernel debug KASAN suggested by Johannes to dig problem, but in
my side I can't see any kernel warning and the crash. 

Since I saw 'NetworkManager' and 'hostapd' in code trace, I would like to know
if you have two virtual interfaces, which for STA and AP modes? (Please check
this by 'iw dev') If so, is it possible to remove hostapd (AP mode) to see if
this is a factor causing crash.

Attachment is a debug patch that add more messages and code trace, please help
to reproduce problem with patches of [2] and attachment. If your kernel enables
dynamic debug, need additional commands to have debug message:
   sudo bash -c 'echo -n "module rtw89_core +p" > /sys/kernel/debug/dynamic_debug/control'
   sudo bash -c 'echo -n "module rtw89_pci +p" > /sys/kernel/debug/dynamic_debug/control'
Since there are more than one symptoms causing system freeze, please collect
four logs as before. Also please give me two logs that system can normally
suspend/resume, so I can compare their difference.


[1] bcbefbd032 wifi: rtw89: add wait/completion for abort scan
[2] https://lore.kernel.org/linux-wireless/20240517013350.11278-1-pkshih@realtek.com/

Thanks
Ping-ke


[-- Attachment #2: 0001-debug-scan-abort.patch --]
[-- Type: application/octet-stream, Size: 7181 bytes --]

From 0dec70207ab62c87e2f9b3a232166e07c3260f36 Mon Sep 17 00:00:00 2001
From: Ping-Ke Shih <pkshih@realtek.com>
Date: Fri, 28 Jun 2024 11:17:59 +0800
Subject: [PATCH] debug scan abort

Signed-off-by: Ping-Ke Shih <pkshih@realtek.com>
---
 drivers/net/wireless/realtek/rtw89/debug.c    |  2 +-
 drivers/net/wireless/realtek/rtw89/fw.c       |  5 +++
 drivers/net/wireless/realtek/rtw89/mac.c      |  4 ++
 drivers/net/wireless/realtek/rtw89/mac80211.c | 42 ++++++++++++++++---
 drivers/net/wireless/realtek/rtw89/pci.c      |  4 ++
 5 files changed, 50 insertions(+), 7 deletions(-)

diff --git a/drivers/net/wireless/realtek/rtw89/debug.c b/drivers/net/wireless/realtek/rtw89/debug.c
index 49bbbd049316..4709d50b8fa1 100644
--- a/drivers/net/wireless/realtek/rtw89/debug.c
+++ b/drivers/net/wireless/realtek/rtw89/debug.c
@@ -14,7 +14,7 @@
 #include "sar.h"
 
 #ifdef CONFIG_RTW89_DEBUGMSG
-unsigned int rtw89_debug_mask;
+unsigned int rtw89_debug_mask = 0x80021000;
 EXPORT_SYMBOL(rtw89_debug_mask);
 module_param_named(debug_mask, rtw89_debug_mask, uint, 0644);
 MODULE_PARM_DESC(debug_mask, "Debugging mask");
diff --git a/drivers/net/wireless/realtek/rtw89/fw.c b/drivers/net/wireless/realtek/rtw89/fw.c
index fbe08c162b93..eecb43ad6735 100644
--- a/drivers/net/wireless/realtek/rtw89/fw.c
+++ b/drivers/net/wireless/realtek/rtw89/fw.c
@@ -4855,6 +4855,9 @@ int rtw89_fw_h2c_scan_offload(struct rtw89_dev *rtwdev,
 	else
 		cond = RTW89_SCANOFLD_WAIT_COND_STOP;
 
+	printk("pk> %s:%d start scan offload abort=%d\n", __func__, __LINE__,
+		!option->enable);
+
 	ret = rtw89_h2c_tx_and_wait(rtwdev, skb, wait, cond);
 	if (ret) {
 		rtw89_debug(rtwdev, RTW89_DBG_FW, "failed to scan ofld\n");
@@ -6267,6 +6270,8 @@ void rtw89_hw_scan_complete(struct rtw89_dev *rtwdev, struct ieee80211_vif *vif,
 	if (!vif)
 		return;
 
+	printk("pk> %s:%d abort=%d\n", __func__, __LINE__, scan_info->abort);
+
 	rtw89_write32_mask(rtwdev,
 			   rtw89_mac_reg_by_idx(rtwdev, mac->rx_fltr, RTW89_MAC_0),
 			   B_AX_RX_FLTR_CFG_MASK,
diff --git a/drivers/net/wireless/realtek/rtw89/mac.c b/drivers/net/wireless/realtek/rtw89/mac.c
index 73462f3343e3..48ef521618e2 100644
--- a/drivers/net/wireless/realtek/rtw89/mac.c
+++ b/drivers/net/wireless/realtek/rtw89/mac.c
@@ -4757,6 +4757,8 @@ rtw89_mac_c2h_scanofld_rsp(struct rtw89_dev *rtwdev, struct sk_buff *skb,
 		}
 		return;
 	case RTW89_SCAN_END_SCAN_NOTIFY:
+		printk("pk> %s:%d scan end handler abort=%d\n", __func__, __LINE__,
+			rtwdev->scan_info.abort);
 		if (rtwdev->scan_info.abort)
 			return;
 
@@ -4895,6 +4897,7 @@ rtw89_mac_c2h_done_ack(struct rtw89_dev *rtwdev, struct sk_buff *skb_c2h, u32 le
 			break;
 		case H2C_FUNC_SCANOFLD:
 			cond = RTW89_SCANOFLD_WAIT_COND_START;
+			printk("pk> %s:%d DACK for scan offload\n", __func__, __LINE__);
 			break;
 		case H2C_FUNC_SCANOFLD_BE:
 			cond = RTW89_SCANOFLD_BE_WAIT_COND_START;
@@ -5283,6 +5286,7 @@ static void rtw89_mac_c2h_scanofld_rsp_atomic(struct rtw89_dev *rtwdev,
 		else
 			cond = RTW89_SCANOFLD_WAIT_COND_STOP;
 
+		printk("pk> %s:%d scan end ISR\n", __func__, __LINE__);
 		rtw89_complete_cond(fw_ofld_wait, cond, &data);
 	}
 }
diff --git a/drivers/net/wireless/realtek/rtw89/mac80211.c b/drivers/net/wireless/realtek/rtw89/mac80211.c
index 41b286da3d59..9f2d42552ed2 100644
--- a/drivers/net/wireless/realtek/rtw89/mac80211.c
+++ b/drivers/net/wireless/realtek/rtw89/mac80211.c
@@ -60,6 +60,14 @@ static int rtw89_ops_start(struct ieee80211_hw *hw)
 	int ret;
 
 	mutex_lock(&rtwdev->mutex);
+
+	{
+	extern void dump_stack(void);
+
+	printk("pk> %s:%d\n", __func__, __LINE__);
+	dump_stack();
+	}
+
 	ret = rtw89_core_start(rtwdev);
 	mutex_unlock(&rtwdev->mutex);
 
@@ -71,6 +79,14 @@ static void rtw89_ops_stop(struct ieee80211_hw *hw)
 	struct rtw89_dev *rtwdev = hw->priv;
 
 	mutex_lock(&rtwdev->mutex);
+
+	{
+	extern void dump_stack(void);
+
+	printk("pk> %s:%d\n", __func__, __LINE__);
+	dump_stack();
+	}
+
 	rtw89_core_stop(rtwdev);
 	mutex_unlock(&rtwdev->mutex);
 }
@@ -112,8 +128,8 @@ static int rtw89_ops_add_interface(struct ieee80211_hw *hw,
 	struct rtw89_vif *rtwvif = (struct rtw89_vif *)vif->drv_priv;
 	int ret = 0;
 
-	rtw89_debug(rtwdev, RTW89_DBG_STATE, "add vif %pM type %d, p2p %d\n",
-		    vif->addr, vif->type, vif->p2p);
+	rtw89_debug(rtwdev, RTW89_DBG_STATE, "add vif %p %pM type %d, p2p %d\n",
+		    vif, vif->addr, vif->type, vif->p2p);
 
 	mutex_lock(&rtwdev->mutex);
 
@@ -175,8 +191,8 @@ static void rtw89_ops_remove_interface(struct ieee80211_hw *hw,
 	struct rtw89_dev *rtwdev = hw->priv;
 	struct rtw89_vif *rtwvif = (struct rtw89_vif *)vif->drv_priv;
 
-	rtw89_debug(rtwdev, RTW89_DBG_STATE, "remove vif %pM type %d p2p %d\n",
-		    vif->addr, vif->type, vif->p2p);
+	rtw89_debug(rtwdev, RTW89_DBG_STATE, "remove vif %p %pM type %d p2p %d\n",
+		    vif, vif->addr, vif->type, vif->p2p);
 
 	cancel_work_sync(&rtwvif->update_beacon_work);
 	cancel_delayed_work_sync(&rtwvif->roc.roc_work);
@@ -202,8 +218,8 @@ static int rtw89_ops_change_interface(struct ieee80211_hw *hw,
 
 	set_bit(RTW89_FLAG_CHANGING_INTERFACE, rtwdev->flags);
 
-	rtw89_debug(rtwdev, RTW89_DBG_STATE, "change vif %pM (%d)->(%d), p2p (%d)->(%d)\n",
-		    vif->addr, vif->type, type, vif->p2p, p2p);
+	rtw89_debug(rtwdev, RTW89_DBG_STATE, "change vif %p %pM (%d)->(%d), p2p (%d)->(%d)\n",
+		    vif, vif->addr, vif->type, type, vif->p2p, p2p);
 
 	rtw89_ops_remove_interface(hw, vif);
 
@@ -882,6 +898,13 @@ static int rtw89_ops_hw_scan(struct ieee80211_hw *hw, struct ieee80211_vif *vif,
 	struct rtw89_vif *rtwvif = vif_to_rtwvif_safe(vif);
 	int ret = 0;
 
+	{
+	extern void dump_stack(void);
+
+	printk("pk> %s:%d vif=%p\n", __func__, __LINE__, vif);
+	dump_stack();
+	}
+
 	if (!RTW89_CHK_FW_FEATURE(SCAN_OFFLOAD, &rtwdev->fw))
 		return 1;
 
@@ -905,6 +928,13 @@ static void rtw89_ops_cancel_hw_scan(struct ieee80211_hw *hw,
 {
 	struct rtw89_dev *rtwdev = hw->priv;
 
+	{
+	extern void dump_stack(void);
+
+	printk("pk> %s:%d vif=%p\n", __func__, __LINE__, vif);
+	dump_stack();
+	}
+
 	if (!RTW89_CHK_FW_FEATURE(SCAN_OFFLOAD, &rtwdev->fw))
 		return;
 
diff --git a/drivers/net/wireless/realtek/rtw89/pci.c b/drivers/net/wireless/realtek/rtw89/pci.c
index 02afeb3acce4..c95fa9e66cc4 100644
--- a/drivers/net/wireless/realtek/rtw89/pci.c
+++ b/drivers/net/wireless/realtek/rtw89/pci.c
@@ -4160,6 +4160,8 @@ static int __maybe_unused rtw89_pci_suspend(struct device *dev)
 	struct rtw89_dev *rtwdev = hw->priv;
 	enum rtw89_core_chip_id chip_id = rtwdev->chip->chip_id;
 
+	printk("pk> %s:%d\n", __func__, __LINE__);
+
 	rtw89_write32_set(rtwdev, R_AX_RSV_CTRL, B_AX_WLOCK_1C_BIT6);
 	rtw89_write32_set(rtwdev, R_AX_RSV_CTRL, B_AX_R_DIS_PRST);
 	rtw89_write32_clr(rtwdev, R_AX_RSV_CTRL, B_AX_WLOCK_1C_BIT6);
@@ -4194,6 +4196,8 @@ static int __maybe_unused rtw89_pci_resume(struct device *dev)
 	struct rtw89_dev *rtwdev = hw->priv;
 	enum rtw89_core_chip_id chip_id = rtwdev->chip->chip_id;
 
+	printk("pk> %s:%d\n", __func__, __LINE__);
+
 	rtw89_write32_set(rtwdev, R_AX_RSV_CTRL, B_AX_WLOCK_1C_BIT6);
 	rtw89_write32_clr(rtwdev, R_AX_RSV_CTRL, B_AX_R_DIS_PRST);
 	rtw89_write32_clr(rtwdev, R_AX_RSV_CTRL, B_AX_WLOCK_1C_BIT6);
-- 
2.25.1