qcacld-3.0: Fix SAP start on DFS freq due to invalid sap fsm state

SAP FSM state is not moved to STARTING from STARTED for DFS freq,
thus CAC complete is not handled in STARTED state and VDEV does
not move to UP state.

Fix this by moving state to STARTING from STARTED for DFS Freq.
Also add vdev id in all FSM logs.

Change-Id: Id8f178d8d7838bdeacdeea50b41dbb19146108c2
CRs-Fixed: 3556248

core/sap/src/sap_api_link_cntl.c

@@ -463,7 +463,8 @@ wlansap_roam_process_ch_change_success(struct mac_context *mac_ctx,
 	 * Channel change is successful. If the new channel is a DFS channel,
 	 * then we will to perform channel availability check for 60 seconds
 	 */
-	sap_nofl_debug("sapdfs: SAP CSA: freq to [%d] state %d",
+	sap_nofl_debug("sap_fsm: vdev %d: sapdfs: SAP CSA: freq %d state %d",
+		       sap_ctx->vdev_id,
 		       mac_ctx->sap.SapDfsInfo.target_chan_freq,
 		       sap_ctx->fsm_state);
 	target_chan_freq = mac_ctx->sap.SapDfsInfo.target_chan_freq;
@@ -471,8 +472,8 @@ wlansap_roam_process_ch_change_success(struct mac_context *mac_ctx,
 	/* If SAP is not in starting or started state don't proceed further */
 	if (sap_ctx->fsm_state == SAP_INIT ||
 	    sap_ctx->fsm_state == SAP_STOPPING) {
-		sap_info("sapdfs: state [%d] not starting SAP after channel change",
-			  sap_ctx->fsm_state);
+		sap_info("sap_fsm: vdev %d: sapdfs: state %d, not starting SAP after channel change",
+			 sap_ctx->vdev_id, sap_ctx->fsm_state);
 		return;
 	}
 
@@ -510,10 +511,11 @@ wlansap_roam_process_ch_change_success(struct mac_context *mac_ctx,
 	if (WLAN_REG_IS_6GHZ_CHAN_FREQ(sap_ctx->chan_freq))
 		is_ch_dfs = false;
 
+	sap_ctx->fsm_state = SAP_STARTING;
+	sap_debug("sap_fsm: vdev %d: => SAP_STARTING", sap_ctx->vdev_id);
 	sap_ctx->chan_freq = target_chan_freq;
 	/* check if currently selected channel is a DFS channel */
 	if (is_ch_dfs && wlan_pre_cac_complete_get(sap_ctx->vdev)) {
-		sap_ctx->fsm_state = SAP_STARTING;
 		sap_ctx->sap_radar_found_status = false;
 		sap_event.event = eSAP_MAC_START_BSS_SUCCESS;
 		sap_event.params = csr_roam_info;
@@ -528,14 +530,12 @@ wlansap_roam_process_ch_change_success(struct mac_context *mac_ctx,
 		    policy_mgr_get_dfs_master_dynamic_enabled(
 					mac_ctx->psoc,
 					sap_ctx->sessionId)) {
-			sap_ctx->fsm_state = SAP_STARTING;
 			/* DFS Channel */
 			sap_event.event = eSAP_DFS_CHANNEL_CAC_START;
 			sap_event.params = csr_roam_info;
 			sap_event.u1 = 0;
 			sap_event.u2 = 0;
 		} else {
-			sap_ctx->fsm_state = SAP_STARTING;
 			sap_ctx->sap_radar_found_status = false;
 			sap_event.event = eSAP_MAC_START_BSS_SUCCESS;
 			sap_event.params = csr_roam_info;
@@ -544,7 +544,6 @@ wlansap_roam_process_ch_change_success(struct mac_context *mac_ctx,
 		}
 	} else {
 		/* non-DFS channel */
-		sap_ctx->fsm_state = SAP_STARTING;
 		sap_ctx->sap_radar_found_status = false;
 		sap_event.event = eSAP_MAC_START_BSS_SUCCESS;
 		sap_event.params = csr_roam_info;
@@ -603,8 +602,6 @@ wlansap_roam_process_dfs_chansw_update(mac_handle_t mac_handle,
 			  sap_ctx->fsm_state);
 		return;
 	}
-
-	sap_debug("sapdfs: from state SAP_STARTED => SAP_STOPPING");
 	sap_ctx->is_chan_change_inprogress = true;
 	/*
 	 * The associated stations have been informed to move to a different

core/sap/src/sap_fsm.c

@@ -2964,8 +2964,8 @@ static void wlansap_pre_cac_end_notify(struct sap_context *sap_context,
 	sap_context->isCacEndNotified = true;
 	sap_context->sap_radar_found_status = false;
 	sap_context->fsm_state = SAP_STARTED;
-
-	sap_warn("pre cac end notify on %d: move to state SAP_STARTED", intf);
+	sap_warn("sap_fsm: vdev %d => SAP_STARTED, pre cac end notify on %d",
+		 sap_context->vdev_id, intf);
 	wlan_pre_cac_handle_cac_end(sap_context->vdev);
 }
 #endif
@@ -3034,11 +3034,9 @@ QDF_STATUS sap_cac_end_notify(mac_handle_t mac_handle,
 			/* Transition from SAP_STARTING to SAP_STARTED
 			 * (both without substates)
 			 */
-			sap_debug("sapdfs: chan_freq[%d] from state %s => %s",
-				  sap_context->chan_freq, "SAP_STARTING",
-				  "SAP_STARTED");
-
 			sap_context->fsm_state = SAP_STARTED;
+			sap_debug("sap_fsm: vdev %d: SAP_STARTING => SAP_STARTED, freq %d",
+				  sap_context->vdev_id, sap_context->chan_freq);
 
 			/*Action code for transition */
 			qdf_status = sap_signal_hdd_event(sap_context, roamInfo,
@@ -3312,8 +3310,8 @@ static QDF_STATUS sap_goto_starting(struct sap_context *sap_ctx,
 	sap_validate_chanmode_and_chwidth(mac_ctx, sap_ctx);
 	/* Channel selected. Now can sap_goto_starting */
 	sap_ctx->fsm_state = SAP_STARTING;
-	sap_debug("from state %s => %s phyMode %d, bw %d",
-		  "SAP_INIT", "SAP_STARTING", sap_ctx->phyMode,
+	sap_debug("sap_fsm: vdev %d: SAP_INIT => SAP_STARTING, phyMode %d bw %d",
+		  sap_ctx->vdev_id, sap_ctx->phyMode,
 		  sap_ctx->ch_params.ch_width);
 	/* Specify the channel */
 	sap_get_cac_dur_dfs_region(sap_ctx,
@@ -3449,16 +3447,19 @@ static QDF_STATUS sap_fsm_state_init(struct sap_context *sap_ctx,
 		 */
 		qdf_status = sap_validate_chan(sap_ctx, false, true);
 		if (QDF_IS_STATUS_ERROR(qdf_status)) {
-			sap_err("channel is not valid!");
+			sap_err("vdev %d: channel is not valid!",
+				sap_ctx->vdev_id);
 			goto exit;
 		}
 
 		qdf_status = sap_goto_starting(sap_ctx, sap_event,
 					       mac_ctx, mac_handle);
 		if (QDF_IS_STATUS_ERROR(qdf_status))
-			sap_err("sap_goto_starting failed");
+			sap_err("vdev %d: sap_goto_starting failed",
+				sap_ctx->vdev_id);
 	} else {
-		sap_err("in state %s, event msg %d", "SAP_INIT", msg);
+		sap_err("sap_fsm: vdev %d: SAP_INIT, invalid event %d",
+			sap_ctx->vdev_id, msg);
 	}
 
 exit:
@@ -3533,10 +3534,6 @@ static QDF_STATUS sap_fsm_handle_start_failure(struct sap_context *sap_ctx,
 	QDF_STATUS qdf_status = QDF_STATUS_E_FAILURE;
 
 	if (msg == eSAP_HDD_STOP_INFRA_BSS) {
-		/* Transition from SAP_STARTING to SAP_STOPPING */
-		sap_debug("SAP start is in progress, state from state %s => %s",
-			  "SAP_STARTING", "SAP_STOPPING");
-
 		/*
 		 * Stop the CAC timer only in following conditions
 		 * single AP: if there is a single AP then stop timer
@@ -3547,18 +3544,19 @@ static QDF_STATUS sap_fsm_handle_start_failure(struct sap_context *sap_ctx,
 			sap_debug("sapdfs: no sessions are valid, stopping timer");
 			sap_stop_dfs_cac_timer(sap_ctx);
 		}
-
+		/* Transition from SAP_STARTING to SAP_STOPPING */
 		sap_ctx->fsm_state = SAP_STOPPING;
+		sap_debug("sap_fsm: vdev %d: SAP_STARTING => SAP_STOPPING, start is in progress",
+			  sap_ctx->vdev_id);
 		qdf_status = sap_goto_stopping(sap_ctx);
 	} else {
 		/*
 		 * Transition from SAP_STARTING to SAP_INIT
 		 * (both without substates)
 		 */
-		sap_debug("from state %s => %s", "SAP_STARTING", "SAP_INIT");
-
-		/* Advance outer statevar */
 		sap_ctx->fsm_state = SAP_INIT;
+		sap_debug("sap_fsm: vdev %d: SAP_STARTING => SAP_INIT",
+			  sap_ctx->vdev_id);
 		qdf_status = sap_signal_hdd_event(sap_ctx, NULL,
 						  eSAP_START_BSS_EVENT,
 						  (void *)
@@ -3771,10 +3769,10 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 		 * Transition from SAP_STARTING to SAP_STARTED
 		 * (both without substates)
 		 */
-		sap_debug("Chan %d %s => %s ch_width %d",
-			  sap_ctx->chan_freq, "SAP_STARTING", "SAP_STARTED",
-			  sap_ctx->ch_params.ch_width);
 		sap_ctx->fsm_state = SAP_STARTED;
+		sap_debug("sap_fsm: vdev %d: SAP_STARTING => SAP_STARTED, freq %d ch_width %d",
+			  sap_ctx->vdev_id, sap_ctx->chan_freq,
+			  sap_ctx->ch_params.ch_width);
 
 		if (sap_ctx->is_chan_change_inprogress) {
 			/* SAP channel change request processing is completed */
@@ -3783,8 +3781,8 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 						(void *)eSAP_STATUS_SUCCESS);
 			sap_ctx->is_chan_change_inprogress = false;
 		} else {
-			sap_debug("notify hostapd about chan freq selection: %d",
-				  sap_ctx->chan_freq);
+			sap_debug("vdev %d notify hostapd about chan freq selection: %d",
+				  sap_ctx->vdev_id, sap_ctx->chan_freq);
 			qdf_status =
 				sap_signal_hdd_event(sap_ctx, roam_info,
 						     eSAP_CHANNEL_CHANGE_EVENT,
@@ -3842,7 +3840,8 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 		if (WLAN_REG_IS_6GHZ_CHAN_FREQ(sap_ctx->chan_freq))
 			is_dfs = false;
 
-		sap_debug("is_dfs %d", is_dfs);
+		sap_debug("vdev %d freq %d, is_dfs %d", sap_ctx->vdev_id,
+			  sap_ctx->chan_freq, is_dfs);
 		if (is_dfs) {
 			sap_dfs_info = &mac_ctx->sap.SapDfsInfo;
 			if (sap_plus_sap_cac_skip(mac_ctx, sap_ctx,
@@ -3854,11 +3853,14 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 			    policy_mgr_get_dfs_master_dynamic_enabled(
 					mac_ctx->psoc,
 					sap_ctx->sessionId)) {
-				sap_debug("start cac timer");
+				sap_ctx->fsm_state = SAP_STARTING;
+				sap_debug("sap_fsm: vdev %d: SAP_STARTED => SAP_STARTING to start cac timer",
+					  sap_ctx->vdev_id);
 				qdf_status = sap_fsm_cac_start(sap_ctx, mac_ctx,
 							       mac_handle);
 			} else {
-				sap_debug("skip cac timer");
+				sap_debug("vdev %d skip cac timer",
+					  sap_ctx->vdev_id);
 				sap_ctx->sap_radar_found_status = false;
 				/*
 				 * If hostapd starts AP on dfs channel,
@@ -3889,8 +3891,8 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 		sap_ctx->chan_freq = mac_ctx->sap.SapDfsInfo.target_chan_freq;
 
 		sap_ctx->fsm_state = SAP_STARTED;
-
-		sap_debug("from state %s => %s", "SAP_STARTING", "SAP_STARTED");
+		sap_debug("sap_fsm: vdev %d: SAP_STARTING => SAP_STARTED",
+			  sap_ctx->vdev_id);
 
 		/* Indicate change in the state to upper layers */
 		qdf_status = sap_signal_hdd_event(sap_ctx, roam_info,
@@ -3903,7 +3905,8 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 		    wlan_util_vdev_mgr_get_cac_timeout_for_vdev(sap_ctx->vdev)) {
 			qdf_status = sap_cac_end_notify(mac_handle, roam_info);
 		} else {
-			sap_debug("cac duration is zero");
+			sap_debug("vdev %d cac duration is zero",
+				  sap_ctx->vdev_id);
 			qdf_status = QDF_STATUS_SUCCESS;
 		}
 	} else if (msg == eSAP_DFS_CHANNEL_CAC_START) {
@@ -3916,8 +3919,8 @@ static QDF_STATUS sap_fsm_state_starting(struct sap_context *sap_ctx,
 		}
 		qdf_status = sap_fsm_cac_start(sap_ctx, mac_ctx, mac_handle);
 	} else {
-		sap_err("in state %s, invalid event msg %d", "SAP_STARTING",
-			 msg);
+		sap_err("sap_fsm: vdev %d: SAP_STARTING, invalid event %d",
+			sap_ctx->vdev_id, msg);
 	}
 
 	return qdf_status;
@@ -3945,8 +3948,9 @@ static QDF_STATUS sap_fsm_state_started(struct sap_context *sap_ctx,
 		 * Transition from SAP_STARTED to SAP_STOPPING
 		 * (both without substates)
 		 */
-		sap_debug("from state %s => %s", "SAP_STARTED", "SAP_STOPPING");
 		sap_ctx->fsm_state = SAP_STOPPING;
+		sap_debug("sap_fsm: vdev %d: SAP_STARTED => SAP_STOPPING",
+			  sap_ctx->vdev_id);
 		qdf_status = sap_goto_stopping(sap_ctx);
 	} else if (eSAP_DFS_CHNL_SWITCH_ANNOUNCEMENT_START == msg) {
 		uint8_t intf;
@@ -3996,8 +4000,8 @@ static QDF_STATUS sap_fsm_state_started(struct sap_context *sap_ctx,
 			}
 		}
 	} else {
-		sap_err("in state %s, invalid event msg %d", "SAP_STARTED",
-			 msg);
+		sap_err("sap_fsm: vdev %d: SAP_STARTED, invalid event %d",
+			sap_ctx->vdev_id, msg);
 	}
 
 	return qdf_status;
@@ -4027,8 +4031,9 @@ sap_fsm_state_stopping(struct sap_context *sap_ctx,
 		 * Transition from SAP_STOPPING to SAP_INIT
 		 * (both without substates)
 		 */
-		sap_debug("from state %s => %s", "SAP_STOPPING", "SAP_INIT");
 		sap_ctx->fsm_state = SAP_INIT;
+		sap_debug("sap_fsm: vdev %d: SAP_STOPPING => SAP_INIT",
+			  sap_ctx->vdev_id);
 
 		/* Close the SME session */
 		qdf_status = sap_signal_hdd_event(sap_ctx, NULL,
@@ -4039,11 +4044,12 @@ sap_fsm_state_stopping(struct sap_context *sap_ctx,
 		 * In case the SAP is already in stopping case and
 		 * we get a STOP request, return success.
 		 */
-		sap_debug("SAP already in Stopping state");
+		sap_debug("vdev %d SAP already in Stopping state",
+			  sap_ctx->vdev_id);
 		qdf_status = QDF_STATUS_SUCCESS;
 	} else {
-		sap_err("in state %s, invalid event msg %d", "SAP_STOPPING",
-			 msg);
+		sap_err("sap_fsm: vdev %d: SAP_STOPPING, invalid event %d",
+			sap_ctx->vdev_id, msg);
 	}
 
 	return qdf_status;
@@ -4078,7 +4084,8 @@ QDF_STATUS sap_fsm(struct sap_context *sap_ctx, struct sap_sm_event *sap_event)
 	}
 	mac_handle = MAC_HANDLE(mac_ctx);
 
-	sap_debug("state=%d handle event=%d", state_var, msg);
+	sap_debug("vdev %d: state %d event %d", sap_ctx->vdev_id, state_var,
+		  msg);
 
 	switch (state_var) {
 	case SAP_INIT:

core/sap/src/sap_internal.h

@@ -131,9 +131,10 @@ struct sap_context {
 #ifdef DCS_INTERFERENCE_DETECTION
 	qdf_freq_t dcs_ch_freq;
 #endif
-
-	/* Include the SME(CSR) sessionId here */
-	uint8_t sessionId;
+	union {
+		uint8_t sessionId;
+		uint8_t vdev_id;
+	};
 	uint8_t sap_radar_found_status;
 
 	/* vdev object corresponding to sessionId */

core/sap/src/sap_module.c

@@ -810,6 +810,7 @@ QDF_STATUS wlansap_start_bss(struct sap_context *sap_ctx,
 	}
 
 	sap_ctx->fsm_state = SAP_INIT;
+	sap_debug("sap_fsm: vdev %d:  => SAP_INIT", sap_ctx->vdev_id);
 
 	qdf_status = wlan_set_vdev_crypto_prarams_from_ie(
 			sap_ctx->vdev,