bcmdhd: Add roaming statistics to ring buffer

Create one ring buffer 'roam_stats' for store roam statistics log

Bug: 149451043
Test: hikey960
hikey960:/ # cat /data/ring-roam_stats-0.bin
[00:02:29.039384][  143.194208] roam reason: LOW_RSSI
[00:02:29.039397][  143.194220] roam status: 0
[00:02:29.039420][  143.194243] roam scan channels: count(2) 6 8
[00:02:29.039432][  143.194255] Candidate AP number: 3
[00:02:29.039452][  143.194274]   ROAM_AP_CANDIDATE 0: 70:4d:7b:0c:20:50 rssi:-42 score:0 channel:8
[00:02:29.039470][  143.194293]   ROAM_AP_CANDIDATE 1: 78:24:af:68:a1:a1 rssi:-22 score:65513 channel:6 [connected]
[00:02:29.039489][  143.194311]   ROAM_AP_CANDIDATE 2: 02:09:0b:71:3f:d5 rssi:-27 score:65508 channel:6
[00:05:50.845605][  345.000429] roam reason: RECEIVED DEAUTHENTICATION
[00:05:50.845629][  345.000452] roam status: 0
[00:05:50.845653][  345.000476] roam scan channels: count(2) 6 8
[00:05:50.845664][  345.000487] Candidate AP number: 3
[00:05:50.845684][  345.000506]   ROAM_AP_CANDIDATE 0: 78:24:af:68:a1:a1 rssi:-18 score:65517 channel:6 [connected]
[00:05:50.845703][  345.000525]   ROAM_AP_CANDIDATE 1: 02:09:0b:71:3f:d5 rssi:-31 score:65504 channel:6
[00:05:50.845721][  345.000543]   ROAM_AP_CANDIDATE 2: 70:4d:7b:0c:20:50 rssi:-41 score:65494 channel:8
[00:05:54.090990][  348.245814] roam reason: BEACONS LOST
[00:05:54.091014][  348.245837] roam status: 0
[00:05:54.091037][  348.245860] roam scan channels: count(2) 6 8
[00:05:54.091048][  348.245871] Candidate AP number: 2
[00:05:54.091068][  348.245891]   ROAM_AP_CANDIDATE 0: 02:09:0b:71:3f:d5 rssi:-30 score:65505 channel:6
[00:05:54.091116][  348.245939]   ROAM_AP_CANDIDATE 1: 70:4d:7b:0c:20:50 rssi:-40 score:65495 channel:8 [connected]

Change-Id: Ifb0e00a0af8d51f9763164739f68983217d6569e
Signed-off-by: Ahmed ElArabawy <arabawy@google.com>

8 files changed, 157 insertions, 6 deletions

