mirror of
https://github.com/torvalds/linux.git
synced 2026-07-31 19:47:08 +02:00
rpmsg: glink: Improve logging
Add IPC logs and update some device prints to return error codes and more context about the error. This will facilitate debugging. Change-Id: Iab4b1bc008a20f717f7599d3e49aa8ee00376ae0 Signed-off-by: Chris Lew <quic_clew@quicinc.com>
This commit is contained in:
Chris Lew
Gerrit - the friendly Code Review server
parent
245c259be8
commit
a924179aa4
|
|
@ -22,10 +22,31 @@
|
|||
#include <linux/kthread.h>
|
||||
#include <linux/mailbox_client.h>
|
||||
#include <linux/suspend.h>
|
||||
#include <linux/ipc_logging.h>
|
||||
|
||||
#include "rpmsg_internal.h"
|
||||
#include "qcom_glink_native.h"
|
||||
|
||||
#define GLINK_LOG_PAGE_CNT 2
|
||||
#define GLINK_INFO(ctxt, x, ...) \
|
||||
ipc_log_string(ctxt, "[%s]: "x, __func__, ##__VA_ARGS__)
|
||||
|
||||
#define CH_INFO(ch, x, ...) \
|
||||
do { \
|
||||
if (ch->glink) \
|
||||
ipc_log_string(ch->glink->ilc, "%s[%d:%d] %s: "x, ch->name, \
|
||||
ch->lcid, ch->rcid, __func__, ##__VA_ARGS__); \
|
||||
} while (0)
|
||||
|
||||
#define CH_ERR(ch, x, ...) \
|
||||
do { \
|
||||
if (ch->glink) { \
|
||||
ipc_log_string(ch->glink->ilc, "%s[%d:%d] %s: "x, ch->name, \
|
||||
ch->lcid, ch->rcid, __func__, ##__VA_ARGS__); \
|
||||
dev_err_ratelimited(ch->glink->dev, "[%s]: "x, __func__, ##__VA_ARGS__); \
|
||||
} \
|
||||
} while (0)
|
||||
|
||||
#define GLINK_NAME_SIZE 32
|
||||
#define GLINK_VERSION_1 1
|
||||
|
||||
|
|
@ -104,6 +125,7 @@ struct glink_core_rx_intent {
|
|||
* @intentless: flag to indicate that there is no intent
|
||||
* @tx_avail_notify: Waitqueue for pending tx tasks
|
||||
* @sent_read_notify: flag to check cmd sent or not
|
||||
* @ilc: ipc logging context reference
|
||||
*/
|
||||
struct qcom_glink {
|
||||
struct device *dev;
|
||||
|
|
@ -141,6 +163,8 @@ struct qcom_glink {
|
|||
bool intentless;
|
||||
wait_queue_head_t tx_avail_notify;
|
||||
bool sent_read_notify;
|
||||
|
||||
void *ilc;
|
||||
};
|
||||
|
||||
enum {
|
||||
|
|
@ -279,6 +303,7 @@ static void qcom_glink_channel_release(struct kref *ref)
|
|||
unsigned long flags;
|
||||
int iid;
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
channel->intent_req_result = false;
|
||||
atomic_inc(&channel->intent_req_acked);
|
||||
wake_up(&channel->intent_req_ack);
|
||||
|
|
@ -357,6 +382,8 @@ static void qcom_glink_send_read_notify(struct qcom_glink *glink)
|
|||
msg.param1 = 0;
|
||||
msg.param2 = 0;
|
||||
|
||||
GLINK_INFO(glink->ilc, "send READ NOTIFY cmd\n");
|
||||
|
||||
qcom_glink_tx_write(glink, &msg, sizeof(msg), NULL, 0);
|
||||
|
||||
mbox_send_message(glink->mbox_chan, NULL);
|
||||
|
|
@ -427,6 +454,7 @@ static int qcom_glink_send_version(struct qcom_glink *glink)
|
|||
msg.param1 = cpu_to_le16(GLINK_VERSION_1);
|
||||
msg.param2 = cpu_to_le32(glink->features);
|
||||
|
||||
GLINK_INFO(glink->ilc, "vers:%d features:%d\n", msg.param1, msg.param2);
|
||||
return qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
|
||||
}
|
||||
|
||||
|
|
@ -438,6 +466,7 @@ static void qcom_glink_send_version_ack(struct qcom_glink *glink)
|
|||
msg.param1 = cpu_to_le16(GLINK_VERSION_1);
|
||||
msg.param2 = cpu_to_le32(glink->features);
|
||||
|
||||
GLINK_INFO(glink->ilc, "vers:%d features:%d\n", msg.param1, msg.param2);
|
||||
qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
|
||||
}
|
||||
|
||||
|
|
@ -450,6 +479,7 @@ static void qcom_glink_send_open_ack(struct qcom_glink *glink,
|
|||
msg.param1 = cpu_to_le16(channel->rcid);
|
||||
msg.param2 = cpu_to_le32(0);
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
|
||||
}
|
||||
|
||||
|
|
@ -470,6 +500,7 @@ static void qcom_glink_handle_intent_req_ack(struct qcom_glink *glink,
|
|||
channel->intent_req_result = granted;
|
||||
atomic_inc(&channel->intent_req_acked);
|
||||
wake_up(&channel->intent_req_ack);
|
||||
CH_INFO(channel, "\n");
|
||||
}
|
||||
|
||||
/**
|
||||
|
|
@ -505,6 +536,7 @@ static int qcom_glink_send_open_req(struct qcom_glink *glink,
|
|||
return ret;
|
||||
|
||||
channel->lcid = ret;
|
||||
CH_INFO(channel, "\n");
|
||||
|
||||
req.msg.cmd = cpu_to_le16(RPM_CMD_OPEN);
|
||||
req.msg.param1 = cpu_to_le16(channel->lcid);
|
||||
|
|
@ -518,6 +550,8 @@ static int qcom_glink_send_open_req(struct qcom_glink *glink,
|
|||
return 0;
|
||||
|
||||
remove_idr:
|
||||
CH_INFO(channel, "remote_idr\n");
|
||||
|
||||
spin_lock_irqsave(&glink->idr_lock, flags);
|
||||
idr_remove(&glink->lcids, channel->lcid);
|
||||
channel->lcid = 0;
|
||||
|
|
@ -535,6 +569,7 @@ static void qcom_glink_send_close_req(struct qcom_glink *glink,
|
|||
req.param1 = cpu_to_le16(channel->lcid);
|
||||
req.param2 = 0;
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
qcom_glink_tx(glink, &req, sizeof(req), NULL, 0, true);
|
||||
}
|
||||
|
||||
|
|
@ -547,6 +582,7 @@ static void qcom_glink_send_close_ack(struct qcom_glink *glink,
|
|||
req.param1 = cpu_to_le16(rcid);
|
||||
req.param2 = 0;
|
||||
|
||||
GLINK_INFO(glink->ilc, "rcid:%d\n", rcid);
|
||||
qcom_glink_tx(glink, &req, sizeof(req), NULL, 0, true);
|
||||
}
|
||||
|
||||
|
|
@ -578,6 +614,7 @@ static int __qcom_glink_rx_done(struct qcom_glink *glink,
|
|||
kfree(intent);
|
||||
}
|
||||
|
||||
CH_INFO(channel, "reuse:%d liid:%d", reuse, iid);
|
||||
return 0;
|
||||
}
|
||||
|
||||
|
|
@ -647,6 +684,8 @@ static void qcom_glink_receive_version(struct qcom_glink *glink,
|
|||
u32 version,
|
||||
u32 features)
|
||||
{
|
||||
GLINK_INFO(glink->ilc, "vers:%d features:%d\n", version, features);
|
||||
|
||||
switch (version) {
|
||||
case 0:
|
||||
break;
|
||||
|
|
@ -674,6 +713,8 @@ static void qcom_glink_receive_version_ack(struct qcom_glink *glink,
|
|||
u32 version,
|
||||
u32 features)
|
||||
{
|
||||
GLINK_INFO(glink->ilc, "vers:%d features:%d\n", version, features);
|
||||
|
||||
switch (version) {
|
||||
case 0:
|
||||
/* Version negotiation failed */
|
||||
|
|
@ -709,6 +750,7 @@ static int qcom_glink_send_intent_req_ack(struct qcom_glink *glink,
|
|||
msg.param1 = cpu_to_le16(channel->lcid);
|
||||
msg.param2 = cpu_to_le32(granted);
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
|
||||
|
||||
return 0;
|
||||
|
|
@ -751,6 +793,9 @@ static int qcom_glink_advertise_intent(struct qcom_glink *glink,
|
|||
cmd.size = cpu_to_le32(intent->size);
|
||||
cmd.liid = cpu_to_le32(intent->id);
|
||||
|
||||
CH_INFO(channel, "count:%d size:%zd liid:%d\n", 1,
|
||||
intent->size, intent->id);
|
||||
|
||||
qcom_glink_tx(glink, &cmd, sizeof(cmd), NULL, 0, true);
|
||||
|
||||
return 0;
|
||||
|
|
@ -821,6 +866,7 @@ static void qcom_glink_handle_rx_done(struct qcom_glink *glink,
|
|||
}
|
||||
|
||||
intent->in_use = false;
|
||||
CH_INFO(channel, "reuse:%d iid:%d\n", reuse, intent->id);
|
||||
|
||||
if (!reuse) {
|
||||
idr_remove(&channel->riids, intent->id);
|
||||
|
|
@ -960,6 +1006,7 @@ static int qcom_glink_rx_data(struct qcom_glink *glink, size_t avail)
|
|||
/* Drop the message */
|
||||
goto advance_rx;
|
||||
}
|
||||
CH_INFO(channel, "chunk_size:%d left_size:%d\n", chunk_size, left_size);
|
||||
|
||||
if (glink->intentless) {
|
||||
/* Might have an ongoing, fragmented, message to append */
|
||||
|
|
@ -1014,11 +1061,19 @@ static int qcom_glink_rx_data(struct qcom_glink *glink, size_t avail)
|
|||
if (!left_size) {
|
||||
spin_lock(&channel->recv_lock);
|
||||
if (channel->ept.cb) {
|
||||
channel->ept.cb(channel->ept.rpdev,
|
||||
ret = channel->ept.cb(channel->ept.rpdev,
|
||||
intent->data,
|
||||
intent->offset,
|
||||
channel->ept.priv,
|
||||
RPMSG_ADDR_ANY);
|
||||
|
||||
if (ret < 0 && ret != -ENODEV) {
|
||||
CH_ERR(channel,
|
||||
"callback error ret = %d\n", ret);
|
||||
ret = 0;
|
||||
}
|
||||
} else {
|
||||
CH_ERR(channel, "callback not present\n");
|
||||
}
|
||||
spin_unlock(&channel->recv_lock);
|
||||
|
||||
|
|
@ -1089,6 +1144,9 @@ static void qcom_glink_handle_intent(struct qcom_glink *glink,
|
|||
intent->id = le32_to_cpu(msg->intents[i].iid);
|
||||
intent->size = le32_to_cpu(msg->intents[i].size);
|
||||
|
||||
CH_INFO(channel, "riid:%d size:%zd\n",
|
||||
intent->id, intent->size);
|
||||
|
||||
spin_lock_irqsave(&channel->intent_lock, flags);
|
||||
ret = idr_alloc(&channel->riids, intent,
|
||||
intent->id, intent->id + 1, GFP_ATOMIC);
|
||||
|
|
@ -1117,6 +1175,7 @@ static int qcom_glink_rx_open_ack(struct qcom_glink *glink, unsigned int lcid)
|
|||
return -EINVAL;
|
||||
}
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
complete_all(&channel->open_ack);
|
||||
|
||||
return 0;
|
||||
|
|
@ -1250,6 +1309,7 @@ static struct glink_channel *qcom_glink_create_local(struct qcom_glink *glink,
|
|||
if (IS_ERR(channel))
|
||||
return ERR_CAST(channel);
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
ret = qcom_glink_send_open_req(glink, channel);
|
||||
if (ret)
|
||||
goto release_channel;
|
||||
|
|
@ -1267,12 +1327,15 @@ static struct glink_channel *qcom_glink_create_local(struct qcom_glink *glink,
|
|||
return channel;
|
||||
|
||||
err_timeout:
|
||||
CH_INFO(channel, "err_timeout\n");
|
||||
|
||||
/* qcom_glink_send_open_req() did register the channel in lcids*/
|
||||
spin_lock_irqsave(&glink->idr_lock, flags);
|
||||
idr_remove(&glink->lcids, channel->lcid);
|
||||
spin_unlock_irqrestore(&glink->idr_lock, flags);
|
||||
|
||||
release_channel:
|
||||
CH_INFO(channel, "release_channel\n");
|
||||
/* Release qcom_glink_send_open_req() reference */
|
||||
kref_put(&channel->refcount, qcom_glink_channel_release);
|
||||
/* Release qcom_glink_alloc_channel() reference */
|
||||
|
|
@ -1287,6 +1350,8 @@ static int qcom_glink_create_remote(struct qcom_glink *glink,
|
|||
{
|
||||
int ret;
|
||||
|
||||
CH_INFO(channel, "\n");
|
||||
|
||||
qcom_glink_send_open_ack(glink, channel);
|
||||
|
||||
ret = qcom_glink_send_open_req(glink, channel);
|
||||
|
|
@ -1302,6 +1367,8 @@ static int qcom_glink_create_remote(struct qcom_glink *glink,
|
|||
return 0;
|
||||
|
||||
close_link:
|
||||
CH_INFO(channel, "close_link %d\n", ret);
|
||||
|
||||
/*
|
||||
* Send a close request to "undo" our open-ack. The close-ack will
|
||||
* release qcom_glink_send_open_req() reference and the last reference
|
||||
|
|
@ -1344,12 +1411,14 @@ static struct rpmsg_endpoint *qcom_glink_create_ept(struct rpmsg_device *rpdev,
|
|||
if (ret)
|
||||
return NULL;
|
||||
}
|
||||
CH_INFO(channel, "Initializing ept\n");
|
||||
|
||||
ept = &channel->ept;
|
||||
ept->rpdev = rpdev;
|
||||
ept->cb = cb;
|
||||
ept->priv = priv;
|
||||
ept->ops = &glink_endpoint_ops;
|
||||
CH_INFO(channel, "Initialized ept\n");
|
||||
|
||||
return ept;
|
||||
}
|
||||
|
|
@ -1370,6 +1439,7 @@ static int qcom_glink_announce_create(struct rpmsg_device *rpdev)
|
|||
int iid;
|
||||
int size;
|
||||
|
||||
CH_INFO(channel, "Entered\n");
|
||||
if (glink->intentless || !completion_done(&channel->open_ack))
|
||||
return 0;
|
||||
|
||||
|
|
@ -1406,6 +1476,7 @@ static int qcom_glink_announce_create(struct rpmsg_device *rpdev)
|
|||
qcom_glink_advertise_intent(glink, channel, intent);
|
||||
}
|
||||
}
|
||||
CH_INFO(channel, "Exit\n");
|
||||
return 0;
|
||||
}
|
||||
|
||||
|
|
@ -1450,6 +1521,8 @@ static int qcom_glink_request_intent(struct qcom_glink *glink,
|
|||
cmd.cid = channel->lcid;
|
||||
cmd.size = size;
|
||||
|
||||
CH_INFO(channel, "size:%zd\n", size);
|
||||
|
||||
ret = qcom_glink_tx(glink, &cmd, sizeof(cmd), NULL, 0, true);
|
||||
if (ret)
|
||||
goto unlock;
|
||||
|
|
@ -1458,9 +1531,10 @@ static int qcom_glink_request_intent(struct qcom_glink *glink,
|
|||
atomic_read(&channel->intent_req_acked) ||
|
||||
atomic_read(&glink->in_reset), 10 * HZ);
|
||||
if (!ret) {
|
||||
dev_err(glink->dev, "intent request ack timed out\n");
|
||||
dev_err(glink->dev, "%s: intent request ack timed out\n", channel->name);
|
||||
ret = -ETIMEDOUT;
|
||||
} else if (atomic_read(&glink->in_reset)) {
|
||||
CH_INFO(channel, "ssr detected\n");
|
||||
ret = -ECONNRESET;
|
||||
} else {
|
||||
ret = channel->intent_req_result ? 0 : -ECANCELED;
|
||||
|
|
@ -1529,6 +1603,7 @@ static int __qcom_glink_send(struct glink_channel *channel,
|
|||
"intent request completion timed out\n");
|
||||
ret = -ETIMEDOUT;
|
||||
} else if (atomic_read(&glink->in_reset)) {
|
||||
CH_INFO(channel, "ssr detected\n");
|
||||
ret = -ECONNRESET;
|
||||
} else {
|
||||
ret = channel->intent_req_result ? 0 : -ECANCELED;
|
||||
|
|
@ -1551,6 +1626,8 @@ static int __qcom_glink_send(struct glink_channel *channel,
|
|||
req.chunk_size = cpu_to_le32(chunk_size);
|
||||
req.left_size = cpu_to_le32(left_size);
|
||||
|
||||
CH_INFO(channel, "iid:%d chunk_size:%d left_size:%d\n", iid,
|
||||
chunk_size, left_size);
|
||||
ret = qcom_glink_tx(glink, &req, sizeof(req), data, chunk_size, wait);
|
||||
|
||||
/* Mark intent available if we failed */
|
||||
|
|
@ -1572,6 +1649,8 @@ static int __qcom_glink_send(struct glink_channel *channel,
|
|||
req.chunk_size = cpu_to_le32(chunk_size);
|
||||
req.left_size = cpu_to_le32(left_size);
|
||||
|
||||
CH_INFO(channel, "iid:%d chunk_size:%d left_size:%d\n", iid,
|
||||
chunk_size, left_size);
|
||||
ret = qcom_glink_tx(glink, &req, sizeof(req), data,
|
||||
chunk_size, wait);
|
||||
|
||||
|
|
@ -1719,15 +1798,18 @@ static int qcom_glink_rx_open(struct qcom_glink *glink, unsigned int rcid,
|
|||
|
||||
channel->rpdev = rpdev;
|
||||
}
|
||||
CH_INFO(channel, "\n");
|
||||
|
||||
return 0;
|
||||
|
||||
rcid_remove:
|
||||
CH_INFO(channel, "rcid_remove\n");
|
||||
spin_lock_irqsave(&glink->idr_lock, flags);
|
||||
idr_remove(&glink->rcids, channel->rcid);
|
||||
channel->rcid = 0;
|
||||
spin_unlock_irqrestore(&glink->idr_lock, flags);
|
||||
free_channel:
|
||||
CH_INFO(channel, "free_channel\n");
|
||||
/* Release the reference, iff we took it */
|
||||
if (create_device)
|
||||
kref_put(&channel->refcount, qcom_glink_channel_release);
|
||||
|
|
@ -1746,6 +1828,7 @@ static void qcom_glink_rx_close(struct qcom_glink *glink, unsigned int rcid)
|
|||
spin_unlock_irqrestore(&glink->idr_lock, flags);
|
||||
if (WARN(!channel, "close request on unknown channel\n"))
|
||||
return;
|
||||
CH_INFO(channel, "\n");
|
||||
|
||||
/* cancel pending rx_done work */
|
||||
kthread_cancel_work_sync(&channel->intent_work);
|
||||
|
|
@ -1784,6 +1867,7 @@ static void qcom_glink_rx_close_ack(struct qcom_glink *glink, unsigned int lcid)
|
|||
spin_unlock_irqrestore(&glink->idr_lock, flags);
|
||||
return;
|
||||
}
|
||||
CH_INFO(channel, "\n");
|
||||
|
||||
idr_remove(&glink->lcids, channel->lcid);
|
||||
channel->lcid = 0;
|
||||
|
|
@ -2023,6 +2107,8 @@ struct qcom_glink *qcom_glink_native_probe(struct device *dev,
|
|||
|
||||
scnprintf(glink->irqname, 32, "glink-native-%s", glink->name);
|
||||
|
||||
glink->ilc = ipc_log_context_create(GLINK_LOG_PAGE_CNT, glink->name, 0);
|
||||
|
||||
return glink;
|
||||
}
|
||||
EXPORT_SYMBOL(qcom_glink_native_probe);
|
||||
|
|
@ -2045,7 +2131,7 @@ int qcom_glink_native_start(struct qcom_glink *glink)
|
|||
IRQF_NO_SUSPEND | IRQF_ONESHOT,
|
||||
glink->irqname, glink);
|
||||
if (ret) {
|
||||
dev_err(dev, "failed to request IRQ\n");
|
||||
dev_err(dev, "failed to request IRQ with %d\n", ret);
|
||||
return ret;
|
||||
}
|
||||
|
||||
|
|
@ -2064,8 +2150,10 @@ int qcom_glink_native_start(struct qcom_glink *glink)
|
|||
}
|
||||
|
||||
ret = qcom_glink_send_version(glink);
|
||||
if (ret)
|
||||
if (ret) {
|
||||
dev_err(glink->dev, "failed to send version: %d\n", ret);
|
||||
return ret;
|
||||
}
|
||||
|
||||
ret = qcom_glink_create_chrdev(glink);
|
||||
if (ret)
|
||||
|
|
|
|||
Loading…
Reference in New Issue
Block a user