[DEBUG] Add debug logs for pipeline prepare failures

Add info-level logs to diagnose test failures:
- aria: Log format/rate/channels before validation
- ipc4: Log pipeline state during RESET transitions
- pipeline: Log component state during prepare

Signed-off-by: Tomasz Leman <tomasz.m.leman@intel.com>

Author: tmleman

src/audio/aria/aria.c

@@ -198,9 +198,21 @@ static int aria_prepare(struct processing_module *mod,
 	aria_set_stream_params(source, mod);
 	aria_set_stream_params(sink, mod);
 
+	/* Log detailed format information before validation */
+	comp_info(dev, "aria_prepare: source fmt=%d rate=%d channels=%d",
+		  audio_stream_get_valid_fmt(&source->stream),
+		  audio_stream_get_rate(&source->stream),
+		  audio_stream_get_channels(&source->stream));
+	comp_info(dev, "aria_prepare: sink fmt=%d rate=%d channels=%d",
+		  audio_stream_get_valid_fmt(&sink->stream),
+		  audio_stream_get_rate(&sink->stream),
+		  audio_stream_get_channels(&sink->stream));
+
 	if (audio_stream_get_valid_fmt(&source->stream) != SOF_IPC_FRAME_S24_4LE ||
 	    audio_stream_get_valid_fmt(&sink->stream) != SOF_IPC_FRAME_S24_4LE) {
-		comp_err(dev, "format is not supported");
+		comp_err(dev, "format is not supported: source_fmt=%d (expected=%d), sink_fmt=%d (expected=%d)",
+			 audio_stream_get_valid_fmt(&source->stream), SOF_IPC_FRAME_S24_4LE,
+			 audio_stream_get_valid_fmt(&sink->stream), SOF_IPC_FRAME_S24_4LE);
 		return -EINVAL;
 	}
 

src/audio/pipeline/pipeline-params.c

@@ -262,8 +262,8 @@ static int pipeline_comp_prepare(struct comp_dev *current,
 	struct pipeline_data *ppl_data = ctx->comp_data;
 	int err;
 
-	pipe_dbg(current->pipeline, "pipeline_comp_prepare(), current->comp.id = 0x%x, dir = %u",
-		 dev_comp_id(current), dir);
+	pipe_info(current->pipeline, "pipeline_comp_prepare(), current->comp.id = 0x%x, dir = %u",
+		  dev_comp_id(current), dir);
 
 	if (!comp_is_single_pipeline(current, ppl_data->start)) {
 		/* ipc4 module is only prepared in its parent pipeline */
@@ -282,9 +282,14 @@ static int pipeline_comp_prepare(struct comp_dev *current,
 			return err;
 	}
 
+	pipe_info(current->pipeline, "calling comp_prepare() for comp 0x%x (state=%d)",
+		  dev_comp_id(current), current->state);
 	err = comp_prepare(current);
-	if (err < 0 || err == PPL_STATUS_PATH_STOP)
+	if (err < 0 || err == PPL_STATUS_PATH_STOP) {
+		pipe_err(current->pipeline, "comp_prepare() failed for comp 0x%x: err=%d",
+			 dev_comp_id(current), err);
 		return err;
+	}
 
 	return pipeline_for_each_comp(current, ctx, dir);
 }

src/ipc/ipc4/handler.c

@@ -160,11 +160,16 @@ static int ipc4_pcm_params(struct ipc_comp_dev *pcm_dev)
 	}
 
 	/* prepare pipeline audio params */
+	tr_info(&ipc_tr, "ipc: attempting to prepare pipe %d comp %d (state=%d)",
+		pcm_dev->cd->pipeline->pipeline_id,
+		pcm_dev->cd->pipeline->comp_id,
+		pcm_dev->cd->pipeline->status);
 	err = pipeline_prepare(pcm_dev->cd->pipeline, pcm_dev->cd);
 	if (err < 0) {
-		ipc_cmd_err(&ipc_tr, "ipc: pipe %d comp %d prepare failed %d",
+		ipc_cmd_err(&ipc_tr, "ipc: pipe %d comp %d prepare failed %d (state=%d)",
 			    pcm_dev->cd->pipeline->pipeline_id,
-			    pcm_dev->cd->pipeline->comp_id, err);
+			    pcm_dev->cd->pipeline->comp_id, err,
+			    pcm_dev->cd->pipeline->status);
 		goto error;
 	}
 
@@ -309,20 +314,29 @@ int ipc4_pipeline_prepare(struct ipc_comp_dev *ppl_icd, uint32_t cmd)
 		}
 		break;
 	case SOF_IPC4_PIPELINE_STATE_RESET:
+		tr_info(&ipc_tr, "pipeline %d: attempting RESET from state %d", ppl_icd->id, status);
 		switch (status) {
 		case COMP_STATE_INIT:
-			tr_dbg(&ipc_tr, "pipeline %d: reset from init", ppl_icd->id);
+			tr_info(&ipc_tr, "pipeline %d: reset from init", ppl_icd->id);
 			ret = ipc4_pipeline_complete(ipc, ppl_icd->id, cmd);
 			break;
 		case COMP_STATE_READY:
+			tr_info(&ipc_tr, "pipeline %d: reset from ready (no action)", ppl_icd->id);
+			/* No action needed */
+			break;
 		case COMP_STATE_ACTIVE:
+			tr_info(&ipc_tr, "pipeline %d: reset from active (no action)", ppl_icd->id);
+			/* No action needed */
+			break;
 		case COMP_STATE_PAUSED:
+			tr_info(&ipc_tr, "pipeline %d: reset from paused (no action)", ppl_icd->id);
 			/* No action needed */
 			break;
 		default:
 			ipc_cmd_err(&ipc_tr,
-				    "pipeline %d: Invalid state for RESET: %d",
-				    ppl_icd->id, status);
+				    "pipeline %d: Invalid state for RESET: %d (valid: %d,%d,%d,%d)",
+				    ppl_icd->id, status, COMP_STATE_INIT, COMP_STATE_READY,
+				    COMP_STATE_ACTIVE, COMP_STATE_PAUSED);
 			return IPC4_INVALID_REQUEST;
 		}