diff --git a/dhd.h b/dhd.h
index a229b47..51952aa 100644
--- a/dhd.h
+++ b/dhd.h
@@ -768,6 +768,7 @@ typedef enum {
 typedef enum {
 	DBG_RING_TYPE_FW_VERBOSE = 0,
 	DBG_RING_TYPE_DRIVER_LOG = 1,
+	DBG_RING_TYPE_ROAM_STATS = 2,
 } dbg_ring_type_t;
 
 #define LOG_DUMP_MAGIC 0xDEB3DEB3
diff --git a/dhd_dbg.h b/dhd_dbg.h
index 55237cd..364ff66 100755
--- a/dhd_dbg.h
+++ b/dhd_dbg.h
@@ -65,11 +65,20 @@ extern void dhd_dbg_ring_write(int type, char *binary_data,
 	dhd_dbg_ring_write(DBG_RING_TYPE_DRIVER_LOG, NULL, 0, fmt, ##__VA_ARGS__)
 #define DHD_DBG_RING_WRITE_EX(fmt, ...) \
 	dhd_dbg_ring_write(DBG_RING_TYPE_FW_VERBOSE, NULL, 0, fmt, ##__VA_ARGS__)
+#define DHD_DBG_RING_WRITE_ROAM(fmt, ...) \
+	dhd_dbg_ring_write(DBG_RING_TYPE_ROAM_STATS, NULL, 0, fmt, ##__VA_ARGS__)
 #if defined(DHD_DEBUG)
 
 /* NON-NDIS cases */
 #ifdef DHD_LOG_DUMP
 /* Common case for EFI and non EFI */
+#define DHD_ROAM(args)	\
+do {	\
+	if (dbgring_msg_level & DHD_ERROR_VAL) {	\
+		DHD_DBG_RING_WRITE_ROAM args;	\
+	}	\
+} while (0)
+
 #define DHD_ERROR(args)	\
 do {	\
 	if (dhd_msg_level & DHD_ERROR_VAL) {	\
diff --git a/dhd_debug.c b/dhd_debug.c
index 497ba61..b2d7435 100755
--- a/dhd_debug.c
+++ b/dhd_debug.c
@@ -156,6 +156,8 @@ struct tracelog_header {
 	int seq_num;
 };
 #define TRACE_LOG_MAGIC_NUMBER 0xEAE47C06
+static void print_roam_chan_list(char *prefix, uint chan_num, uint16 band_2g,
+	uint16 uni2a, uint8 uni3, uint8 *uni2c);
 
 int
 dhd_dbg_push_to_ring(dhd_pub_t *dhdp, int ring_id, dhd_dbg_ring_entry_t *hdr, void *data)
@@ -805,6 +807,112 @@ exit:
 	MFREE(dhdp->osh, str_buf, (MAX_NO_OF_ARG * SIZE_LOC_STR));
 }
 
+typedef struct roam_ap_info {
+	uint8   ctrl_chan;
+	struct ether_addr BSSID;
+	int16   rssi;
+	uint32  score;
+	uint8	target;
+} roam_ap_info_t;
+
+#define ROAM_STATS_MAX_AP_COUNT	32
+enum {
+	ROAM_STOP_REASON_NO_ROAM_CACHE = 0,
+	ROAM_STOP_REASON_WAIT_RCV_BCN = 1,
+	ROAM_STOP_REASON_RSSI_RESUME = 2,
+	ROAM_STOP_REASON_TX_RESUME = 3,
+	ROAM_STOP_REASON_ROAM_IN_PROGRESS = 4,
+	ROAM_STOP_REASON_LAST = 5,
+};
+
+#define ROAM_STATUS_STOP_ROAM   0xdead
+typedef struct roam_log_done {
+	msgtrace_hdr_t hdr;
+	uint32	roam_reason;
+	uint32	roam_status;
+	uint8   partial_roam_chan_cnt;  /* partial roam scan channel count */
+	uint16  roam_scan_band2g_chan_list;
+	uint16  roam_scan_uni2a_chan_list;
+	uint8   roam_scan_uni2c_chan_list[3];
+	uint8   roam_scan_uni3_chan_list;
+	uint32  ap_count;
+	roam_ap_info_t *roamapinfo;
+} roam_log_done_t;
+
+void
+dhd_dbg_msgtrace_log_roam(dhd_pub_t *dhdp, void *event_data, uint datalen)
+{
+	roam_log_done_t *roam_data = (roam_log_done_t *)event_data;
+	int i;
+	roam_ap_info_t *ap_info = (roam_ap_info_t *)&roam_data->roamapinfo;
+	const char *reason_name[] = {
+		"INITIAL ASSOCIATION", /* WLC_E_REASON_INITIAL_ASSOC */
+		"LOW_RSSI", /* WLC_E_REASON_LOW_RSSI */
+		"RECEIVED DEAUTHENTICATION", /* WLC_E_REASON_DEAUTH */
+		"RECEIVED DISASSOCATION", /* WLC_E_REASON_DISASSOC */
+		"BEACONS LOST", /* WLC_E_REASON_BCNS_LOST */
+		"N/A",
+		"N/A",
+		"N/A",
+		"BETTER AP FOUND", /* WLC_E_REASON_BETTER_AP */
+		"STUCK AT MIN TX RATE", /* WLC_E_REASON_MINTXRATE */
+		"TOO MANY TXFAILURES", /* WLC_E_REASON_TXFAIL */
+		"REQUESTED ROAM" /* WLC_E_REASON_BSSTRANS_REQ */
+	};
+
+	const char *roam_stop_reason[] = {
+		"no roam cache for tx rate drop/tx fail roaming",
+				/* ROAM_STOP_REASON_NO_ROAM_CACHE */
+		"previous roaming done, waiting for receive beacon",
+				/* ROAM_STOP_REASON_WAIT_RCV_BCN */
+		"link rssi back to normal", /* ROAM_STOP_REASON_RSSI_RESUME */
+		"tx back to normal from rate drop/txfail", /* ROAM_STOP_REASON_TX_RESUME */
+		"another roaming in progress" /* ROAM_STOP_REASON_ROAM_IN_PROGRESS */
+	};
+
+	if (roam_data->ap_count > ROAM_STATS_MAX_AP_COUNT) {
+		DHD_ROAM(("Invalid roam statistics data!\n"));
+		return;
+	}
+
+	if (roam_data->roam_status == ROAM_STATUS_STOP_ROAM) {
+		DHD_ROAM(("roaming aborted, due to %s\n",
+			(roam_data->roam_reason < ROAM_STOP_REASON_LAST) ?
+				roam_stop_reason[roam_data->roam_reason]:"unknown reason"));
+		return;
+	}
+
+	/* reason */
+	DHD_ROAM(("roam reason: %s\n",
+		(roam_data->roam_reason <= WLC_E_REASON_BSSTRANS_REQ) ?
+			reason_name[roam_data->roam_reason]:"N/A"));
+
+	/* status */
+	DHD_ROAM(("roam status: %d\n", roam_data->roam_status));
+
+	/* scan channel */
+	if (roam_data->partial_roam_chan_cnt == 0)
+		DHD_ROAM(("roam scan channels: full scan\n"));
+	else {
+		print_roam_chan_list("roam scan channels",
+			roam_data->partial_roam_chan_cnt, roam_data->roam_scan_band2g_chan_list,
+			roam_data->roam_scan_uni2a_chan_list, roam_data->roam_scan_uni3_chan_list,
+			roam_data->roam_scan_uni2c_chan_list);
+	}
+
+	DHD_ROAM(("Candidate AP number: %d\n", roam_data->ap_count));
+	if (roam_data->ap_count > 0) {
+		for (i = 0; i < roam_data->ap_count; i++) {
+			DHD_ROAM(("  ROAM_AP_CANDIDATE %d: " MACDBG
+				" rssi:%d score:%d channel:%d %s\n",
+				i, MAC2STRDBG((uint8 *)&ap_info[i].BSSID),
+				ap_info[i].rssi, ap_info[i].score,
+				ap_info[i].ctrl_chan,
+				ap_info[i].target?"[connected]":""));
+		}
+	}
+}
+
 void
 dhd_dbg_msgtrace_log_parser(dhd_pub_t *dhdp, void *event_data,
 	void *raw_event_ptr, uint datalen, bool msgtrace_hdr_present,
@@ -1142,6 +1250,8 @@ dhd_dbg_trace_evnt_handler(dhd_pub_t *dhdp, void *event_data,
 		dhd_dbg_msgtrace_msg_parser(event_data);
 	else if (hdr->trace_type == MSGTRACE_HDR_TYPE_LOG)
 		dhd_dbg_msgtrace_log_parser(dhdp, event_data, raw_event_ptr, datalen, TRUE, 0);
+	else if (hdr->trace_type == MSGTRACE_HDR_TYPE_ROAM)
+		dhd_dbg_msgtrace_log_roam(dhdp, event_data, datalen);
 }
 
 /*
@@ -2208,7 +2318,7 @@ dhd_dbg_process_tx_status(dhd_pub_t *dhdp, void *pkt,
 	} \
 }
 
-void print_roam_chan_list(char *prefix, uint chan_num, uint16 band_2g,
+static void print_roam_chan_list(char *prefix, uint chan_num, uint16 band_2g,
 	uint16 uni2a, uint8 uni3, uint8 *uni2c)
 {
 	struct bcmstrbuf b;
@@ -2256,7 +2366,7 @@ void print_roam_chan_list(char *prefix, uint chan_num, uint16 band_2g,
 	}
 
 	if (cnt != 0) {
-		DHD_ERROR(("%s\n", b.origbuf));
+		DHD_ROAM(("%s\n", b.origbuf));
 	}
 }
 
@@ -2629,6 +2739,15 @@ dhd_dbg_attach(dhd_pub_t *dhdp, dbg_pullreq_t os_pullreq,
 			(uint8 *)DRIVER_LOG_RING_NAME, DRIVER_LOG_RING_SIZE, buf, FALSE);
 	if (ret)
 		goto error;
+
+	buf = MALLOCZ(dhdp->osh, ROAM_STATS_RING_SIZE);
+	if (!buf)
+		goto error;
+	ret = dhd_dbg_ring_init(dhdp, &dbg->dbg_rings[ROAM_STATS_RING_ID], ROAM_STATS_RING_ID,
+			(uint8 *)ROAM_STATS_RING_NAME, ROAM_STATS_RING_SIZE, buf, FALSE);
+	if (ret)
+		goto error;
+
 	ring_buf = &g_ring_buf;
 	dbg->private = os_priv;
 	dbg->pullreq = os_pullreq;
diff --git a/dhd_debug.h b/dhd_debug.h
index cfeff77..b0d1128 100755
--- a/dhd_debug.h
+++ b/dhd_debug.h
@@ -34,6 +34,7 @@ enum {
 	FW_VERBOSE_RING_ID,
 	DHD_EVENT_RING_ID,
 	DRIVER_LOG_RING_ID,
+	ROAM_STATS_RING_ID,
 	/* add new id here */
 	DEBUG_RING_ID_MAX
 };
@@ -60,20 +61,22 @@ enum {
 };
 
 /* firmware verbose ring, ring id 1 */
-#define FW_VERBOSE_RING_NAME		"fw_verbose"
-#define FW_VERBOSE_RING_SIZE		(256 * 1024)
+#define FW_VERBOSE_RING_NAME	"fw_verbose"
+#define FW_VERBOSE_RING_SIZE	(256 * 1024)
 /* firmware event ring, ring id 2 */
 #define FW_EVENT_RING_NAME		"fw_event"
 #define FW_EVENT_RING_SIZE		(64 * 1024)
 /* DHD driver log ring, ring id 3 */
-#define DRIVER_LOG_RING_NAME        "driver_log"
-#define DRIVER_LOG_RING_SIZE        (256 * 1024)
+#define DRIVER_LOG_RING_NAME	"driver_log"
+#define DRIVER_LOG_RING_SIZE	(256 * 1024)
 /* DHD connection event ring */
 #define DHD_EVENT_RING_NAME		"dhd_event"
 #define DHD_EVENT_RING_SIZE		(64 * 1024)
 /* NAN event ring */
 #define NAN_EVENT_RING_NAME		"nan_event"
 #define NAN_EVENT_RING_SIZE		(64 * 1024)
+#define ROAM_STATS_RING_NAME	"roam_stats"
+#define ROAM_STATS_RING_SIZE	(64 * 1024)
 
 
 #define TLV_LOG_SIZE(tlv) ((tlv) ? (sizeof(tlv_log) + (tlv)->len) : 0)
diff --git a/dhd_debug_linux.c b/dhd_debug_linux.c
index 5dd12b1..754e47e 100755
--- a/dhd_debug_linux.c
+++ b/dhd_debug_linux.c
@@ -366,6 +366,13 @@ dhd_os_push_push_ring_data(dhd_pub_t *dhdp, int ring_id, void *data, int32 data_
 		/* convert to ms */
 		msg_hdr.timestamp = DIV_U64_BY_U32(msg_hdr.timestamp, NSEC_PER_MSEC);
 		msg_hdr.len = strlen(data);
+	} else if (ring_id == ROAM_STATS_RING_ID) {
+		msg_hdr.type = DBG_RING_ENTRY_DATA_TYPE;
+		msg_hdr.flags |= DBG_RING_ENTRY_FLAGS_HAS_TIMESTAMP;
+		msg_hdr.timestamp = local_clock();
+		/* convert to ms */
+		msg_hdr.timestamp = DIV_U64_BY_U32(msg_hdr.timestamp, NSEC_PER_MSEC);
+		msg_hdr.len = strlen(data);
 	}
 	ret = dhd_dbg_push_to_ring(dhdp, ring_id, &msg_hdr, event_data);
 	if (ret) {
diff --git a/dhd_linux.c b/dhd_linux.c
index 6589c27..0d23da2 100644
--- a/dhd_linux.c
+++ b/dhd_linux.c
@@ -21393,6 +21393,16 @@ dhd_dbg_ring_write(int type, char *binary_data,
 				return;
 			}
 		}
+		if (type == DBG_RING_TYPE_ROAM_STATS){
+			if (DBG_RING_ACTIVE(dhdp, ROAM_STATS_RING_ID)) {
+				snprintf(tmp_buf, DHD_LOG_DUMP_MAX_TEMP_BUFFER_SIZE,
+					"[%s][%s] %s", dhd_dbg_get_system_timestamp(),
+						dhd_log_dump_get_timestamp(), buf);
+				dhd_os_push_push_ring_data(dhdp , ROAM_STATS_RING_ID,
+						tmp_buf, strlen(tmp_buf));
+				return;
+			}
+		}
 	}
 	return;
 }
diff --git a/include/msgtrace.h b/include/msgtrace.h
index f564999..68a4523 100644
--- a/include/msgtrace.h
+++ b/include/msgtrace.h
@@ -39,6 +39,7 @@ typedef BWL_PRE_PACKED_STRUCT struct msgtrace_hdr {
 	uint8   trace_type;
 #define MSGTRACE_HDR_TYPE_MSG 0
 #define MSGTRACE_HDR_TYPE_LOG 1
+#define MSGTRACE_HDR_TYPE_ROAM 2
 	uint16	len;	/* Len of the trace */
 	uint32	seqnum;	/* Sequence number of message. Useful if the messsage has been lost
 			 * because of DMA error or a bus reset (ex: SDIO Func2)
diff --git a/wl_cfgvendor.c b/wl_cfgvendor.c
index 7f691db..426fa22 100644
--- a/wl_cfgvendor.c
+++ b/wl_cfgvendor.c
@@ -9412,6 +9412,7 @@ int wl_cfgvendor_attach(struct wiphy *wiphy, dhd_pub_t *dhd)
 #ifdef DEBUGABILITY
 	dhd_os_dbg_register_callback(FW_VERBOSE_RING_ID, wl_cfgvendor_dbg_ring_send_evt);
 	dhd_os_dbg_register_callback(DRIVER_LOG_RING_ID, wl_cfgvendor_dbg_ring_send_evt);
+	dhd_os_dbg_register_callback(ROAM_STATS_RING_ID, wl_cfgvendor_dbg_ring_send_evt);
 #endif /* DEBUGABILITY */
 #ifdef DHD_LOG_DUMP
 	dhd_os_dbg_register_urgent_notifier(dhd, wl_cfgvendor_dbg_send_file_dump_evt);