codecs: Enable clock voting logs to debug AHB/NOC issues
Enable clock voting logs to debug stability issues.
Change-Id: Ie1f995ab004778a81ea42baad15ea36858407e9a
Signed-off-by: Aditya Bavanari <abavanar@codeaurora.org>
diff --git a/asoc/codecs/audio-ext-clk-up.c b/asoc/codecs/audio-ext-clk-up.c
index 632f674..fc3cb38 100644
--- a/asoc/codecs/audio-ext-clk-up.c
+++ b/asoc/codecs/audio-ext-clk-up.c
@@ -70,6 +70,8 @@
if ((clk_priv->clk_src >= AUDIO_EXT_CLK_LPASS) &&
(clk_priv->clk_src < AUDIO_EXT_CLK_LPASS_MAX)) {
clk_priv->clk_cfg.enable = 1;
+ trace_printk("%s: vote for %d clock\n",
+ __func__, clk_priv->clk_src);
ret = afe_set_lpass_clk_cfg(IDX_RSVD_3, &clk_priv->clk_cfg);
if (ret < 0) {
pr_err_ratelimited("%s afe_set_digital_codec_core_clock failed\n",
@@ -112,6 +114,8 @@
if ((clk_priv->clk_src >= AUDIO_EXT_CLK_LPASS) &&
(clk_priv->clk_src < AUDIO_EXT_CLK_LPASS_MAX)) {
clk_priv->clk_cfg.enable = 0;
+ trace_printk("%s: unvote for %d clock\n",
+ __func__, clk_priv->clk_src);
ret = afe_set_lpass_clk_cfg(IDX_RSVD_3, &clk_priv->clk_cfg);
if (ret < 0)
pr_err_ratelimited("%s: afe_set_lpass_clk_cfg failed, ret = %d\n",
@@ -146,6 +150,8 @@
int ret;
if (clk_priv->clk_src == AUDIO_EXT_CLK_LPASS_CORE_HW_VOTE) {
+ trace_printk("%s: vote for %d clock\n",
+ __func__, clk_priv->clk_src);
ret = afe_vote_lpass_core_hw(AFE_LPASS_CORE_HW_MACRO_BLOCK,
"LPASS_HW_MACRO",
&clk_priv->lpass_core_hwvote_client_handle);
@@ -157,6 +163,8 @@
}
if (clk_priv->clk_src == AUDIO_EXT_CLK_LPASS_AUDIO_HW_VOTE) {
+ trace_printk("%s: vote for %d clock\n",
+ __func__, clk_priv->clk_src);
ret = afe_vote_lpass_core_hw(AFE_LPASS_CORE_HW_DCODEC_BLOCK,
"LPASS_HW_DCODEC",
&clk_priv->lpass_audio_hwvote_client_handle);
@@ -176,6 +184,8 @@
int ret = 0;
if (clk_priv->clk_src == AUDIO_EXT_CLK_LPASS_CORE_HW_VOTE) {
+ trace_printk("%s: unvote for %d clock\n",
+ __func__, clk_priv->clk_src);
ret = afe_unvote_lpass_core_hw(
AFE_LPASS_CORE_HW_MACRO_BLOCK,
clk_priv->lpass_core_hwvote_client_handle);
@@ -186,6 +196,8 @@
}
if (clk_priv->clk_src == AUDIO_EXT_CLK_LPASS_AUDIO_HW_VOTE) {
+ trace_printk("%s: unvote for %d clock\n",
+ __func__, clk_priv->clk_src);
ret = afe_unvote_lpass_core_hw(
AFE_LPASS_CORE_HW_DCODEC_BLOCK,
clk_priv->lpass_audio_hwvote_client_handle);
diff --git a/asoc/codecs/bolero/bolero-cdc.c b/asoc/codecs/bolero/bolero-cdc.c
index af22bb2..53640a2 100644
--- a/asoc/codecs/bolero/bolero-cdc.c
+++ b/asoc/codecs/bolero/bolero-cdc.c
@@ -828,6 +828,7 @@
priv->component,
BOLERO_MACRO_EVT_CLK_RESET, 0x0);
}
+ trace_printk("%s: clk count reset\n", __func__);
regcache_cache_only(priv->regmap, false);
mutex_lock(&priv->clk_lock);
priv->dev_up = true;
@@ -838,6 +839,7 @@
/* Add a 100usec sleep to ensure last register write is done */
usleep_range(100,110);
bolero_clk_rsc_enable_all_clocks(priv->clk_dev, false);
+ trace_printk("%s: regcache_sync done\n", __func__);
/* call ssr event for supported macros */
for (macro_idx = START_MACRO; macro_idx < MAX_MACRO; macro_idx++) {
if (!priv->macro_params[macro_idx].event_handler)
@@ -846,6 +848,7 @@
priv->component,
BOLERO_MACRO_EVT_SSR_UP, 0x0);
}
+ trace_printk("%s: SSR up events processed by all macros\n", __func__);
bolero_cdc_notifier_call(priv, BOLERO_WCD_EVT_SSR_UP);
return 0;
}
@@ -1374,6 +1377,8 @@
}
}
priv->core_hw_vote_count++;
+ trace_printk("%s: hw vote count %d\n",
+ __func__, priv->core_hw_vote_count);
audio_vote:
if (priv->lpass_audio_hw_vote == NULL) {
@@ -1390,6 +1395,8 @@
}
}
priv->core_audio_vote_count++;
+ trace_printk("%s: audio vote count %d\n",
+ __func__, priv->core_audio_vote_count);
done:
mutex_unlock(&priv->vote_lock);
@@ -1412,6 +1419,8 @@
dev_dbg(dev, "%s: Invalid lpass core hw node\n",
__func__);
}
+ trace_printk("%s: hw vote count %d\n",
+ __func__, priv->core_hw_vote_count);
if (priv->lpass_audio_hw_vote != NULL) {
if (--priv->core_audio_vote_count == 0)
@@ -1422,6 +1431,8 @@
dev_dbg(dev, "%s: Invalid lpass audio hw node\n",
__func__);
}
+ trace_printk("%s: audio vote count %d\n",
+ __func__, priv->core_audio_vote_count);
mutex_unlock(&priv->vote_lock);
return 0;
diff --git a/asoc/codecs/bolero/bolero-clk-rsc.c b/asoc/codecs/bolero/bolero-clk-rsc.c
index b8ed664..2921624 100644
--- a/asoc/codecs/bolero/bolero-clk-rsc.c
+++ b/asoc/codecs/bolero/bolero-clk-rsc.c
@@ -129,6 +129,8 @@
}
dev_dbg(priv->dev,
"%s: clock reset after ssr, count %d\n", __func__, count);
+
+ trace_printk("%s: clock reset after ssr, count %d\n", __func__, count);
while (count--) {
clk_prepare_enable(priv->clk[clk_id]);
clk_prepare_enable(priv->clk[clk_id + NPL_CLK_OFFSET]);
@@ -238,6 +240,7 @@
char __iomem *clk_muxsel = NULL;
int ret = 0;
int default_clk_id = priv->default_clk_id[clk_id];
+ u32 muxsel = 0;
clk_muxsel = bolero_clk_rsc_get_clk_muxsel(priv, clk_id);
if (!clk_muxsel) {
@@ -269,6 +272,9 @@
}
}
iowrite32(0x1, clk_muxsel);
+ muxsel = ioread32(clk_muxsel);
+ trace_printk("%s: muxsel value after enable: %d\n",
+ __func__, muxsel);
bolero_clk_rsc_mux0_clk_request(priv, default_clk_id,
false);
}
@@ -288,6 +294,9 @@
if (!ret)
iowrite32(0x0, clk_muxsel);
+ muxsel = ioread32(clk_muxsel);
+ trace_printk("%s: muxsel value after disable: %d\n",
+ __func__, muxsel);
if (priv->clk[clk_id + NPL_CLK_OFFSET])
clk_disable_unprepare(
priv->clk[clk_id + NPL_CLK_OFFSET]);
@@ -504,6 +513,7 @@
if (!priv->dev_up && enable) {
dev_err_ratelimited(priv->dev, "%s: SSR is in progress..\n",
__func__);
+ trace_printk("%s: SSR is in progress..\n", __func__);
ret = -EINVAL;
goto err;
}
@@ -533,6 +543,9 @@
dev_dbg(priv->dev, "%s: clk_cnt: %d for requested clk: %d, enable: %d\n",
__func__, priv->clk_cnt[clk_id_req], clk_id_req,
enable);
+ trace_printk("%s: clk_cnt: %d for requested clk: %d, enable: %d\n",
+ __func__, priv->clk_cnt[clk_id_req], clk_id_req,
+ enable);
mutex_unlock(&priv->rsc_clk_lock);
diff --git a/asoc/codecs/bolero/rx-macro.c b/asoc/codecs/bolero/rx-macro.c
index 66be468..22ddf3f 100644
--- a/asoc/codecs/bolero/rx-macro.c
+++ b/asoc/codecs/bolero/rx-macro.c
@@ -1284,6 +1284,8 @@
}
}
exit:
+ trace_printk("%s: mclk_enable = %u, dapm = %d clk_users= %d\n",
+ __func__, mclk_enable, dapm, rx_priv->rx_mclk_users);
mutex_unlock(&rx_priv->mclk_lock);
return ret;
}
@@ -1369,6 +1371,7 @@
rx_macro_wcd_clsh_imped_config(component, data, false);
break;
case BOLERO_MACRO_EVT_SSR_DOWN:
+ trace_printk("%s, enter SSR down\n", __func__);
rx_priv->dev_up = false;
if (rx_priv->swr_ctrl_data) {
swrm_wcd_notify(
@@ -1389,6 +1392,7 @@
}
break;
case BOLERO_MACRO_EVT_SSR_UP:
+ trace_printk("%s, enter SSR up\n", __func__);
rx_priv->dev_up = true;
/* reset swr after ssr/pdr */
rx_priv->reset_swr = true;
@@ -3636,6 +3640,8 @@
mutex_lock(&rx_priv->swr_clk_lock);
+ trace_printk("%s: swrm clock %s\n",
+ __func__, (enable ? "enable" : "disable"));
dev_dbg(rx_priv->dev, "%s: swrm clock %s\n",
__func__, (enable ? "enable" : "disable"));
if (enable) {
@@ -3702,6 +3708,8 @@
}
}
}
+ trace_printk("%s: swrm clock users %d\n",
+ __func__, rx_priv->swr_clk_users);
dev_dbg(rx_priv->dev, "%s: swrm clock users %d\n",
__func__, rx_priv->swr_clk_users);
exit:
diff --git a/asoc/codecs/bolero/tx-macro.c b/asoc/codecs/bolero/tx-macro.c
index a9efa30..12bb331 100644
--- a/asoc/codecs/bolero/tx-macro.c
+++ b/asoc/codecs/bolero/tx-macro.c
@@ -373,6 +373,7 @@
switch (event) {
case BOLERO_MACRO_EVT_SSR_DOWN:
+ trace_printk("%s, enter SSR down\n", __func__);
if (tx_priv->swr_ctrl_data) {
swrm_wcd_notify(
tx_priv->swr_ctrl_data[0].tx_swr_pdev,
@@ -392,6 +393,7 @@
}
break;
case BOLERO_MACRO_EVT_SSR_UP:
+ trace_printk("%s, enter SSR up\n", __func__);
/* reset swr after ssr/pdr */
tx_priv->reset_swr = true;
if (tx_priv->swr_ctrl_data)
@@ -2355,6 +2357,9 @@
{
int ret = 0, clk_tx_ret = 0;
+ trace_printk("%s: clock type %s, enable: %s tx_mclk_users: %d\n",
+ __func__, (clk_type ? "VA_MCLK" : "TX_MCLK"),
+ (enable ? "enable" : "disable"), tx_priv->tx_mclk_users);
dev_dbg(tx_priv->dev,
"%s: clock type %s, enable: %s tx_mclk_users: %d\n",
__func__, (clk_type ? "VA_MCLK" : "TX_MCLK"),
@@ -2362,6 +2367,7 @@
if (enable) {
if (tx_priv->swr_clk_users == 0) {
+ trace_printk("%s: tx swr clk users 0\n", __func__);
ret = msm_cdc_pinctrl_select_active_state(
tx_priv->tx_swr_gpio_p);
if (ret < 0) {
@@ -2377,6 +2383,7 @@
TX_CORE_CLK,
true);
if (clk_type == TX_MCLK) {
+ trace_printk("%s: requesting TX_MCLK\n", __func__);
ret = tx_macro_mclk_enable(tx_priv, 1);
if (ret < 0) {
if (tx_priv->swr_clk_users == 0)
@@ -2389,6 +2396,7 @@
}
}
if (clk_type == VA_MCLK) {
+ trace_printk("%s: requesting VA_MCLK\n", __func__);
ret = bolero_clk_rsc_request_clock(tx_priv->dev,
TX_CORE_CLK,
VA_CORE_CLK,
@@ -2420,6 +2428,8 @@
if (tx_priv->swr_clk_users == 0) {
dev_dbg(tx_priv->dev, "%s: reset_swr: %d\n",
__func__, tx_priv->reset_swr);
+ trace_printk("%s: reset_swr: %d\n",
+ __func__, tx_priv->reset_swr);
if (tx_priv->reset_swr)
regmap_update_bits(regmap,
BOLERO_CDC_TX_CLK_RST_CTRL_SWR_CONTROL,
@@ -2513,6 +2523,7 @@
TX_CORE_CLK,
false);
exit:
+ trace_printk("%s: exit\n", __func__);
return ret;
}
@@ -2589,6 +2600,10 @@
}
mutex_lock(&tx_priv->swr_clk_lock);
+ trace_printk("%s: swrm clock %s tx_swr_clk_cnt: %d va_swr_clk_cnt: %d\n",
+ __func__,
+ (enable ? "enable" : "disable"),
+ tx_priv->tx_swr_clk_cnt, tx_priv->va_swr_clk_cnt);
dev_dbg(tx_priv->dev,
"%s: swrm clock %s tx_swr_clk_cnt: %d va_swr_clk_cnt: %d\n",
__func__, (enable ? "enable" : "disable"),
@@ -2651,6 +2666,9 @@
}
}
+ trace_printk("%s: swrm clock users %d tx_clk_sts_cnt: %d va_clk_sts_cnt: %d\n",
+ __func__, tx_priv->swr_clk_users, tx_priv->tx_clk_status,
+ tx_priv->va_clk_status);
dev_dbg(tx_priv->dev,
"%s: swrm clock users %d tx_clk_sts_cnt: %d va_clk_sts_cnt: %d\n",
__func__, tx_priv->swr_clk_users, tx_priv->tx_clk_status,
diff --git a/asoc/codecs/bolero/va-macro.c b/asoc/codecs/bolero/va-macro.c
index 3493a65..34cb177 100644
--- a/asoc/codecs/bolero/va-macro.c
+++ b/asoc/codecs/bolero/va-macro.c
@@ -295,6 +295,7 @@
__func__);
break;
case BOLERO_MACRO_EVT_SSR_UP:
+ trace_printk("%s, enter SSR up\n", __func__);
/* enable&disable VA_CORE_CLK to reset GFMUX reg */
ret = bolero_clk_rsc_request_clock(va_priv->dev,
va_priv->default_clk_id,
diff --git a/asoc/codecs/bolero/wsa-macro.c b/asoc/codecs/bolero/wsa-macro.c
index 38c075f..e42627f 100644
--- a/asoc/codecs/bolero/wsa-macro.c
+++ b/asoc/codecs/bolero/wsa-macro.c
@@ -994,6 +994,7 @@
switch (event) {
case BOLERO_MACRO_EVT_SSR_DOWN:
+ trace_printk("%s, enter SSR down\n", __func__);
if (wsa_priv->swr_ctrl_data) {
swrm_wcd_notify(
wsa_priv->swr_ctrl_data[0].wsa_swr_pdev,
@@ -1013,6 +1014,7 @@
}
break;
case BOLERO_MACRO_EVT_SSR_UP:
+ trace_printk("%s, enter SSR up\n", __func__);
/* reset swr after ssr/pdr */
wsa_priv->reset_swr = true;
/* enable&disable WSA_CORE_CLK to reset GFMUX reg */
@@ -2832,6 +2834,9 @@
mutex_lock(&wsa_priv->swr_clk_lock);
+ trace_printk("%s: %s swrm clock %s\n",
+ dev_name(wsa_priv->dev), __func__,
+ (enable ? "enable" : "disable"));
dev_dbg(wsa_priv->dev, "%s: swrm clock %s\n",
__func__, (enable ? "enable" : "disable"));
if (enable) {
@@ -2897,6 +2902,9 @@
}
}
}
+ trace_printk("%s: %s swrm clock users: %d\n",
+ dev_name(wsa_priv->dev), __func__,
+ wsa_priv->swr_clk_users);
dev_dbg(wsa_priv->dev, "%s: swrm clock users %d\n",
__func__, wsa_priv->swr_clk_users);
exit:
diff --git a/asoc/msm-dai-q6-v2.c b/asoc/msm-dai-q6-v2.c
index e9d354b..bf9c4c5 100644
--- a/asoc/msm-dai-q6-v2.c
+++ b/asoc/msm-dai-q6-v2.c
@@ -1285,6 +1285,7 @@
u16 port_id = (u16)kcontrol->private_value;
pr_debug("%s: island mode = %d\n", __func__, value);
+ trace_printk("%s: island mode = %d\n", __func__, value);
afe_set_island_mode_cfg(port_id, value);
return 0;
diff --git a/asoc/msm-pcm-routing-v2.c b/asoc/msm-pcm-routing-v2.c
index 2c7bcba..81c6c05 100644
--- a/asoc/msm-pcm-routing-v2.c
+++ b/asoc/msm-pcm-routing-v2.c
@@ -29267,8 +29267,8 @@
pr_debug("%s: port_id %d, copp_idx %d\n", __func__, port_id, copp_idx);
if (port_id != HDMI_RX && port_id != DISPLAY_PORT_RX) {
- pr_err("%s: Device pp params on invalid port %d\n",
- __func__, port_id);
+ pr_err("%s: Device pp params on invalid port %d, copp_idx %d, fe_id %d\n",
+ __func__, port_id, copp_idx, fe_id);
return -EINVAL;
}
diff --git a/dsp/q6afe.c b/dsp/q6afe.c
index 7370ae9..11f3c3e 100644
--- a/dsp/q6afe.c
+++ b/dsp/q6afe.c
@@ -1084,6 +1084,8 @@
pr_err_ratelimited("%s: request timedout\n",
__func__);
ret = -ETIMEDOUT;
+ trace_printk("%s: wait for ADSP response timed out\n",
+ __func__);
} else if (atomic_read(&this_afe.status) > 0) {
pr_err("%s: DSP returned error[%s]\n", __func__,
adsp_err_get_err_str(atomic_read(
@@ -2235,7 +2237,7 @@
__func__, port_id, ret);
fail_cmd:
- pr_debug("%s: port_id 0x%x rate %u delay_usec %d status %d\n",
+ pr_info("%s: port_id 0x%x rate %u delay_usec %d status %d\n",
__func__, port_id, rate, delay_entry.delay_usec, ret);
return ret;
}
@@ -2259,6 +2261,8 @@
/* Skip cal_block if it is already marked stale */
if (cal_utils_is_cal_stale(cal_block))
continue;
+ pr_info("%s: port id: 0x%x, dev_acdb_id: %d\n", __func__,
+ port_id, this_afe.dev_acdb_id[afe_port_index]);
path = ((afe_get_port_type(port_id) ==
MSM_AFE_PORT_TYPE_TX)?(TX_DEVICE):(RX_DEVICE));
afe_top =
@@ -2267,14 +2271,14 @@
if (this_afe.dev_acdb_id[afe_port_index] > 0) {
if (afe_top->acdb_id ==
this_afe.dev_acdb_id[afe_port_index]) {
- pr_debug("%s: top_id:%x acdb_id:%d afe_port_id:%d\n",
+ pr_info("%s: top_id:%x acdb_id:%d afe_port_id:0x%x\n",
__func__, afe_top->topology,
afe_top->acdb_id,
q6audio_get_port_id(port_id));
return cal_block;
}
} else {
- pr_debug("%s: top_id:%x acdb_id:%d afe_port:%d\n",
+ pr_info("%s: top_id:%x acdb_id:%d afe_port:0x%x\n",
__func__, afe_top->topology, afe_top->acdb_id,
q6audio_get_port_id(port_id));
return cal_block;
@@ -2331,9 +2335,9 @@
*topology_id = (u32)afe_top_info->topology;
cal_utils_mark_cal_used(cal_block);
- pr_debug("%s: port_id = %u acdb_id = %d topology_id = %u ret=%d\n",
+ pr_info("%s: port_id = 0x%x acdb_id = %d topology_id = 0x%x cal_type_index=%d ret=%d\n",
__func__, port_id, afe_top_info->acdb_id,
- afe_top_info->topology, ret);
+ afe_top_info->topology, cal_type_index, ret);
unlock:
mutex_unlock(&this_afe.cal_data[cal_type_index]->lock);
return ret;
@@ -2388,7 +2392,7 @@
this_afe.topology[index] = topology_id;
rtac_update_afe_topology(port_id);
done:
- pr_debug("%s: AFE set topology id 0x%x enable for port 0x%x ret %d\n",
+ pr_info("%s: AFE set topology id 0x%x enable for port 0x%x ret %d\n",
__func__, topology_id, port_id, ret);
return ret;
@@ -2461,6 +2465,8 @@
}
pr_debug("%s: AFE set island mode 0x%x enable for port 0x%x ret %d\n",
__func__, island_mode, port_id, ret);
+ trace_printk("%s: AFE set island mode 0x%x enable for port 0x%x ret %d\n",
+ __func__, island_mode, port_id, ret);
return ret;
}
EXPORT_SYMBOL(afe_send_port_island_mode);
@@ -2623,7 +2629,7 @@
struct audio_cal_info_afe *afe_cal_info = NULL;
int afe_port_index = q6audio_get_port_index(port_id);
- pr_debug("%s: cal_index %d port_id %d port_index %d\n", __func__,
+ pr_info("%s: cal_index %d port_id 0x%x port_index %d\n", __func__,
cal_index, port_id, afe_port_index);
if (afe_port_index < 0) {
pr_err("%s: Error getting AFE port index %d\n",
@@ -2635,16 +2641,21 @@
&this_afe.cal_data[cal_index]->cal_blocks) {
cal_block = list_entry(ptr, struct cal_block_data, list);
afe_cal_info = cal_block->cal_info;
+ pr_info("%s: acdb_id %d dev_acdb_id %d sample_rate %d afe_sample_rates %d\n",
+ __func__, afe_cal_info->acdb_id,
+ this_afe.dev_acdb_id[afe_port_index],
+ afe_cal_info->sample_rate,
+ this_afe.afe_sample_rates[afe_port_index]);
if ((afe_cal_info->acdb_id ==
this_afe.dev_acdb_id[afe_port_index]) &&
(afe_cal_info->sample_rate ==
this_afe.afe_sample_rates[afe_port_index])) {
- pr_debug("%s: cal block is a match, size is %zd\n",
+ pr_info("%s: cal block is a match, size is %zd\n",
__func__, cal_block->cal_data.size);
goto exit;
}
}
- pr_debug("%s: no matching cal_block found\n", __func__);
+ pr_info("%s: no matching cal_block found\n", __func__);
cal_block = NULL;
exit:
@@ -2657,7 +2668,7 @@
int ret;
int afe_port_index = q6audio_get_port_index(port_id);
- pr_debug("%s:\n", __func__);
+ pr_info("%s: cal_index is %d\n", __func__, cal_index);
if (this_afe.cal_data[cal_index] == NULL) {
pr_warn("%s: cal_index %d not allocated!\n",
@@ -2674,7 +2685,9 @@
}
mutex_lock(&this_afe.cal_data[cal_index]->lock);
-
+ pr_info("%s: dev_acdb_id[%d] is %d\n",
+ __func__, afe_port_index,
+ this_afe.dev_acdb_id[afe_port_index]);
if (((cal_index == AFE_COMMON_RX_CAL) ||
(cal_index == AFE_COMMON_TX_CAL) ||
(cal_index == AFE_LSM_TX_CAL)) &&
@@ -2690,7 +2703,7 @@
goto unlock;
}
- pr_debug("%s: Sending cal_index cal %d\n", __func__, cal_index);
+ pr_info("%s: Sending cal_index cal %d\n", __func__, cal_index);
ret = remap_cal_data(cal_block, cal_index);
if (ret) {
@@ -2701,7 +2714,7 @@
}
ret = afe_send_cal_block(port_id, cal_block);
if (ret < 0)
- pr_debug("%s: No cal sent for cal_index %d, port_id = 0x%x! ret %d\n",
+ pr_err("%s: No cal sent for cal_index %d, port_id = 0x%x! ret %d\n",
__func__, cal_index, port_id, ret);
cal_utils_mark_cal_used(cal_block);
@@ -3776,6 +3789,8 @@
port_index = afe_get_port_index(port_id);
this_afe.island_mode[port_index] = enable_flag;
+ trace_printk("%s: set island mode cfg 0x%x for port 0x%x\n",
+ __func__, this_afe.island_mode[port_index], port_id);
}
EXPORT_SYMBOL(afe_set_island_mode_cfg);
@@ -4559,7 +4574,7 @@
port_id = VIRTUAL_ID_TO_PORTID(port_id);
}
- pr_debug("%s: port id: 0x%x\n", __func__, port_id);
+ pr_info("%s: port id: 0x%x\n", __func__, port_id);
index = q6audio_get_port_index(port_id);
if (index < 0 || index >= AFE_MAX_PORTS) {
@@ -7580,7 +7595,7 @@
ret = -EINVAL;
goto fail_cmd;
}
- pr_debug("%s: port_id = 0x%x\n", __func__, port_id);
+ pr_info("%s: port_id = 0x%x\n", __func__, port_id);
if ((port_id == RT_PROXY_DAI_001_RX) ||
(port_id == RT_PROXY_DAI_002_TX)) {
pr_debug("%s: before decrementing pcm_afe_instance %d\n",
@@ -7767,6 +7782,15 @@
cfg->clk_root, cfg->clk_set_mode,
cfg->reserved, q6audio_get_port_id(port_id));
+ trace_printk("%s: Minor version =0x%x clk val1 = %d\n"
+ "clk val2 = %d, clk src = 0x%x\n"
+ "clk root = 0x%x clk mode = 0x%x resrv = 0x%x\n"
+ "port id = 0x%x\n",
+ __func__, cfg->i2s_cfg_minor_version,
+ cfg->clk_val1, cfg->clk_val2, cfg->clk_src,
+ cfg->clk_root, cfg->clk_set_mode,
+ cfg->reserved, q6audio_get_port_id(port_id));
+
ret = q6afe_pack_and_set_param_in_band(port_id,
q6audio_get_port_index(port_id),
param_hdr, (u8 *) &clk_cfg);
@@ -7819,12 +7843,21 @@
cfg->clk_id, cfg->clk_freq_in_hz, cfg->clk_attri,
cfg->clk_root, cfg->enable);
+ trace_printk("%s: Minor version =0x%x clk id = %d\n"
+ "clk freq (Hz) = %d, clk attri = 0x%x\n"
+ "clk root = 0x%x clk enable = 0x%x\n",
+ __func__, cfg->clk_set_minor_version,
+ cfg->clk_id, cfg->clk_freq_in_hz, cfg->clk_attri,
+ cfg->clk_root, cfg->enable);
+
ret = q6afe_svc_pack_and_set_param_in_band(index, param_hdr,
(u8 *) cfg);
- if (ret < 0)
+ if (ret < 0) {
pr_err_ratelimited("%s: AFE clk cfg failed with ret %d\n",
+ __func__, ret);
+ trace_printk("%s: AFE clk cfg failed with ret %d\n",
__func__, ret);
-
+ }
mutex_unlock(&this_afe.afe_clk_lock);
return ret;
}
@@ -9327,6 +9360,8 @@
pr_debug("%s: lpass core hw vote opcode[0x%x] hw id[0x%x]\n",
__func__, cmd_ptr->hdr.opcode, cmd_ptr->hw_block_id);
+ trace_printk("%s: lpass core hw vote opcode[0x%x] hw id[0x%x]\n",
+ __func__, cmd_ptr->hdr.opcode, cmd_ptr->hw_block_id);
*client_handle = 0;
ret = afe_apr_send_clk_pkt((uint32_t *)cmd_ptr,
@@ -9366,6 +9401,7 @@
if (!this_afe.lpass_hw_core_client_hdl[hw_block_id]) {
pr_debug("%s: SSR in progress, return\n", __func__);
+ trace_printk("%s: SSR in progress, return\n", __func__);
goto done;
}
@@ -9385,6 +9421,9 @@
pr_debug("%s: lpass core hw unvote opcode[0x%x] hw id[0x%x]\n",
__func__, cmd_ptr->hdr.opcode, cmd_ptr->hw_block_id);
+ trace_printk("%s: lpass core hw unvote opcode[0x%x] hw id[0x%x]\n",
+ __func__, cmd_ptr->hdr.opcode, cmd_ptr->hw_block_id);
+
if (cmd_ptr->client_handle <= 0) {
pr_err("%s: invalid client handle\n", __func__);
ret = -EINVAL;
diff --git a/soc/pinctrl-lpi.c b/soc/pinctrl-lpi.c
index 2b9e52e..e69afdd 100644
--- a/soc/pinctrl-lpi.c
+++ b/soc/pinctrl-lpi.c
@@ -497,6 +497,7 @@
{
int ret = 0;
+ trace_printk("%s: system suspend\n", __func__);
dev_dbg(dev, "%s: system suspend\n", __func__);
if ((!pm_runtime_enabled(dev) || !pm_runtime_suspended(dev))) {
@@ -533,6 +534,7 @@
static void lpi_pinctrl_ssr_disable(struct device *dev, void *data)
{
+ trace_printk("%s: enter\n", __func__);
lpi_dev_up = false;
lpi_pinctrl_suspend(dev);
}
@@ -857,6 +859,7 @@
int ret = 0;
struct clk *hw_vote = state->lpass_core_hw_vote;
+ trace_printk("%s: enter\n", __func__);
if (state->lpass_core_hw_vote == NULL) {
dev_dbg(dev, "%s: Invalid core hw node\n", __func__);
if (state->lpass_audio_hw_vote == NULL) {
@@ -882,6 +885,7 @@
exit:
mutex_unlock(&state->core_hw_vote_lock);
+ trace_printk("%s: exit\n", __func__);
return 0;
}
@@ -890,6 +894,7 @@
struct lpi_gpio_state *state = dev_get_drvdata(dev);
struct clk *hw_vote = state->lpass_core_hw_vote;
+ trace_printk("%s: enter\n", __func__);
if (state->lpass_core_hw_vote == NULL) {
dev_dbg(dev, "%s: Invalid core hw node\n", __func__);
if (state->lpass_audio_hw_vote == NULL) {
@@ -905,6 +910,7 @@
state->core_hw_vote_status = false;
}
mutex_unlock(&state->core_hw_vote_lock);
+ trace_printk("%s: exit\n", __func__);
return 0;
}
diff --git a/soc/swr-mstr-ctrl.c b/soc/swr-mstr-ctrl.c
index cd3805f..b8f8e2a 100644
--- a/soc/swr-mstr-ctrl.c
+++ b/soc/swr-mstr-ctrl.c
@@ -454,6 +454,8 @@
}
swrm->clk_ref_count++;
if (swrm->clk_ref_count == 1) {
+ trace_printk("%s: clock enable count %d",
+ __func__, swrm->clk_ref_count);
ret = swrm->clk(swrm->handle, true);
if (ret) {
dev_err_ratelimited(swrm->dev,
@@ -463,6 +465,8 @@
}
}
} else if (--swrm->clk_ref_count == 0) {
+ trace_printk("%s: clock disable count %d",
+ __func__, swrm->clk_ref_count);
swrm->clk(swrm->handle, false);
complete(&swrm->clk_off_complete);
}
@@ -1673,6 +1677,7 @@
struct swr_device *swr_dev;
struct swr_master *mstr = &swrm->master;
+ trace_printk("%s enter\n", __func__);
if (unlikely(swrm_lock_sleep(swrm) == false)) {
dev_err(swrm->dev, "%s Failed to hold suspend\n", __func__);
return IRQ_NONE;
@@ -1689,6 +1694,8 @@
intr_sts = swr_master_read(swrm, SWRM_INTERRUPT_STATUS);
intr_sts_masked = intr_sts & swrm->intr_mask;
+
+ trace_printk("%s: status: 0x%x \n", __func__, intr_sts_masked);
handle_irq:
for (i = 0; i < SWRM_INTERRUPT_MAX; i++) {
value = intr_sts_masked & (1 << i);
@@ -1833,6 +1840,7 @@
mutex_unlock(&swrm->reslock);
exit:
swrm_unlock_sleep(swrm);
+ trace_printk("%s exit\n", __func__);
return ret;
}
@@ -1847,6 +1855,7 @@
struct swr_device *swr_dev;
struct swr_master *mstr = &swrm->master;
+ trace_printk("%s enter\n", __func__);
if (unlikely(swrm_lock_sleep(swrm) == false)) {
dev_err(swrm->dev, "%s Failed to hold suspend\n", __func__);
return IRQ_NONE;
@@ -1873,6 +1882,7 @@
intr_sts_masked = intr_sts & swrm->intr_mask;
dev_dbg(swrm->dev, "%s: status: 0x%x \n", __func__, intr_sts_masked);
+ trace_printk("%s: status: 0x%x \n", __func__, intr_sts_masked);
handle_irq:
for (i = 0; i < SWRM_INTERRUPT_MAX; i++) {
value = intr_sts_masked & (1 << i);
@@ -2054,6 +2064,7 @@
exit:
mutex_unlock(&swrm->reslock);
swrm_unlock_sleep(swrm);
+ trace_printk("%s exit\n", __func__);
return ret;
}
@@ -2067,6 +2078,7 @@
return IRQ_NONE;
}
+ trace_printk("%s enter\n", __func__);
mutex_lock(&swrm->devlock);
if (!swrm->dev_up) {
if (swrm->wake_irq > 0) {
@@ -2105,6 +2117,7 @@
pm_runtime_put_autosuspend(swrm->dev);
swrm_unlock_sleep(swrm);
exit:
+ trace_printk("%s exit\n", __func__);
return ret;
}
@@ -2119,6 +2132,7 @@
return;
}
+ trace_printk("%s enter\n", __func__);
mutex_lock(&swrm->devlock);
if (!swrm->dev_up) {
mutex_unlock(&swrm->devlock);
@@ -2134,6 +2148,7 @@
pm_runtime_put_autosuspend(swrm->dev);
swrm_unlock_sleep(swrm);
exit:
+ trace_printk("%s exit\n", __func__);
pm_relax(swrm->dev);
}
@@ -2238,6 +2253,8 @@
}
dev_dbg(swrm->dev, "%s: hw_clk_en: %d audio_core_clk_en: %d\n",
__func__, swrm->hw_core_clk_en, swrm->aud_core_clk_en);
+ trace_printk("%s: hw_clk_en: %d audio_core_clk_en: %d\n",
+ __func__, swrm->hw_core_clk_en, swrm->aud_core_clk_en);
pm_runtime_get_sync(swrm->dev);
}
@@ -2255,6 +2272,8 @@
dev_dbg(swrm->dev, "%s: hw_clk_en: %d audio_core_clk_en: %d\n",
__func__, swrm->hw_core_clk_en, swrm->aud_core_clk_en);
+ trace_printk("%s: hw_clk_en: %d audio_core_clk_en: %d\n",
+ __func__, swrm->hw_core_clk_en, swrm->aud_core_clk_en);
--swrm->aud_core_clk_en;
if (swrm->aud_core_clk_en < 0)
swrm->aud_core_clk_en = 0;
@@ -2807,6 +2826,8 @@
dev_dbg(dev, "%s: pm_runtime: resume, state:%d\n",
__func__, swrm->state);
+ trace_printk("%s: pm_runtime: resume, state:%d\n",
+ __func__, swrm->state);
mutex_lock(&swrm->reslock);
if (swrm_request_hw_vote(swrm, LPASS_HW_CORE, true)) {
@@ -2857,6 +2878,9 @@
dev_dbg(dev,
"%s slave device up not implemented\n",
__func__);
+ trace_printk(
+ "%s slave device up not implemented\n",
+ __func__);
ret = 0;
} else if (ret) {
dev_err(dev,
@@ -2912,6 +2936,8 @@
auto_suspend_timer);
mutex_unlock(&swrm->reslock);
+ trace_printk("%s: pm_runtime: resume done, state:%d\n",
+ __func__, swrm->state);
return ret;
}
@@ -2926,6 +2952,8 @@
struct swr_device *swr_dev;
int current_state = 0;
+ trace_printk("%s: pm_runtime: suspend state: %d\n",
+ __func__, swrm->state);
dev_dbg(dev, "%s: pm_runtime: suspend state: %d\n",
__func__, swrm->state);
mutex_lock(&swrm->reslock);
@@ -2950,10 +2978,13 @@
if ((current_state != SWR_MSTR_SSR) &&
swrm_is_port_en(&swrm->master)) {
dev_dbg(dev, "%s ports are enabled\n", __func__);
+ trace_printk("%s ports are enabled\n", __func__);
ret = -EBUSY;
goto exit;
}
if (!swrm->clk_stop_mode0_supp || swrm->state == SWR_MSTR_SSR) {
+ dev_err(dev, "%s: clk stop mode not supported or SSR entry\n",
+ __func__);
mutex_unlock(&swrm->reslock);
enable_bank_switch(swrm, 0, SWR_ROW_50, SWR_MIN_COL);
mutex_lock(&swrm->reslock);
@@ -2964,15 +2995,23 @@
if (ret == -ENODEV) {
dev_dbg_ratelimited(dev,
"%s slave device down not implemented\n",
- __func__);
+ __func__);
+ trace_printk(
+ "%s slave device down not implemented\n",
+ __func__);
ret = 0;
} else if (ret) {
dev_err(dev,
"%s: failed to shutdown swr dev %d\n",
__func__, swr_dev->dev_num);
+ trace_printk(
+ "%s: failed to shutdown swr dev %d\n",
+ __func__, swr_dev->dev_num);
goto exit;
}
}
+ trace_printk("%s: clk stop mode not supported or SSR exit\n",
+ __func__);
} else {
/* Mask bus clash interrupt */
swrm->intr_mask &= ~((u32)0x08);
@@ -3018,6 +3057,8 @@
if (!hw_core_err)
swrm_request_hw_vote(swrm, LPASS_HW_CORE, false);
mutex_unlock(&swrm->reslock);
+ trace_printk("%s: pm_runtime: suspend done state: %d\n",
+ __func__, swrm->state);
return ret;
}
#endif /* CONFIG_PM */
@@ -3029,6 +3070,7 @@
int ret = 0;
dev_dbg(dev, "%s: swrm state: %d\n", __func__, swrm->state);
+ trace_printk("%s: swrm state: %d\n", __func__, swrm->state);
if (!pm_runtime_enabled(dev) || !pm_runtime_suspended(dev)) {
ret = swrm_runtime_suspend(dev);
if (!ret) {
@@ -3047,6 +3089,7 @@
struct swr_mstr_ctrl *swrm = platform_get_drvdata(pdev);
dev_dbg(dev, "%s: swrm state: %d\n", __func__, swrm->state);
+ trace_printk("%s: swrm state: %d\n", __func__, swrm->state);
mutex_lock(&swrm->force_down_lock);
swrm->state = SWR_MSTR_SSR;
@@ -3220,6 +3263,7 @@
}
break;
case SWR_DEVICE_SSR_DOWN:
+ trace_printk("%s: swr device down called\n", __func__);
mutex_lock(&swrm->devlock);
swrm->dev_up = false;
mutex_unlock(&swrm->devlock);
@@ -3229,6 +3273,7 @@
break;
case SWR_DEVICE_SSR_UP:
/* wait for clk voting to be zero */
+ trace_printk("%s: swr device up called\n", __func__);
reinit_completion(&swrm->clk_off_complete);
if (swrm->clk_ref_count &&
!wait_for_completion_timeout(&swrm->clk_off_complete,
@@ -3242,6 +3287,7 @@
break;
case SWR_DEVICE_DOWN:
dev_dbg(swrm->dev, "%s: swr master down called\n", __func__);
+ trace_printk("%s: swr master down called\n", __func__);
mutex_lock(&swrm->mlock);
if (swrm->state == SWR_MSTR_DOWN)
dev_dbg(swrm->dev, "%s:SWR master is already Down:%d\n",
@@ -3252,6 +3298,7 @@
break;
case SWR_DEVICE_UP:
dev_dbg(swrm->dev, "%s: swr master up called\n", __func__);
+ trace_printk("%s: swr master up called\n", __func__);
mutex_lock(&swrm->devlock);
if (!swrm->dev_up) {
dev_dbg(swrm->dev, "SSR not complete yet\n");