Merge "rpmsg: glink: Improve logging"

This commit is contained in:
qctecmdr 2022-08-31 14:19:06 -07:00 committed by Gerrit - the friendly Code Review server
commit e5d5d337b0

View File

@ -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;
@ -123,6 +145,7 @@ struct qcom_glink {
struct kthread_worker kworker;
struct task_struct *task;
struct cpumask cpu_mask;
struct work_struct rx_work;
spinlock_t rx_lock;
@ -140,6 +163,8 @@ struct qcom_glink {
bool intentless;
wait_queue_head_t tx_avail_notify;
bool sent_read_notify;
void *ilc;
};
enum {
@ -278,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);
@ -356,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);
@ -426,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);
}
@ -437,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);
}
@ -449,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);
}
@ -469,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");
}
/**
@ -504,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);
@ -517,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;
@ -534,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);
}
@ -546,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);
}
@ -577,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;
}
@ -646,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;
@ -673,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 */
@ -708,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;
@ -750,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;
@ -820,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);
@ -959,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 */
@ -1013,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);
@ -1088,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);
@ -1116,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;
@ -1249,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;
@ -1266,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 */
@ -1286,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);
@ -1301,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
@ -1343,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;
}
@ -1369,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;
@ -1405,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;
}
@ -1449,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;
@ -1457,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;
@ -1528,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;
@ -1550,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 */
@ -1571,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);
@ -1718,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);
@ -1745,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);
@ -1783,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;
@ -1945,6 +2030,22 @@ static int qcom_glink_create_chrdev(struct qcom_glink *glink)
return rpmsg_ctrldev_register_device(rpdev);
}
static void qcom_glink_set_affinity(struct qcom_glink *glink, u32 *arr,
size_t size)
{
int i;
cpumask_clear(&glink->cpu_mask);
for (i = 0; i < size; i++) {
if (arr[i] < num_possible_cpus())
cpumask_set_cpu(arr[i], &glink->cpu_mask);
}
if (irq_set_affinity_hint(glink->irq, &glink->cpu_mask))
dev_err(glink->dev, "failed to set irq affinity\n");
if (set_cpus_allowed_ptr(glink->task, &glink->cpu_mask))
dev_err(glink->dev, "failed to set task affinity\n");
}
struct qcom_glink *qcom_glink_native_probe(struct device *dev,
unsigned long features,
struct qcom_glink_pipe *rx,
@ -2006,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);
@ -2013,6 +2116,8 @@ EXPORT_SYMBOL(qcom_glink_native_probe);
int qcom_glink_native_start(struct qcom_glink *glink)
{
struct device *dev = glink->dev;
u32 *arr;
int size;
int irq;
int ret;
@ -2026,15 +2131,29 @@ 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;
}
glink->irq = irq;
size = of_property_count_u32_elems(dev->of_node, "cpu-affinity");
if (size > 0) {
arr = kmalloc_array(size, sizeof(u32), GFP_KERNEL);
if (!arr)
return -ENOMEM;
ret = of_property_read_u32_array(dev->of_node, "cpu-affinity",
arr, size);
if (!ret)
qcom_glink_set_affinity(glink, arr, size);
kfree(arr);
}
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)