diff --git a/src/ipc/apl-ipc.c b/src/ipc/apl-ipc.c index 79eb8da5530a..3d28616b504b 100644 --- a/src/ipc/apl-ipc.c +++ b/src/ipc/apl-ipc.c @@ -59,18 +59,21 @@ static void irq_handler(void *arg) { uint32_t dipct; uint32_t dipcie; + uint32_t dipcctl; uint32_t msg = 0; dipct = ipc_read(IPC_DIPCT); dipcie = ipc_read(IPC_DIPCIE); + dipcctl = ipc_read(IPC_DIPCCTL); - tracev_ipc("ipc: irq dipct 0x%x dipcie 0x%x", dipct, dipcie); + tracev_ipc("ipc: irq dipct 0x%x dipcie 0x%x dipcctl 0x%x", dipct, + dipcie, dipcctl); /* new message from host */ - if (dipct & IPC_DIPCT_BUSY) { + if (dipct & IPC_DIPCT_BUSY && dipcctl & IPC_DIPCCTL_IPCTBIE) { /* mask Busy interrupt */ - ipc_write(IPC_DIPCCTL, ipc_read(IPC_DIPCCTL) & ~IPC_DIPCCTL_IPCTBIE); + ipc_write(IPC_DIPCCTL, dipcctl & ~IPC_DIPCCTL_IPCTBIE); msg = dipct & IPC_DIPCT_MSG_MASK; diff --git a/src/ipc/byt-ipc.c b/src/ipc/byt-ipc.c index 764c76a8d01d..b1da00312035 100644 --- a/src/ipc/byt-ipc.c +++ b/src/ipc/byt-ipc.c @@ -58,13 +58,13 @@ static void do_notify(void) uint32_t flags; struct ipc_msg *msg; - tracev_ipc("Not"); - spin_lock_irq(&_ipc->lock, flags); msg = _ipc->shared_ctx->dsp_msg; if (msg == NULL) goto out; + trace_ipc("ipc: not rx -> 0x%x", msg->header); + /* copy the data returned from DSP */ if (msg->rx_size && msg->rx_size < SOF_IPC_MSG_MAX_SIZE) mailbox_dspbox_read(msg->rx_data, 0, msg->rx_size); @@ -88,12 +88,13 @@ static void do_notify(void) static void irq_handler(void *arg) { uint32_t isr; - - tracev_ipc("IRQ"); + uint32_t msg = 0; /* Interrupt arrived, check src */ isr = shim_read(SHIM_ISRD); + tracev_ipc("ipc: irq isr 0x%x", isr); + if (isr & SHIM_ISRD_DONE) { /* Mask Done interrupt before return */ @@ -108,12 +109,17 @@ static void irq_handler(void *arg) shim_write(SHIM_IMRD, shim_read(SHIM_IMRD) | SHIM_IMRD_BUSY); interrupt_clear(PLATFORM_IPC_INTERRUPT); + msg = shim_read(SHIM_IPCXL); + /* TODO: place message in Q and process later */ /* It's not Q ATM, may overwrite */ if (_ipc->host_pending) { - trace_ipc_error("Pen"); + trace_ipc_error("ipc: dropping msg 0x%x", msg); + trace_ipc_error(" isr 0x%x imrd 0x%x ipcxh 0x%x", + isr, shim_read(SHIM_IMRD), + shim_read(SHIM_IPCXH)); } else { - _ipc->host_msg = shim_read(SHIM_IPCXL); + _ipc->host_msg = msg; _ipc->host_pending = 1; ipc_schedule_process(_ipc); } @@ -127,7 +133,7 @@ void ipc_platform_do_cmd(struct ipc *ipc) uint32_t ipcxh; int32_t err; - tracev_ipc("Cmd"); + trace_ipc("ipc: msg rx -> 0x%x", ipc->host_msg); /* perform command and return any error */ err = ipc_cmd(); @@ -159,12 +165,9 @@ void ipc_platform_do_cmd(struct ipc *ipc) /* are we about to enter D3 ? */ if (iipc->pm_prepare_D3) { while (1) { - trace_ipc("pme"); wait_for_interrupt(0); } } - - tracev_ipc("CmD"); } void ipc_platform_send_msg(struct ipc *ipc) @@ -190,7 +193,7 @@ void ipc_platform_send_msg(struct ipc *ipc) mailbox_dspbox_write(0, msg->tx_data, msg->tx_size); list_item_del(&msg->list); ipc->shared_ctx->dsp_msg = msg; - tracev_ipc("Msg"); + tracev_ipc("ipc: msg tx -> 0x%x", msg->header); /* now interrupt host to tell it we have message sent */ shim_write(SHIM_IPCDL, msg->header); diff --git a/src/ipc/cnl-ipc.c b/src/ipc/cnl-ipc.c index 881340a7d3ed..9d5165a6064a 100644 --- a/src/ipc/cnl-ipc.c +++ b/src/ipc/cnl-ipc.c @@ -50,14 +50,9 @@ #include #include #include -//<<<<<<< HEAD #include - -//======= -//#include -//#include #include -//>>>>>>> Added SRAM power gating on D3 entry for cAVS 1.8 (i.e. Cannonlake). + extern struct ipc *_ipc; /* test code to check working IRQ */ @@ -65,26 +60,31 @@ static void irq_handler(void *arg) { uint32_t dipctdr; uint32_t dipcida; + uint32_t dipcctl; uint32_t msg = 0; - tracev_ipc("IRQ"); - dipctdr = ipc_read(IPC_DIPCTDR); dipcida = ipc_read(IPC_DIPCIDA); + dipcctl = ipc_read(IPC_DIPCCTL); + + tracev_ipc("ipc: irq dipct 0x%x dipcie 0x%x dipcctl 0x%x", dipct, + dipcie, dipcctl); /* new message from host */ - if (dipctdr & IPC_DIPCTDR_BUSY) { - tracev_ipc("Nms"); + if (dipctdr & IPC_DIPCTDR_BUSY && dipcctl & IPC_DIPCCTL_IPCTBIE) { /* mask Busy interrupt */ - ipc_write(IPC_DIPCCTL, ipc_read(IPC_DIPCCTL) & ~IPC_DIPCCTL_IPCTBIE); + ipc_write(IPC_DIPCCTL, dipcctl & ~IPC_DIPCCTL_IPCTBIE); msg = dipctdr & IPC_DIPCTDR_MSG_MASK; /* TODO: place message in Q and process later */ /* It's not Q ATM, may overwrite */ if (_ipc->host_pending) { - trace_ipc_error("Pen"); + trace_ipc_error("ipc: dropping msg 0x%x", msg); + trace_ipc_error(" dipctdr 0x%x dipcida 0x%x dipcctl 0x%x", + dipctdr, dipcida, + ipc_read(IPC_DIPCCTL)); } else { _ipc->host_msg = msg; _ipc->host_pending = 1; @@ -94,7 +94,7 @@ static void irq_handler(void *arg) /* reply message(done) from host */ if (dipcida & IPC_DIPCIDA_DONE) { - tracev_ipc("Rpy"); + /* mask Done interrupt */ ipc_write(IPC_DIPCCTL, ipc_read(IPC_DIPCCTL) & ~IPC_DIPCCTL_IPCIDIE); @@ -113,7 +113,7 @@ void ipc_platform_do_cmd(struct ipc *ipc) struct sof_ipc_reply reply; int32_t err; - trace_ipc("Cmd"); + trace_ipc("ipc: msg rx -> 0x%x", ipc->host_msg); /* perform command and return any error */ err = ipc_cmd(); @@ -154,8 +154,6 @@ void ipc_platform_do_cmd(struct ipc *ipc) wait_for_interrupt(0); #endif } - - tracev_ipc("CmD"); } void ipc_platform_send_msg(struct ipc *ipc) @@ -181,7 +179,7 @@ void ipc_platform_send_msg(struct ipc *ipc) mailbox_dspbox_write(0, msg->tx_data, msg->tx_size); list_item_del(&msg->list); ipc->shared_ctx->dsp_msg = msg; - tracev_ipc("Msg"); + tracev_ipc("ipc: msg tx -> 0x%x", msg->header); /* now interrupt host to tell it we have message sent */ ipc_write(IPC_DIPCIDD, 0); diff --git a/src/ipc/handler.c b/src/ipc/handler.c index a830e0733fd3..8cb9a186222b 100644 --- a/src/ipc/handler.c +++ b/src/ipc/handler.c @@ -85,8 +85,7 @@ static inline struct sof_ipc_hdr *mailbox_validate(void) /* validate component header */ if (hdr->size > SOF_IPC_MSG_MAX_SIZE) { - trace_ipc_error("mailbox_validate() error: Invalid size of " - "component header."); + trace_ipc_error("ipc: msg too big at 0x%x", hdr->size); return NULL; } @@ -184,28 +183,25 @@ static int ipc_stream_pcm_params(uint32_t stream) struct comp_dev *cd; int err, posn_offset; - trace_ipc("ipc_stream_pcm_params()"); + trace_ipc("ipc: comp %d -> params", pcm_params->comp_id); /* sanity check size */ if (IPC_INVALID_SIZE(pcm_params)) { - trace_ipc_error("ipc_stream_pcm_params() error: Invalid size of" - "IPC pcm params."); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*pcm_params), pcm_params->hdr.size); return -EINVAL; } /* get the pcm_dev */ pcm_dev = ipc_get_comp(_ipc, pcm_params->comp_id); if (pcm_dev == NULL) { - trace_ipc_error("ipc_stream_pcm_params() error: Requested " - "pcm_dev ID = %u not found.", - pcm_params->comp_id); + trace_ipc_error("ipc: comp %d not found", pcm_params->comp_id); return -ENODEV; } /* sanity check comp */ if (pcm_dev->cd->pipeline == NULL) { - trace_ipc_error("ipc_stream_pcm_params() error: Requested " - "pcm_dev ID = %u has no pipeline associated.", + trace_ipc_error("ipc: comp %d pipeline not found", pcm_params->comp_id); return -EINVAL; } @@ -228,9 +224,8 @@ static int ipc_stream_pcm_params(uint32_t stream) err = ipc_get_page_descriptors(iipc->dmac, iipc->page_table, &pcm_params->params.buffer); if (err < 0) { - trace_ipc_error("ipc_stream_pcm_params() error: " - "ipc_get_page_descriptors() failed with err = " - "%d", err); + trace_ipc_error("ipc: comp %d get descriptors failed %d", + pcm_params->comp_id, err); goto error; } @@ -242,16 +237,15 @@ static int ipc_stream_pcm_params(uint32_t stream) &pcm_params->params.buffer, &elem_array, host->direction); if (err < 0) { - trace_ipc_error("ipc_stream_pcm_params() error: " - "ipc_parse_page_descriptors() failed with err =" - " %d", err); + trace_ipc_error("ipc: comp %d parse descriptors failed %d", + pcm_params->comp_id, err); goto error; } err = comp_host_buffer(cd, &elem_array, ring_size); if (err < 0) { - trace_ipc_error("ipc_stream_pcm_params() error: " - "comp_host_buffer() failed with err = %d", err); + trace_ipc_error("ipc: comp %d host buffer failed %d", + pcm_params->comp_id, err); goto error; } @@ -261,23 +255,26 @@ static int ipc_stream_pcm_params(uint32_t stream) /* configure pipeline audio params */ err = pipeline_params(pcm_dev->cd->pipeline, pcm_dev->cd, pcm_params); if (err < 0) { - trace_ipc_error("ipc_stream_pcm_params() error: " - "pipeline_params() failed with err = %d", err); + trace_ipc_error("ipc: pipe %d comp %d params failed %d", + pcm_dev->cd->pipeline->ipc_pipe.pipeline_id, + pcm_params->comp_id, err); goto error; } /* prepare pipeline audio params */ err = pipeline_prepare(pcm_dev->cd->pipeline, pcm_dev->cd); if (err < 0) { - trace_ipc_error("ipc_stream_pcm_params() error: " - "pipeline_prepare() failed with err = %d", err); + trace_ipc_error("ipc: pipe %d comp %d prepare failed %d", + pcm_dev->cd->pipeline->ipc_pipe.pipeline_id, + pcm_params->comp_id, err); goto error; } posn_offset = ipc_get_posn_offset(_ipc, pcm_dev->cd->pipeline); if (posn_offset < 0) { - trace_ipc_error("ipc_stream_pcm_params() error: " - "ipc_get_posn_offset() failed."); + trace_ipc_error("ipc: pipe %d comp %d posn offset failed %d", + pcm_dev->cd->pipeline->ipc_pipe.pipeline_id, + pcm_params->comp_id, err); goto error; } /* write component values to the outbox */ @@ -296,8 +293,9 @@ static int ipc_stream_pcm_params(uint32_t stream) err = pipeline_reset(pcm_dev->cd->pipeline, pcm_dev->cd); if (err < 0) - trace_ipc_error("ipc_stream_pcm_params() error: " - "pipeline_reset() failed with err = %d", err); + trace_ipc_error("ipc: pipe %d comp %d reset failed %d", + pcm_dev->cd->pipeline->ipc_pipe.pipeline_id, + pcm_params->comp_id, err); return -EINVAL; } @@ -307,27 +305,25 @@ static int ipc_stream_pcm_free(uint32_t header) struct sof_ipc_stream *free_req = _ipc->comp_data; struct ipc_comp_dev *pcm_dev; - trace_ipc("ipc_stream_pcm_free()"); + trace_ipc("ipc: comp %d -> free", free_req->comp_id); /* sanity check size */ if (IPC_INVALID_SIZE(free_req)) { - trace_ipc_error("ipc_stream_pcm_free() error: Invalid size of " - "IPC."); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*free_req), free_req->hdr.size); return -EINVAL; } /* get the pcm_dev */ pcm_dev = ipc_get_comp(_ipc, free_req->comp_id); if (pcm_dev == NULL) { - trace_ipc_error("ipc_stream_pcm_free() error: Requested pcm_dev" - " ID = %u not found.", free_req->comp_id); + trace_ipc_error("ipc: comp %d not found", free_req->comp_id); return -ENODEV; } /* sanity check comp */ if (pcm_dev->cd->pipeline == NULL) { - trace_ipc_error("ipc_stream_pcm_free() error: Requested pcm_dev" - " ID = %u has no pipeline associated.", + trace_ipc_error("ipc: comp %d pipeline not found", free_req->comp_id); return -EINVAL; } @@ -343,22 +339,21 @@ static int ipc_stream_position(uint32_t header) struct sof_ipc_stream_posn posn; struct ipc_comp_dev *pcm_dev; - trace_ipc("ipc_stream_position()"); + trace_ipc("ipc: comp %d -> position", stream->comp_id); memset(&posn, 0, sizeof(posn)); /* sanity check size */ if (IPC_INVALID_SIZE(stream)) { - trace_ipc_error("ipc_stream_position() error: Invalid size of " - "IPC"); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*stream), stream->hdr.size); return -EINVAL; } /* get the pcm_dev */ pcm_dev = ipc_get_comp(_ipc, stream->comp_id); if (pcm_dev == NULL) { - trace_ipc_error("ipc_stream_position() error: Requested pcm_dev" - " ID = %u not found.", stream->comp_id); + trace_ipc_error("ipc: comp %d not found", stream->comp_id); return -ENODEV; } @@ -382,7 +377,6 @@ static int ipc_stream_position(uint32_t header) int ipc_stream_send_position(struct comp_dev *cdev, struct sof_ipc_stream_posn *posn) { - tracev_ipc("Pos"); posn->rhdr.hdr.cmd = SOF_IPC_GLB_STREAM_MSG | SOF_IPC_STREAM_POSITION | cdev->comp.id; posn->rhdr.hdr.size = sizeof(*posn); @@ -414,20 +408,19 @@ static int ipc_stream_trigger(uint32_t header) uint32_t ipc_cmd = (header & SOF_CMD_TYPE_MASK) >> SOF_CMD_TYPE_SHIFT; int ret; - trace_ipc("ipc_stream_trigger()"); + trace_ipc("ipc: comp %d -> trigger cmd %d", stream->comp_id, ipc_cmd); /* sanity check size */ if (IPC_INVALID_SIZE(stream)) { - trace_ipc_error("ipc_stream_trigger() error: Invalid size of " - "IPC"); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*stream), stream->hdr.size); return -EINVAL; } /* get the pcm_dev */ pcm_dev = ipc_get_comp(_ipc, stream->comp_id); if (pcm_dev == NULL) { - trace_ipc_error("ipc_stream_trigger() error: Requested pcm_dev " - " ID = %u not found.", stream->comp_id); + trace_ipc_error("ipc: comp %d not found", stream->comp_id); return -ENODEV; } @@ -452,9 +445,8 @@ static int ipc_stream_trigger(uint32_t header) /* trigger the component */ ret = pipeline_trigger(pcm_dev->cd->pipeline, pcm_dev->cd, cmd); if (ret < 0) { - trace_ipc_error("ipc_stream_trigger() error: pipeline_trigger()" - " failed with ret = %d, ipc_cmd = %u", ret, - ipc_cmd); + trace_ipc_error("ipc: comp %d trigger %d failed %d", + stream->comp_id, ipc_cmd, ret); } return ret; @@ -479,8 +471,7 @@ static int ipc_glb_stream_message(uint32_t header) case iCS(SOF_IPC_STREAM_POSITION): return ipc_stream_position(header); default: - trace_ipc_error("ipc_glb_stream_message() error: Invalid " - "command, cmd = %u", cmd); + trace_ipc_error("ipc: unknown stream cmd %u", cmd); return -EINVAL; } } @@ -495,13 +486,13 @@ static int ipc_dai_config(uint32_t header) struct dai *dai; int ret; - trace_ipc("ipc_dai_config()"); + trace_ipc("ipc: dai %d,%d -> config ", config->type, + config->dai_index); /* get DAI */ dai = dai_get(config->type, config->dai_index, 0 /* existing only */); if (dai == NULL) { - trace_ipc_error("ipc_dai_config() error: Requested DAI not " - "found, type = %u, dai_index = %u", + trace_ipc_error("ipc: dai %d,%d not found", config->type, config->dai_index); return -ENODEV; } @@ -510,8 +501,8 @@ static int ipc_dai_config(uint32_t header) ret = dai_set_config(dai, config); dai_put(dai); /* free ref immediately */ if (ret < 0) { - trace_ipc_error("ipc_dai_config() error: dai_set_config() " - "failed with ret = %d", ret); + trace_ipc_error("ipc: dai %d,%d config failed %d", + config->type, config->dai_index, ret); return ret; } @@ -529,8 +520,7 @@ static int ipc_glb_dai_message(uint32_t header) case iCS(SOF_IPC_DAI_LOOPBACK): //return ipc_comp_set_value(header, COMP_CMD_LOOPBACK); default: - trace_ipc_error("ipc_glb_dai_message() error: Invalid command " - "header = %u", header); + trace_ipc_error("ipc: unknown DAI cmd %u", cmd); return -EINVAL; } } @@ -543,7 +533,7 @@ static int ipc_pm_context_size(uint32_t header) { struct sof_ipc_pm_ctx pm_ctx; - trace_ipc("ipc_pm_context_size()"); + trace_ipc("ipc: pm -> size"); bzero(&pm_ctx, sizeof(pm_ctx)); @@ -559,7 +549,7 @@ static int ipc_pm_context_save(uint32_t header) struct sof_ipc_pm_ctx *pm_ctx = _ipc->comp_data; struct ipc_data *iipc = ipc_get_drvdata(_ipc); - trace_ipc("ipc_pm_context_save()"); + trace_ipc("ipc: pm -> save"); /* TODO: check we are inactive - all streams are suspended */ @@ -595,7 +585,7 @@ static int ipc_pm_context_restore(uint32_t header) { struct sof_ipc_pm_ctx *pm_ctx = _ipc->comp_data; - trace_ipc("ipc_pm_context_restore()"); + trace_ipc("ipc: pm -> restore"); /* restore context placeholder */ mailbox_hostbox_write(0, pm_ctx, sizeof(*pm_ctx)); @@ -608,7 +598,8 @@ static int ipc_pm_core_enable(uint32_t header) struct sof_ipc_pm_core_config *pm_core_config = _ipc->comp_data; int i = 0; - trace_ipc("ipc_pm_core_enable()"); + trace_ipc("ipc: pm core mask 0x%x -> enable", + pm_core_config->enable_mask); for (i = 0; i < PLATFORM_CORE_COUNT; i++) { if (i != PLATFORM_MASTER_CORE_ID) { @@ -639,6 +630,7 @@ static int ipc_glb_pm_message(uint32_t header) case iCS(SOF_IPC_PM_CLK_GET): case iCS(SOF_IPC_PM_CLK_REQ): default: + trace_ipc_error("ipc: unknown pm cmd %u", cmd); return -EINVAL; } } @@ -656,12 +648,11 @@ static int ipc_dma_trace_config(uint32_t header) struct sof_ipc_dma_trace_params *params = _ipc->comp_data; int err; - trace_ipc("ipc_dma_trace_config()"); /* sanity check size */ if (IPC_INVALID_SIZE(params)) { - trace_ipc_error("ipc_dma_trace_config() error: Invalid size of " - "IPC"); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*params), params->hdr.size); return -EINVAL; } @@ -673,30 +664,24 @@ static int ipc_dma_trace_config(uint32_t header) err = ipc_get_page_descriptors(iipc->dmac, iipc->page_table, ¶ms->buffer); if (err < 0) { - trace_ipc_error("ipc_dma_trace_config() error: " - "ipc_get_page_descriptors() failed with err = " - "%u", err); + trace_ipc_error("ipc: trace failed to get descriptors %u", err); goto error; } - trace_ipc("ipc_dma_trace_config() Page descriptors acquired."); - /* Parse host tables */ ring_size = params->buffer.size; err = ipc_parse_page_descriptors(iipc->page_table, ¶ms->buffer, &elem_array, SOF_IPC_STREAM_CAPTURE); if (err < 0) { - trace_ipc_error("ipc_dma_trace_config() error: " - "ipc_parse_page_descriptors() failed with err =" - " %d", err); + trace_ipc_error("ipc: trace failed to parse descriptors %d", + err); goto error; } err = dma_trace_host_buffer(_ipc->dmat, &elem_array, ring_size); if (err < 0) { - trace_ipc_error("ipc_dma_trace_config() error: " - "dma_trace_host_buffer() failed with err = %d", + trace_ipc_error("ipc: trace failed to set host buffers %d", err); goto error; } @@ -708,12 +693,10 @@ static int ipc_dma_trace_config(uint32_t header) /* host buffer size for DMA trace */ _ipc->dmat->host_size = params->buffer.size; #endif - trace_ipc("ipc_dma_trace_config() DMA trace configured."); err = dma_trace_enable(_ipc->dmat); if (err < 0) { - trace_ipc_error("ipc_dma_trace_config() error: " - "dma_trace_enable() failed with err = %d", err); + trace_ipc_error("ipc: failed to enable trace %d", err); goto error; } @@ -746,14 +729,13 @@ static int ipc_glb_debug_message(uint32_t header) { uint32_t cmd = (header & SOF_CMD_TYPE_MASK) >> SOF_CMD_TYPE_SHIFT; - trace_ipc("ipc_glb_debug_message()"); + trace_ipc("ipc: debug cmd 0x%x", cmd); switch (cmd) { case iCS(SOF_IPC_TRACE_DMA_PARAMS): return ipc_dma_trace_config(header); default: - trace_ipc_error("ipc_glb_debug_message() error: Unknown command" - ", header = %u", header); + trace_ipc_error("ipc: unknown debug cmd %u", cmd); return -EINVAL; } } @@ -771,6 +753,7 @@ static int ipc_comp_cmd(struct comp_dev *dev, int cmd, /* pipeline running on other core */ if (dev->pipeline->status == COMP_STATE_ACTIVE && cpu_get_id() != core) { + /* check if requested core is enabled */ if (!cpu_is_core_enabled(core)) return -EINVAL; @@ -794,21 +777,20 @@ static int ipc_comp_value(uint32_t header, uint32_t cmd) struct sof_ipc_ctrl_data *data = _ipc->comp_data; int ret; - trace_ipc("ipc_comp_value()"); + trace_ipc("ipc: comp %d -> cmd %d", data->comp_id, data->cmd); /* get the component */ comp_dev = ipc_get_comp(_ipc, data->comp_id); if (comp_dev == NULL){ - trace_ipc_error("ipc_comp_value() error: Requested comp_dev ID " - "= %u not found.", data->comp_id); + trace_ipc_error("ipc: comp %d not found", data->comp_id); return -ENODEV; } /* get component values */ ret = ipc_comp_cmd(comp_dev->cd, cmd, data); if (ret < 0) { - trace_ipc_error("ipc_comp_value() error: ipc_comp_cmd() failed," - " cmd = %u", cmd); + trace_ipc_error("ipc: comp %d cmd %u failed 5d", data->comp_id, + data->cmd, ret); return ret; } @@ -831,8 +813,7 @@ static int ipc_glb_comp_message(uint32_t header) case iCS(SOF_IPC_COMP_GET_DATA): return ipc_comp_value(header, COMP_CMD_GET_DATA); default: - trace_ipc_error("ipc_glb_comp_message() error: Unknown command," - "header = %u", header); + trace_ipc_error("ipc: unknown comp cmd %u", cmd); return -EINVAL; } } @@ -843,13 +824,14 @@ static int ipc_glb_tplg_comp_new(uint32_t header) struct sof_ipc_comp_reply reply; int ret; - trace_ipc("ipc_glb_tplg_comp_new()"); + trace_ipc("ipc: pipe %d comp %d -> new (type %d)", comp->pipeline_id, + comp->id, comp->type); /* register component */ ret = ipc_comp_new(_ipc, comp); if (ret < 0) { - trace_ipc_error("ipc_glb_tplg_comp_new() error: ipc_comp_new() " - "failed."); + trace_ipc_error("ipc: pipe %d comp %d creation failed %d", + comp->pipeline_id, comp->id, ret); return ret; } @@ -868,12 +850,15 @@ static int ipc_glb_tplg_buffer_new(uint32_t header) struct sof_ipc_comp_reply reply; int ret; - trace_ipc("ipc_glb_tplg_buffer_new()"); + trace_ipc("ipc: pipe %d buffer %d -> new (0x%x bytes)", + ipc_buffer->comp.pipeline_id, ipc_buffer->comp.id, + ipc_buffer->size); ret = ipc_buffer_new(_ipc, ipc_buffer); if (ret < 0) { - trace_ipc_error("ipc_glb_tplg_buffer_new() error: " - "ipc_buffer_new() failed."); + trace_ipc_error("ipc: pipe %d buffer %d creation failed %d", + ipc_buffer->comp.pipeline_id, + ipc_buffer->comp.id, ret); return ret; } @@ -892,19 +877,19 @@ static int ipc_glb_tplg_pipe_new(uint32_t header) struct sof_ipc_comp_reply reply; int ret; - trace_ipc("ipc_glb_tplg_pipe_new()"); + trace_ipc("ipc: pipe %d -> new", ipc_pipeline->pipeline_id); /* sanity check size */ if (IPC_INVALID_SIZE(ipc_pipeline)) { - trace_ipc_error("ipc_glb_tplg_pipe_new() error: Invalid size of" - " IPC"); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*ipc_pipeline), ipc_pipeline->hdr.size); return -EINVAL; } ret = ipc_pipeline_new(_ipc, ipc_pipeline); if (ret < 0) { - trace_ipc_error("ipc_glb_tplg_pipe_new() error: " - "ipc_pipeline_new() failed."); + trace_ipc_error("ipc: pipe %d creation failed %d", + ipc_pipeline->pipeline_id, ret); return ret; } @@ -921,7 +906,7 @@ static int ipc_glb_tplg_pipe_complete(uint32_t header) { struct sof_ipc_pipe_ready *ipc_pipeline = _ipc->comp_data; - trace_ipc("ipc_glb_tplg_pipe_complete()"); + trace_ipc("ipc: pipe %d -> complete", ipc_pipeline->comp_id); return ipc_pipeline_complete(_ipc, ipc_pipeline->comp_id); } @@ -930,12 +915,13 @@ static int ipc_glb_tplg_comp_connect(uint32_t header) { struct sof_ipc_pipe_comp_connect *connect = _ipc->comp_data; - trace_ipc("ipc_glb_tplg_comp_connect()"); + trace_ipc("ipc: comp sink %d, source %d -> connect", + connect->sink_id, connect->source_id); /* sanity check size */ if (IPC_INVALID_SIZE(connect)) { - trace_ipc_error("ipc_glb_tplg_comp_connect() error: Invalid " - "size of IPC"); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*connect), connect->hdr.size); return -EINVAL; } @@ -948,12 +934,12 @@ static int ipc_glb_tplg_free(uint32_t header, struct sof_ipc_free *ipc_free = _ipc->comp_data; int ret; - trace_ipc("ipc_glb_tplg_free()"); + trace_ipc("ipc: comp %d -> free", ipc_free->id); /* sanity check size */ if (IPC_INVALID_SIZE(ipc_free)) { - trace_ipc_error("ipc_glb_tplg_free() error: Invalid size of " - "IPC"); + trace_ipc_error("ipc:_invalid IPC size 0x%x got 0x%x", + sizeof(*ipc_free), ipc_free->hdr.size); return -EINVAL; } @@ -961,8 +947,8 @@ static int ipc_glb_tplg_free(uint32_t header, ret = free_func(_ipc, ipc_free->id); if (ret < 0) { - trace_ipc_error("ipc_glb_tplg_free() error: free_func() failed " - "with ret = %d", ret); + trace_ipc_error("ipc: comp %d free failed %d", + ipc_free->id, ret); } return ret; @@ -990,8 +976,7 @@ static int ipc_glb_tplg_message(uint32_t header) case iCS(SOF_IPC_TPLG_BUFFER_FREE): return ipc_glb_tplg_free(header, ipc_buffer_free); default: - trace_ipc_error("ipc_glb_tplg_message() error: Unknown command," - "header = %u", header); + trace_ipc_error("ipc: unknown tplg header %u", header); return -EINVAL; } } @@ -1007,7 +992,7 @@ int ipc_cmd(void) hdr = mailbox_validate(); if (hdr == NULL) { - trace_ipc_error("ipc_cmd() error: Missing IPC header."); + trace_ipc_error("ipc: invalid IPC header."); return -EINVAL; } @@ -1031,8 +1016,7 @@ int ipc_cmd(void) case iGS(SOF_IPC_GLB_TRACE_MSG): return ipc_glb_debug_message(hdr->cmd); default: - trace_ipc_error("ipc_cmd() error: Unknown command, type = %u", - type); + trace_ipc_error("ipc: unknown command type %u", type); return -EINVAL; } } @@ -1152,7 +1136,7 @@ int ipc_queue_host_message(struct ipc *ipc, uint32_t header, void *tx_data, msg = msg_get_empty(ipc); if (msg == NULL) { - trace_ipc_error("ipc_queue_host_message() error: header 0x08x " + trace_ipc_error("ipc: msg hdr for 0x08x not found " "replace %d", header, replace); ret = -EBUSY; goto out; diff --git a/src/ipc/hsw-ipc.c b/src/ipc/hsw-ipc.c index 344daa19a5aa..8a48d854d5fd 100644 --- a/src/ipc/hsw-ipc.c +++ b/src/ipc/hsw-ipc.c @@ -58,13 +58,13 @@ static void do_notify(void) uint32_t flags; struct ipc_msg *msg; - tracev_ipc("Not"); - spin_lock_irq(&_ipc->lock, flags); msg = _ipc->shared_ctx->dsp_msg; if (msg == NULL) goto out; + trace_ipc("ipc: not rx -> 0x%x", msg->header); + /* copy the data returned from DSP */ if (msg->rx_size && msg->rx_size < SOF_IPC_MSG_MAX_SIZE) mailbox_dspbox_read(msg->rx_data, 0, msg->rx_size); @@ -88,12 +88,13 @@ static void do_notify(void) static void irq_handler(void *arg) { uint32_t isr; - - tracev_ipc("IRQ"); + uint32_t msg = 0; /* Interrupt arrived, check src */ isr = shim_read(SHIM_ISRD); + tracev_ipc("ipc: irq isr 0x%x", isr); + if (isr & SHIM_ISRD_DONE) { /* Mask Done interrupt before return */ @@ -108,12 +109,17 @@ static void irq_handler(void *arg) shim_write(SHIM_IMRD, shim_read(SHIM_IMRD) | SHIM_IMRD_BUSY); interrupt_clear(PLATFORM_IPC_INTERRUPT); + msg = shim_read(SHIM_IPCX); + /* TODO: place message in Q and process later */ /* It's not Q ATM, may overwrite */ if (_ipc->host_pending) { - trace_ipc_error("Pen"); + trace_ipc_error("ipc: dropping msg 0x%x", msg); + trace_ipc_error(" isr 0x%x imrd 0x%x ipcx 0x%x", + isr, shim_read(SHIM_IMRD), + shim_read(SHIM_IPCX)); } else { - _ipc->host_msg = shim_read(SHIM_IPCX); + _ipc->host_msg = msg; _ipc->host_pending = 1; ipc_schedule_process(_ipc); } @@ -126,7 +132,7 @@ void ipc_platform_do_cmd(struct ipc *ipc) struct sof_ipc_reply reply; int32_t err; - tracev_ipc("Cmd"); + trace_ipc("ipc: msg rx -> 0x%x", ipc->host_msg); /* perform command and return any error */ err = ipc_cmd(); @@ -155,12 +161,9 @@ void ipc_platform_do_cmd(struct ipc *ipc) /* are we about to enter D3 ? */ if (iipc->pm_prepare_D3) { while (1) { - trace_ipc("pme"); wait_for_interrupt(0); } } - - tracev_ipc("CmD"); } void ipc_platform_send_msg(struct ipc *ipc) @@ -186,7 +189,7 @@ void ipc_platform_send_msg(struct ipc *ipc) mailbox_dspbox_write(0, msg->tx_data, msg->tx_size); list_item_del(&msg->list); ipc->shared_ctx->dsp_msg = msg; - tracev_ipc("Msg"); + tracev_ipc("ipc: msg tx -> 0x%x", msg->header); /* now interrupt host to tell it we have message sent */ shim_write(SHIM_IPCD, SHIM_IPCD_BUSY); diff --git a/src/ipc/pmc-ipc.c b/src/ipc/pmc-ipc.c index 9a60cfd25789..53517a0d622b 100644 --- a/src/ipc/pmc-ipc.c +++ b/src/ipc/pmc-ipc.c @@ -40,8 +40,6 @@ #include #include - - /* private data for IPC */ struct intel_ipc_pmc_data { uint32_t msg_l; @@ -49,7 +47,6 @@ struct intel_ipc_pmc_data { uint32_t pending; }; - static struct intel_ipc_pmc_data *_pmc; static void do_cmd(void) @@ -57,10 +54,8 @@ static void do_cmd(void) uint32_t ipcsc; uint32_t status = 0; - trace_ipc("SCm"); - trace_value(_pmc->msg_l); + trace_ipc("pmc: tx -> 0x%x", _pmc->msg_l); - //status = ipc_cmd(); _pmc->pending = 0; /* clear BUSY bit and set DONE bit - accept new messages */ @@ -73,7 +68,6 @@ static void do_cmd(void) shim_write(SHIM_IMRLPESC, shim_read(SHIM_IMRLPESC) & ~SHIM_IMRLPESC_BUSY); } - /* process current message */ int pmc_process_msg_queue(void) { @@ -84,7 +78,7 @@ int pmc_process_msg_queue(void) static void do_notify(void) { - trace_ipc("SNo"); + trace_ipc("pmc: not rx"); /* clear DONE bit */ shim_write(SHIM_IPCLPESCH, shim_read(SHIM_IPCLPESCH) & ~SHIM_IPCLPESCH_DONE); @@ -97,11 +91,11 @@ static void irq_handler(void *arg) { uint32_t isrlpesc; - trace_ipc("SIQ"); - /* Interrupt arrived, check src */ isrlpesc = shim_read(SHIM_ISRLPESC); + tracev_ipc("pmc: irq isrlpesc 0x%x", isrlpesc); + if (isrlpesc & SHIM_ISRLPESC_DONE) { /* Mask Done interrupt before return */ @@ -128,13 +122,13 @@ int ipc_pmc_send_msg(uint32_t message) uint32_t ipclpesch; int ret; - trace_ipc("SMs"); + tracev_ipc("pmc: msg tx -> 0x%x", message); ipclpesch = shim_read(SHIM_IPCLPESCH); /* we can only send new messages if the SC is not busy */ if (ipclpesch & SHIM_IPCLPESCH_BUSY) { - trace_ipc_error("ePb"); + trace_ipc_error("pmc: busy 0x%x", ipclpesch); return -EAGAIN; } @@ -149,7 +143,7 @@ int ipc_pmc_send_msg(uint32_t message) /* did command succeed */ if (ret < 0) { - trace_ipc_error("ePf"); + trace_ipc_error("pmc: command 0x%x failed", message); return -EINVAL; } diff --git a/src/ipc/sue-ipc.c b/src/ipc/sue-ipc.c index 3c6718922ea0..f089b35530cf 100644 --- a/src/ipc/sue-ipc.c +++ b/src/ipc/sue-ipc.c @@ -65,7 +65,7 @@ void ipc_platform_do_cmd(struct ipc *ipc) struct sof_ipc_reply reply; int32_t err; - trace_ipc("Cmd"); + trace_ipc("ipc: msg rx -> 0x%x", ipc->host_msg); /* perform command and return any error */ err = ipc_cmd(); @@ -93,8 +93,6 @@ void ipc_platform_do_cmd(struct ipc *ipc) while (1) wait_for_interrupt(0); } - - tracev_ipc("CmD"); } void ipc_platform_send_msg(struct ipc *ipc) @@ -116,7 +114,7 @@ void ipc_platform_send_msg(struct ipc *ipc) mailbox_dspbox_write(0, msg->tx_data, msg->tx_size); list_item_del(&msg->list); ipc->shared_ctx->dsp_msg = msg; - tracev_ipc("Msg"); + tracev_ipc("ipc: msg tx -> 0x%x", msg->header); /* now interrupt host to tell it we have message sent */