From 245c259be835bdba74cb42063794b626f0055dc4 Mon Sep 17 00:00:00 2001 From: Chris Lew Date: Wed, 29 Aug 2018 17:53:41 -0700 Subject: [PATCH 1/2] rpmsg: glink: Add option to affine resources to CPUs On certain systems, all resources for a specific usecase may be pinned to a specific cpu set to meet power and performance requirements. Add support to define a cpu set for the irq and rx thread in device tree. This change does not include any hotplug support. Change-Id: I0e18e3cb1880886dddf20ce0e2744e7af3b8b553 Signed-off-by: Chris Lew --- drivers/rpmsg/qcom_glink_native.c | 31 +++++++++++++++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/drivers/rpmsg/qcom_glink_native.c b/drivers/rpmsg/qcom_glink_native.c index 7fcf996db7b9..1fd6c7244db9 100644 --- a/drivers/rpmsg/qcom_glink_native.c +++ b/drivers/rpmsg/qcom_glink_native.c @@ -123,6 +123,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; @@ -1945,6 +1946,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, @@ -2013,6 +2030,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; @@ -2032,6 +2051,18 @@ int qcom_glink_native_start(struct qcom_glink *glink) 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) return ret; From a924179aa49878f02f03546336953c6698f2facf Mon Sep 17 00:00:00 2001 From: Chris Lew Date: Tue, 2 Aug 2022 13:30:06 -0700 Subject: [PATCH 2/2] 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 --- drivers/rpmsg/qcom_glink_native.c | 96 +++++++++++++++++++++++++++++-- 1 file changed, 92 insertions(+), 4 deletions(-) diff --git a/drivers/rpmsg/qcom_glink_native.c b/drivers/rpmsg/qcom_glink_native.c index 1fd6c7244db9..421db65c0f0f 100644 --- a/drivers/rpmsg/qcom_glink_native.c +++ b/drivers/rpmsg/qcom_glink_native.c @@ -22,10 +22,31 @@ #include #include #include +#include #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)