soc: qcom: glink: Add support for transport based logging

All Transports debug logs are captured in one logging context
which makes the debugging difficult and has a chance to miss
the important logs due to other high traffic transports like RPM.

Create separate logging context for each transports for better
debugging.

Change-Id: If2d00966a186dc48badc8a9a2e017eec6895dcad
Signed-off-by: Arun Kumar Neelakantam <aneela@codeaurora.org>
This commit is contained in:
Arun Kumar Neelakantam 2015-11-13 20:35:49 +05:30 committed by David Keitel
parent 9e34c2bdf3
commit 9188869e03
3 changed files with 155 additions and 74 deletions

View file

@ -30,7 +30,7 @@
#include "glink_xprt_if.h" #include "glink_xprt_if.h"
/* Number of internal IPC Logging log pages */ /* Number of internal IPC Logging log pages */
#define NUM_LOG_PAGES 15 #define NUM_LOG_PAGES 10
#define GLINK_PM_QOS_HOLDOFF_MS 10 #define GLINK_PM_QOS_HOLDOFF_MS 10
#define GLINK_QOS_DEF_NUM_TOKENS 10 #define GLINK_QOS_DEF_NUM_TOKENS 10
#define GLINK_QOS_DEF_NUM_PRIORITY 1 #define GLINK_QOS_DEF_NUM_PRIORITY 1
@ -94,6 +94,7 @@ struct glink_qos_priority_bin {
* @tx_path_activity: transmit activity has occurred * @tx_path_activity: transmit activity has occurred
* @pm_qos_work: removes PM QoS vote due to inactivity * @pm_qos_work: removes PM QoS vote due to inactivity
* @xprt_dbgfs_lock_lhb3: debugfs channel structure lock * @xprt_dbgfs_lock_lhb3: debugfs channel structure lock
* @log_ctx: IPC logging context for this transport.
*/ */
struct glink_core_xprt_ctx { struct glink_core_xprt_ctx {
struct rwref_lock xprt_state_lhb0; struct rwref_lock xprt_state_lhb0;
@ -136,6 +137,7 @@ struct glink_core_xprt_ctx {
struct delayed_work pm_qos_work; struct delayed_work pm_qos_work;
struct mutex xprt_dbgfs_lock_lhb3; struct mutex xprt_dbgfs_lock_lhb3;
void *log_ctx;
}; };
/** /**
@ -3589,6 +3591,7 @@ int glink_core_register_transport(struct glink_transport_if *if_ptr,
size_t len; size_t len;
uint16_t id; uint16_t id;
int ret; int ret;
char log_name[GLINK_NAME_SIZE*2+2] = {0};
if (!if_ptr || !cfg || !cfg->name || !cfg->edge) if (!if_ptr || !cfg || !cfg->name || !cfg->edge)
return -EINVAL; return -EINVAL;
@ -3676,6 +3679,12 @@ int glink_core_register_transport(struct glink_transport_if *if_ptr,
list_add_tail(&xprt_ptr->list_node, &transport_list); list_add_tail(&xprt_ptr->list_node, &transport_list);
mutex_unlock(&transport_list_lock_lha0); mutex_unlock(&transport_list_lock_lha0);
glink_debugfs_add_xprt(xprt_ptr); glink_debugfs_add_xprt(xprt_ptr);
snprintf(log_name, sizeof(log_name), "%s_%s",
xprt_ptr->edge, xprt_ptr->name);
xprt_ptr->log_ctx = ipc_log_context_create(NUM_LOG_PAGES, log_name, 0);
if (!xprt_ptr->log_ctx)
GLINK_ERR("%s: unable to create log context for [%s:%s]\n",
__func__, xprt_ptr->edge, xprt_ptr->name);
return 0; return 0;
} }
@ -3703,6 +3712,8 @@ void glink_core_unregister_transport(struct glink_transport_if *if_ptr)
mutex_unlock(&transport_list_lock_lha0); mutex_unlock(&transport_list_lock_lha0);
flush_delayed_work(&xprt_ptr->pm_qos_work); flush_delayed_work(&xprt_ptr->pm_qos_work);
pm_qos_remove_request(&xprt_ptr->pm_qos_req); pm_qos_remove_request(&xprt_ptr->pm_qos_req);
ipc_log_context_destroy(xprt_ptr->log_ctx);
xprt_ptr->log_ctx = NULL;
rwref_put(&xprt_ptr->xprt_state_lhb0); rwref_put(&xprt_ptr->xprt_state_lhb0);
} }
EXPORT_SYMBOL(glink_core_unregister_transport); EXPORT_SYMBOL(glink_core_unregister_transport);
@ -3800,6 +3811,7 @@ static struct glink_core_xprt_ctx *glink_create_dummy_xprt_ctx(
if_ptr->tx_cmd_ch_remote_close_ack = dummy_tx_cmd_ch_remote_close_ack; if_ptr->tx_cmd_ch_remote_close_ack = dummy_tx_cmd_ch_remote_close_ack;
xprt_ptr->ops = if_ptr; xprt_ptr->ops = if_ptr;
xprt_ptr->log_ctx = log_ctx;
spin_lock_init(&xprt_ptr->xprt_ctx_lock_lhb1); spin_lock_init(&xprt_ptr->xprt_ctx_lock_lhb1);
INIT_LIST_HEAD(&xprt_ptr->free_lcid_list); INIT_LIST_HEAD(&xprt_ptr->free_lcid_list);
xprt_ptr->local_state = GLINK_XPRT_DOWN; xprt_ptr->local_state = GLINK_XPRT_DOWN;
@ -5698,6 +5710,20 @@ void *glink_get_log_ctx(void)
} }
EXPORT_SYMBOL(glink_get_log_ctx); EXPORT_SYMBOL(glink_get_log_ctx);
/**
* glink_get_xprt_log_ctx() - Return log context for GLINK xprts.
*
* Return: Log context or NULL if none.
*/
void *glink_get_xprt_log_ctx(struct glink_core_xprt_ctx *xprt)
{
if (xprt)
return xprt->log_ctx;
else
return NULL;
}
EXPORT_SYMBOL(glink_get_xprt_log_ctx);
static int glink_init(void) static int glink_init(void)
{ {
log_ctx = ipc_log_context_create(NUM_LOG_PAGES, "glink", 0); log_ctx = ipc_log_context_create(NUM_LOG_PAGES, "glink", 0);

View file

@ -186,15 +186,36 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
GLINK_IPC_LOG_STR("<PERF> " x); \ GLINK_IPC_LOG_STR("<PERF> " x); \
} while (0) } while (0)
#define GLINK_XPRT_IPC_LOG_STR(xprt, x...) do { \
if (glink_get_xprt_log_ctx(xprt)) \
ipc_log_string(glink_get_xprt_log_ctx(xprt), x); \
} while (0)
#define GLINK_XPRT_IF_INFO(xprt_if, x...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_INFO) \
GLINK_XPRT_IPC_LOG_STR(xprt_if.glink_core_priv, "<XPRT> " x); \
} while (0)
#define GLINK_XPRT_IF_DBG(xprt_if, x...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \
GLINK_XPRT_IPC_LOG_STR(xprt_if.glink_core_priv, "<XPRT> " x); \
} while (0)
#define GLINK_XPRT_IF_ERR(xprt_if, x...) do { \
pr_err("<XPRT> " x); \
GLINK_XPRT_IPC_LOG_STR(xprt_if.glink_core_priv, "<XPRT> " x); \
} while (0)
#define GLINK_PERF_XPRT(xprt, fmt, args...) do { \ #define GLINK_PERF_XPRT(xprt, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_PERF) \ if (glink_get_debug_mask() & QCOM_GLINK_PERF) \
GLINK_IPC_LOG_STR("<PERF> %s:%s " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, "<PERF> %s:%s " fmt, \
xprt->name, xprt->edge, args); \ xprt->name, xprt->edge, args); \
} while (0) } while (0)
#define GLINK_PERF_CH(ctx, fmt, args...) do { \ #define GLINK_PERF_CH(ctx, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_PERF) \ if (glink_get_debug_mask() & QCOM_GLINK_PERF) \
GLINK_IPC_LOG_STR("<PERF> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(ctx->transport_ptr, \
"<PERF> %s:%s:%s[%u:%u] " fmt, \
ctx->transport_ptr->name, \ ctx->transport_ptr->name, \
ctx->transport_ptr->edge, \ ctx->transport_ptr->edge, \
ctx->name, \ ctx->name, \
@ -204,7 +225,8 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_PERF_CH_XPRT(ctx, xprt, fmt, args...) do { \ #define GLINK_PERF_CH_XPRT(ctx, xprt, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_PERF) \ if (glink_get_debug_mask() & QCOM_GLINK_PERF) \
GLINK_IPC_LOG_STR("<PERF> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, \
"<PERF> %s:%s:%s[%u:%u] " fmt, \
xprt->name, \ xprt->name, \
xprt->edge, \ xprt->edge, \
ctx->name, \ ctx->name, \
@ -214,13 +236,14 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_INFO_PERF_XPRT(xprt, fmt, args...) do { \ #define GLINK_INFO_PERF_XPRT(xprt, fmt, args...) do { \
if (glink_get_debug_mask() & (QCOM_GLINK_INFO | QCOM_GLINK_PERF)) \ if (glink_get_debug_mask() & (QCOM_GLINK_INFO | QCOM_GLINK_PERF)) \
GLINK_IPC_LOG_STR("<CORE> %s:%s " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, "<CORE> %s:%s " fmt, \
xprt->name, xprt->edge, args); \ xprt->name, xprt->edge, args); \
} while (0) } while (0)
#define GLINK_INFO_PERF_CH(ctx, fmt, args...) do { \ #define GLINK_INFO_PERF_CH(ctx, fmt, args...) do { \
if (glink_get_debug_mask() & (QCOM_GLINK_INFO | QCOM_GLINK_PERF)) \ if (glink_get_debug_mask() & (QCOM_GLINK_INFO | QCOM_GLINK_PERF)) \
GLINK_IPC_LOG_STR("<CORE> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(ctx->transport_ptr, \
"<CORE> %s:%s:%s[%u:%u] " fmt, \
ctx->transport_ptr->name, \ ctx->transport_ptr->name, \
ctx->transport_ptr->edge, \ ctx->transport_ptr->edge, \
ctx->name, \ ctx->name, \
@ -230,7 +253,8 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_INFO_PERF_CH_XPRT(ctx, xprt, fmt, args...) do { \ #define GLINK_INFO_PERF_CH_XPRT(ctx, xprt, fmt, args...) do { \
if (glink_get_debug_mask() & (QCOM_GLINK_INFO | QCOM_GLINK_PERF)) \ if (glink_get_debug_mask() & (QCOM_GLINK_INFO | QCOM_GLINK_PERF)) \
GLINK_IPC_LOG_STR("<CORE> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt,\
"<CORE> %s:%s:%s[%u:%u] " fmt, \
xprt->name, \ xprt->name, \
xprt->edge, \ xprt->edge, \
ctx->name, \ ctx->name, \
@ -240,13 +264,14 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_INFO_XPRT(xprt, fmt, args...) do { \ #define GLINK_INFO_XPRT(xprt, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_INFO) \ if (glink_get_debug_mask() & QCOM_GLINK_INFO) \
GLINK_IPC_LOG_STR("<CORE> %s:%s " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, "<CORE> %s:%s " fmt, \
xprt->name, xprt->edge, args); \ xprt->name, xprt->edge, args); \
} while (0) } while (0)
#define GLINK_INFO_CH(ctx, fmt, args...) do { \ #define GLINK_INFO_CH(ctx, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_INFO) \ if (glink_get_debug_mask() & QCOM_GLINK_INFO) \
GLINK_IPC_LOG_STR("<CORE> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(ctx->transport_ptr, \
"<CORE> %s:%s:%s[%u:%u] " fmt, \
ctx->transport_ptr->name, \ ctx->transport_ptr->name, \
ctx->transport_ptr->edge, \ ctx->transport_ptr->edge, \
ctx->name, \ ctx->name, \
@ -256,7 +281,8 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_INFO_CH_XPRT(ctx, xprt, fmt, args...) do { \ #define GLINK_INFO_CH_XPRT(ctx, xprt, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_INFO) \ if (glink_get_debug_mask() & QCOM_GLINK_INFO) \
GLINK_IPC_LOG_STR("<CORE> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, \
"<CORE> %s:%s:%s[%u:%u] " fmt, \
xprt->name, \ xprt->name, \
xprt->edge, \ xprt->edge, \
ctx->name, \ ctx->name, \
@ -266,13 +292,14 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_DBG_XPRT(xprt, fmt, args...) do { \ #define GLINK_DBG_XPRT(xprt, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \ if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \
GLINK_IPC_LOG_STR("<CORE> %s:%s " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, "<CORE> %s:%s " fmt, \
xprt->name, xprt->edge, args); \ xprt->name, xprt->edge, args); \
} while (0) } while (0)
#define GLINK_DBG_CH(ctx, fmt, args...) do { \ #define GLINK_DBG_CH(ctx, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \ if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \
GLINK_IPC_LOG_STR("<CORE> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(ctx->transport_ptr, \
"<CORE> %s:%s:%s[%u:%u] " fmt, \
ctx->transport_ptr->name, \ ctx->transport_ptr->name, \
ctx->transport_ptr->edge, \ ctx->transport_ptr->edge, \
ctx->name, \ ctx->name, \
@ -282,7 +309,8 @@ const char *glink_get_ch_state_string(enum local_channel_state_e enum_id);
#define GLINK_DBG_CH_XPRT(ctx, xprt, fmt, args...) do { \ #define GLINK_DBG_CH_XPRT(ctx, xprt, fmt, args...) do { \
if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \ if (glink_get_debug_mask() & QCOM_GLINK_DEBUG) \
GLINK_IPC_LOG_STR("<CORE> %s:%s:%s[%u:%u] " fmt, \ GLINK_XPRT_IPC_LOG_STR(xprt, \
"<CORE> %s:%s:%s[%u:%u] " fmt, \
xprt->name, \ xprt->name, \
xprt->edge, \ xprt->edge, \
ctx->name, \ ctx->name, \
@ -346,6 +374,13 @@ unsigned glink_get_debug_mask(void);
*/ */
void *glink_get_log_ctx(void); void *glink_get_log_ctx(void);
/**
* glink_get_xprt_log_ctx() - Return log context for other GLINK modules.
*
* Return: Log context or NULL if none.
*/
void *glink_get_xprt_log_ctx(struct glink_core_xprt_ctx *xprt);
/** /**
* glink_get_channel_id_for_handle() - Get logical channel ID * glink_get_channel_id_for_handle() - Get logical channel ID
* *

View file

@ -54,9 +54,9 @@ enum command_types {
*/ */
#define LEGACY_RCID_CHANNEL_OFFSET 128 #define LEGACY_RCID_CHANNEL_OFFSET 128
#define SMDXPRT_ERR(x...) GLINK_ERR("<SMDXPRT> " x) #define SMDXPRT_ERR(einfo, x...) GLINK_XPRT_IF_ERR(einfo->xprt_if, x)
#define SMDXPRT_INFO(x...) GLINK_INFO("<SMDXPRT> " x) #define SMDXPRT_INFO(einfo, x...) GLINK_XPRT_IF_INFO(einfo->xprt_if, x)
#define SMDXPRT_DBG(x...) GLINK_DBG("<SMDXPRT> " x) #define SMDXPRT_DBG(einfo, x...) GLINK_XPRT_IF_DBG(einfo->xprt_if, x)
/** /**
* struct edge_info() - local information for managing an edge * struct edge_info() - local information for managing an edge
@ -295,7 +295,8 @@ static void process_ctl_event(struct work_struct *work)
smd_read(einfo->smd_ch, &cmd, sizeof(cmd)); smd_read(einfo->smd_ch, &cmd, sizeof(cmd));
if (cmd.cmd == CMD_OPEN) { if (cmd.cmd == CMD_OPEN) {
smd_read(einfo->smd_ch, name, GLINK_NAME_SIZE); smd_read(einfo->smd_ch, name, GLINK_NAME_SIZE);
SMDXPRT_INFO("%s RX OPEN '%s'\n", __func__, name); SMDXPRT_INFO(einfo, "%s RX OPEN '%s'\n",
__func__, name);
spin_lock_irqsave(&einfo->channels_lock, flags); spin_lock_irqsave(&einfo->channels_lock, flags);
list_for_each_entry(ch, &einfo->channels, node) { list_for_each_entry(ch, &einfo->channels, node) {
@ -309,7 +310,8 @@ static void process_ctl_event(struct work_struct *work)
if (!found) { if (!found) {
ch = kzalloc(sizeof(*ch), GFP_KERNEL); ch = kzalloc(sizeof(*ch), GFP_KERNEL);
if (!ch) { if (!ch) {
SMDXPRT_ERR("%s: ch alloc failed\n", SMDXPRT_ERR(einfo,
"%s: ch alloc failed\n",
__func__); __func__);
continue; continue;
} }
@ -323,7 +325,8 @@ static void process_ctl_event(struct work_struct *work)
ch->wq = create_singlethread_workqueue( ch->wq = create_singlethread_workqueue(
ch->name); ch->name);
if (!ch->wq) { if (!ch->wq) {
SMDXPRT_ERR("%s: ch wq create failed\n", SMDXPRT_ERR(einfo,
"%s: ch wq create failed\n",
__func__); __func__);
kfree(ch); kfree(ch);
continue; continue;
@ -358,7 +361,7 @@ static void process_ctl_event(struct work_struct *work)
} }
if (ch->remote_legacy) { if (ch->remote_legacy) {
SMDXPRT_DBG("%s SMD Remote Open '%s'\n", SMDXPRT_DBG(einfo, "%s SMD Remote Open '%s'\n",
__func__, name); __func__, name);
cmd.cmd = CMD_OPEN_ACK; cmd.cmd = CMD_OPEN_ACK;
cmd.priority = SMD_TRANS_XPRT_ID; cmd.priority = SMD_TRANS_XPRT_ID;
@ -370,7 +373,8 @@ static void process_ctl_event(struct work_struct *work)
mutex_unlock(&einfo->smd_lock); mutex_unlock(&einfo->smd_lock);
continue; continue;
} else { } else {
SMDXPRT_DBG("%s G-Link Remote Open '%s'\n", SMDXPRT_DBG(einfo,
"%s G-Link Remote Open '%s'\n",
__func__, name); __func__, name);
} }
@ -381,7 +385,8 @@ static void process_ctl_event(struct work_struct *work)
name, name,
cmd.priority); cmd.priority);
} else if (cmd.cmd == CMD_OPEN_ACK) { } else if (cmd.cmd == CMD_OPEN_ACK) {
SMDXPRT_INFO("%s RX OPEN ACK lcid %u; xprt_req %u\n", SMDXPRT_INFO(einfo,
"%s RX OPEN ACK lcid %u; xprt_req %u\n",
__func__, cmd.id, cmd.priority); __func__, cmd.id, cmd.priority);
spin_lock_irqsave(&einfo->channels_lock, flags); spin_lock_irqsave(&einfo->channels_lock, flags);
@ -392,7 +397,7 @@ static void process_ctl_event(struct work_struct *work)
} }
spin_unlock_irqrestore(&einfo->channels_lock, flags); spin_unlock_irqrestore(&einfo->channels_lock, flags);
if (!found) { if (!found) {
GLINK_ERR("%s <SMDXPRT> No channel match %u\n", SMDXPRT_ERR(einfo, "%s No channel match %u\n",
__func__, cmd.id); __func__, cmd.id);
continue; continue;
} }
@ -403,8 +408,8 @@ static void process_ctl_event(struct work_struct *work)
cmd.id, cmd.id,
cmd.priority); cmd.priority);
} else if (cmd.cmd == CMD_CLOSE) { } else if (cmd.cmd == CMD_CLOSE) {
SMDXPRT_INFO("%s RX REMOTE CLOSE rcid %u\n", __func__, SMDXPRT_INFO(einfo, "%s RX REMOTE CLOSE rcid %u\n",
cmd.id); __func__, cmd.id);
spin_lock_irqsave(&einfo->channels_lock, flags); spin_lock_irqsave(&einfo->channels_lock, flags);
list_for_each_entry(ch, &einfo->channels, node) list_for_each_entry(ch, &einfo->channels, node)
if (cmd.id == ch->rcid) { if (cmd.id == ch->rcid) {
@ -414,7 +419,7 @@ static void process_ctl_event(struct work_struct *work)
spin_unlock_irqrestore(&einfo->channels_lock, flags); spin_unlock_irqrestore(&einfo->channels_lock, flags);
if (!found) if (!found)
GLINK_ERR("%s <SMDXPRT> no matching rcid %u\n", SMDXPRT_ERR(einfo, "%s no matching rcid %u\n",
__func__, cmd.id); __func__, cmd.id);
if (found && !ch->remote_legacy) { if (found && !ch->remote_legacy) {
@ -424,7 +429,8 @@ static void process_ctl_event(struct work_struct *work)
cmd.id); cmd.id);
} else { } else {
/* not found or a legacy channel */ /* not found or a legacy channel */
SMDXPRT_INFO("%s Sim RX CLOSE ACK lcid %u\n", SMDXPRT_INFO(einfo,
"%s Sim RX CLOSE ACK lcid %u\n",
__func__, cmd.id); __func__, cmd.id);
cmd.cmd = CMD_CLOSE_ACK; cmd.cmd = CMD_CLOSE_ACK;
mutex_lock(&einfo->smd_lock); mutex_lock(&einfo->smd_lock);
@ -437,8 +443,8 @@ static void process_ctl_event(struct work_struct *work)
} else if (cmd.cmd == CMD_CLOSE_ACK) { } else if (cmd.cmd == CMD_CLOSE_ACK) {
int rcu_id; int rcu_id;
SMDXPRT_INFO("%s RX CLOSE ACK lcid %u\n", __func__, SMDXPRT_INFO(einfo, "%s RX CLOSE ACK lcid %u\n",
cmd.id); __func__, cmd.id);
spin_lock_irqsave(&einfo->channels_lock, flags); spin_lock_irqsave(&einfo->channels_lock, flags);
list_for_each_entry(ch, &einfo->channels, node) { list_for_each_entry(ch, &einfo->channels, node) {
@ -449,7 +455,7 @@ static void process_ctl_event(struct work_struct *work)
} }
spin_unlock_irqrestore(&einfo->channels_lock, flags); spin_unlock_irqrestore(&einfo->channels_lock, flags);
if (!found) { if (!found) {
GLINK_ERR("%s <SMDXPRT> LCID not found %u\n", SMDXPRT_ERR(einfo, "%s LCID not found %u\n",
__func__, cmd.id); __func__, cmd.id);
continue; continue;
} }
@ -500,7 +506,8 @@ static int ctl_ch_probe(struct platform_device *pdev)
ret = smd_named_open_on_edge("GLINK_CTRL", einfo->smd_edge, ret = smd_named_open_on_edge("GLINK_CTRL", einfo->smd_edge,
&einfo->smd_ch, einfo, ctl_ch_notify); &einfo->smd_ch, einfo, ctl_ch_notify);
if (ret != 0) if (ret != 0)
SMDXPRT_ERR("%s Opening failed %d for %d:'GLINK_CTRL'\n", SMDXPRT_ERR(einfo,
"%s Opening failed %d for %d:'GLINK_CTRL'\n",
__func__, ret, einfo->smd_edge); __func__, ret, einfo->smd_edge);
return ret; return ret;
} }
@ -692,7 +699,7 @@ static void process_data_event(struct work_struct *work)
pkt_remaining = smd_cur_packet_size(ch->smd_ch); pkt_remaining = smd_cur_packet_size(ch->smd_ch);
else else
pkt_remaining = smd_read_avail(ch->smd_ch); pkt_remaining = smd_read_avail(ch->smd_ch);
GLINK_DBG("%s <SMDXPRT> Reading packet chunk %u '%s' %u:%u\n", SMDXPRT_DBG(einfo, "%s Reading packet chunk %u '%s' %u:%u\n",
__func__, pkt_remaining, ch->name, ch->lcid, __func__, pkt_remaining, ch->name, ch->lcid,
ch->rcid); ch->rcid);
if (!ch->cur_intent && !einfo->intentless) { if (!ch->cur_intent && !einfo->intentless) {
@ -709,8 +716,9 @@ static void process_data_event(struct work_struct *work)
if (!ch->cur_intent) { if (!ch->cur_intent) {
spin_unlock_irqrestore(&ch->rx_data_lock, spin_unlock_irqrestore(&ch->rx_data_lock,
rx_data_flags); rx_data_flags);
GLINK_DBG("%s %s Reqesting intent '%s' %u:%u\n", SMDXPRT_DBG(einfo,
__func__, "<SMDXPRT>", ch->name, "%s Reqesting intent '%s' %u:%u\n",
__func__, ch->name,
ch->lcid, ch->rcid); ch->lcid, ch->rcid);
ch->intent_req = true; ch->intent_req = true;
einfo->xprt_if.glink_core_if_ptr-> einfo->xprt_if.glink_core_if_ptr->
@ -733,8 +741,9 @@ static void process_data_event(struct work_struct *work)
if (!intent->data && einfo->intentless) { if (!intent->data && einfo->intentless) {
intent->data = kmalloc(pkt_remaining, GFP_ATOMIC); intent->data = kmalloc(pkt_remaining, GFP_ATOMIC);
if (!intent->data) { if (!intent->data) {
GLINK_DBG("%s %s kmalloc failed '%s' %u:%u\n", SMDXPRT_DBG(einfo,
__func__, "<SMDXPRT>", ch->name, "%s kmalloc failed '%s' %u:%u\n",
__func__, ch->name,
ch->lcid, ch->rcid); ch->lcid, ch->rcid);
continue; continue;
} }
@ -778,7 +787,8 @@ static void smd_data_ch_notify(void *priv, unsigned event)
case SMD_EVENT_OPEN: case SMD_EVENT_OPEN:
work = kmalloc(sizeof(*work), GFP_ATOMIC); work = kmalloc(sizeof(*work), GFP_ATOMIC);
if (!work) { if (!work) {
SMDXPRT_ERR("%s: unable to process event %d\n", SMDXPRT_ERR(ch->edge,
"%s: unable to process event %d\n",
__func__, SMD_EVENT_OPEN); __func__, SMD_EVENT_OPEN);
return; return;
} }
@ -789,7 +799,8 @@ static void smd_data_ch_notify(void *priv, unsigned event)
case SMD_EVENT_CLOSE: case SMD_EVENT_CLOSE:
work = kmalloc(sizeof(*work), GFP_ATOMIC); work = kmalloc(sizeof(*work), GFP_ATOMIC);
if (!work) { if (!work) {
SMDXPRT_ERR("%s: unable to process event %d\n", SMDXPRT_ERR(ch->edge,
"%s: unable to process event %d\n",
__func__, SMD_EVENT_CLOSE); __func__, SMD_EVENT_CLOSE);
return; return;
} }
@ -798,12 +809,14 @@ static void smd_data_ch_notify(void *priv, unsigned event)
queue_work(ch->wq, &work->work); queue_work(ch->wq, &work->work);
break; break;
case SMD_EVENT_STATUS: case SMD_EVENT_STATUS:
SMDXPRT_DBG("%s Processing STATUS for '%s' %u:%u\n", __func__, SMDXPRT_DBG(ch->edge,
ch->name, ch->lcid, ch->rcid); "%s Processing STATUS for '%s' %u:%u\n",
__func__, ch->name, ch->lcid, ch->rcid);
work = kmalloc(sizeof(*work), GFP_ATOMIC); work = kmalloc(sizeof(*work), GFP_ATOMIC);
if (!work) { if (!work) {
SMDXPRT_ERR("%s: unable to process event %d\n", SMDXPRT_ERR(ch->edge,
"%s: unable to process event %d\n",
__func__, SMD_EVENT_STATUS); __func__, SMD_EVENT_STATUS);
return; return;
} }
@ -814,7 +827,8 @@ static void smd_data_ch_notify(void *priv, unsigned event)
case SMD_EVENT_REOPEN_READY: case SMD_EVENT_REOPEN_READY:
work = kmalloc(sizeof(*work), GFP_ATOMIC); work = kmalloc(sizeof(*work), GFP_ATOMIC);
if (!work) { if (!work) {
SMDXPRT_ERR("%s: unable to process event %d\n", SMDXPRT_ERR(ch->edge,
"%s: unable to process event %d\n",
__func__, SMD_EVENT_REOPEN_READY); __func__, SMD_EVENT_REOPEN_READY);
return; return;
} }
@ -836,7 +850,8 @@ static void smd_data_ch_close(struct channel *ch)
struct intent_info *intent; struct intent_info *intent;
unsigned long flags; unsigned long flags;
SMDXPRT_INFO("%s Closing SMD channel lcid %u\n", __func__, ch->lcid); SMDXPRT_INFO(ch->edge, "%s Closing SMD channel lcid %u\n",
__func__, ch->lcid);
ch->is_closing = true; ch->is_closing = true;
ch->wait_for_probe = false; ch->wait_for_probe = false;
@ -877,13 +892,13 @@ static void data_ch_probe_body(struct channel *ch)
int ret; int ret;
einfo = ch->edge; einfo = ch->edge;
SMDXPRT_DBG("%s Opening SMD channel %d:'%s'\n", __func__, SMDXPRT_DBG(einfo, "%s Opening SMD channel %d:'%s'\n", __func__,
einfo->smd_edge, ch->name); einfo->smd_edge, ch->name);
ret = smd_named_open_on_edge(ch->name, einfo->smd_edge, &ch->smd_ch, ch, ret = smd_named_open_on_edge(ch->name, einfo->smd_edge, &ch->smd_ch, ch,
smd_data_ch_notify); smd_data_ch_notify);
if (ret != 0) { if (ret != 0) {
SMDXPRT_ERR("%s Opening failed %d for %d:'%s'\n", SMDXPRT_ERR(einfo, "%s Opening failed %d for %d:'%s'\n",
__func__, ret, einfo->smd_edge, ch->name); __func__, ret, einfo->smd_edge, ch->name);
return; return;
} }
@ -1120,7 +1135,8 @@ static int tx_cmd_ch_open(struct glink_transport_if *if_ptr, uint32_t lcid,
if (!found) { if (!found) {
ch = kzalloc(sizeof(*ch), GFP_KERNEL); ch = kzalloc(sizeof(*ch), GFP_KERNEL);
if (!ch) { if (!ch) {
SMDXPRT_ERR("%s: channel struct allocation failed\n", SMDXPRT_ERR(einfo,
"%s: channel struct allocation failed\n",
__func__); __func__);
srcu_read_unlock(&einfo->ssr_sync, rcu_id); srcu_read_unlock(&einfo->ssr_sync, rcu_id);
return -ENOMEM; return -ENOMEM;
@ -1134,7 +1150,8 @@ static int tx_cmd_ch_open(struct glink_transport_if *if_ptr, uint32_t lcid,
INIT_WORK(&ch->work, process_data_event); INIT_WORK(&ch->work, process_data_event);
ch->wq = create_singlethread_workqueue(ch->name); ch->wq = create_singlethread_workqueue(ch->name);
if (!ch->wq) { if (!ch->wq) {
SMDXPRT_ERR("%s: channel workqueue create failed\n", SMDXPRT_ERR(einfo,
"%s: channel workqueue create failed\n",
__func__); __func__);
kfree(ch); kfree(ch);
srcu_read_unlock(&einfo->ssr_sync, rcu_id); srcu_read_unlock(&einfo->ssr_sync, rcu_id);
@ -1169,8 +1186,8 @@ static int tx_cmd_ch_open(struct glink_transport_if *if_ptr, uint32_t lcid,
ch->lcid = lcid; ch->lcid = lcid;
if (einfo->smd_ctl_ch_open) { if (einfo->smd_ctl_ch_open) {
SMDXPRT_INFO("%s TX OPEN '%s' lcid %u reqxprt %u\n", __func__, SMDXPRT_INFO(einfo, "%s TX OPEN '%s' lcid %u reqxprt %u\n",
name, lcid, req_xprt); __func__, name, lcid, req_xprt);
cmd.cmd = CMD_OPEN; cmd.cmd = CMD_OPEN;
cmd.id = lcid; cmd.id = lcid;
cmd.priority = req_xprt; cmd.priority = req_xprt;
@ -1185,7 +1202,7 @@ static int tx_cmd_ch_open(struct glink_transport_if *if_ptr, uint32_t lcid,
smd_write_end(einfo->smd_ch); smd_write_end(einfo->smd_ch);
mutex_unlock(&einfo->smd_lock); mutex_unlock(&einfo->smd_lock);
} else { } else {
SMDXPRT_INFO("%s Legacy Open '%s' lcid %u reqxprt %u\n", SMDXPRT_INFO(einfo, "%s Legacy Open '%s' lcid %u reqxprt %u\n",
__func__, name, lcid, req_xprt); __func__, name, lcid, req_xprt);
ch->rcid = lcid + LEGACY_RCID_CHANNEL_OFFSET; ch->rcid = lcid + LEGACY_RCID_CHANNEL_OFFSET;
ch->local_legacy = true; ch->local_legacy = true;
@ -1239,13 +1256,14 @@ static int tx_cmd_ch_close(struct glink_transport_if *if_ptr, uint32_t lcid)
spin_unlock_irqrestore(&einfo->channels_lock, flags); spin_unlock_irqrestore(&einfo->channels_lock, flags);
if (!found) { if (!found) {
GLINK_ERR("%s <SMDXPRT> LCID not found %u\n", __func__, lcid); SMDXPRT_ERR(einfo, "%s LCID not found %u\n",
__func__, lcid);
srcu_read_unlock(&einfo->ssr_sync, rcu_id); srcu_read_unlock(&einfo->ssr_sync, rcu_id);
return -ENODEV; return -ENODEV;
} }
if (!ch->local_legacy) { if (!ch->local_legacy) {
SMDXPRT_INFO("%s TX CLOSE lcid %u\n", __func__, lcid); SMDXPRT_INFO(einfo, "%s TX CLOSE lcid %u\n", __func__, lcid);
cmd.cmd = CMD_CLOSE; cmd.cmd = CMD_CLOSE;
cmd.id = lcid; cmd.id = lcid;
cmd.reserved = 0; cmd.reserved = 0;
@ -1296,19 +1314,19 @@ static void tx_cmd_ch_remote_open_ack(struct glink_transport_if *if_ptr,
spin_unlock_irqrestore(&einfo->channels_lock, flags); spin_unlock_irqrestore(&einfo->channels_lock, flags);
if (!found) { if (!found) {
GLINK_ERR("%s <SMDXPRT> No matching SMD channel for rcid %u\n", SMDXPRT_ERR(einfo, "%s No matching SMD channel for rcid %u\n",
__func__, rcid); __func__, rcid);
return; return;
} }
if (ch->remote_legacy) { if (ch->remote_legacy) {
SMDXPRT_INFO("%s Legacy ch rcid %u xprt_resp %u\n", __func__, SMDXPRT_INFO(einfo, "%s Legacy ch rcid %u xprt_resp %u\n",
rcid, xprt_resp); __func__, rcid, xprt_resp);
return; return;
} }
SMDXPRT_INFO("%s TX OPEN ACK rcid %u xprt_resp %u\n", __func__, rcid, SMDXPRT_INFO(einfo, "%s TX OPEN ACK rcid %u xprt_resp %u\n",
xprt_resp); __func__, rcid, xprt_resp);
cmd.cmd = CMD_OPEN_ACK; cmd.cmd = CMD_OPEN_ACK;
cmd.id = ch->rcid; cmd.id = ch->rcid;
@ -1353,13 +1371,15 @@ static void tx_cmd_ch_remote_close_ack(struct glink_transport_if *if_ptr,
spin_unlock_irqrestore(&einfo->channels_lock, flags); spin_unlock_irqrestore(&einfo->channels_lock, flags);
if (!found) { if (!found) {
GLINK_ERR("%s <SMDXPRT> No matching SMD channel for rcid %u\n", SMDXPRT_ERR(einfo,
"%s No matching SMD channel for rcid %u\n",
__func__, rcid); __func__, rcid);
return; return;
} }
if (!ch->remote_legacy) { if (!ch->remote_legacy) {
SMDXPRT_INFO("%s TX CLOSE ACK rcid %u\n", __func__, rcid); SMDXPRT_INFO(einfo, "%s TX CLOSE ACK rcid %u\n",
__func__, rcid);
cmd.cmd = CMD_CLOSE_ACK; cmd.cmd = CMD_CLOSE_ACK;
cmd.id = rcid; cmd.id = rcid;
cmd.reserved = 0; cmd.reserved = 0;
@ -1522,7 +1542,7 @@ static int tx_cmd_local_rx_intent(struct glink_transport_if *if_ptr,
intent = kmalloc(sizeof(*intent), GFP_KERNEL); intent = kmalloc(sizeof(*intent), GFP_KERNEL);
if (!intent) { if (!intent) {
SMDXPRT_ERR("%s: no memory for intent\n", __func__); SMDXPRT_ERR(einfo, "%s: no memory for intent\n", __func__);
srcu_read_unlock(&einfo->ssr_sync, rcu_id); srcu_read_unlock(&einfo->ssr_sync, rcu_id);
return -ENOMEM; return -ENOMEM;
} }
@ -1643,8 +1663,8 @@ static int tx(struct glink_transport_if *if_ptr, uint32_t lcid,
rc = tx_size; rc = tx_size;
rc = smd_write_segment(ch->smd_ch, data_start, rc); rc = smd_write_segment(ch->smd_ch, data_start, rc);
if (rc < 0) { if (rc < 0) {
SMDXPRT_ERR("%s: write segment failed %d\n", __func__, SMDXPRT_ERR(einfo, "%s: write segment failed %d\n",
rc); __func__, rc);
srcu_read_unlock(&einfo->ssr_sync, rcu_id); srcu_read_unlock(&einfo->ssr_sync, rcu_id);
return rc; return rc;
} }
@ -1658,7 +1678,8 @@ static int tx(struct glink_transport_if *if_ptr, uint32_t lcid,
rc = tx_size; rc = tx_size;
rc = smd_write(ch->smd_ch, data_start, rc); rc = smd_write(ch->smd_ch, data_start, rc);
if (rc < 0) { if (rc < 0) {
SMDXPRT_ERR("%s: write failed %d\n", __func__, rc); SMDXPRT_ERR(einfo, "%s: write failed %d\n",
__func__, rc);
srcu_read_unlock(&einfo->ssr_sync, rcu_id); srcu_read_unlock(&einfo->ssr_sync, rcu_id);
return rc; return rc;
} }
@ -1923,10 +1944,9 @@ static int __init glink_smd_xprt_init(void)
rc = glink_core_register_transport(&einfo->xprt_if, rc = glink_core_register_transport(&einfo->xprt_if,
&einfo->xprt_cfg); &einfo->xprt_cfg);
if (rc) if (rc)
SMDXPRT_ERR("%s: %s glink register xprt failed %d\n", SMDXPRT_ERR(einfo,
__func__, "%s: %s glink register xprt failed %d\n",
einfo->xprt_cfg.edge, __func__, einfo->xprt_cfg.edge, rc);
rc);
else else
einfo->xprt_if.glink_core_if_ptr->link_up( einfo->xprt_if.glink_core_if_ptr->link_up(
&einfo->xprt_if); &einfo->xprt_if);