* [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk
@ 2023-10-19 8:21 Umang Jain
2023-10-19 8:21 ` [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
` (4 more replies)
0 siblings, 5 replies; 10+ messages in thread
From: Umang Jain @ 2023-10-19 8:21 UTC (permalink / raw)
To: linux-staging, linux-rpi-kernel, linux-media, linux-arm-kernel
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Kieran Bingham, Laurent Pinchart, Umang Jain
Hello,
This series address the discussion on [1], i.e. removing the printk
based logging mechanism and migrate it use dynamic debug.
Patch 1/4 targets migration of vchiq_log_error().
Patch 2/4 targets migration of vchiq_log_warning().
... and so on.
This series does not touch debugfs entries which are:
DEBUG_INITIALISE, DEBUG_TRACE, DEBUG_VALUE and DEBUG_COUNT. As far as I
understand from the previous discussions, those too should be moved
to use dynamic debug as well (but is not part of this series yet), as
I found there are more moving parts involved. I will build a series on
top of this one, to move the debugfs entries to dynamic debug and remove
all custom logging remanants (like VCHIQ_LOG_* macros, *_log_levels externs)
because they do still tie into vchiq_debugfs.c.
[1] https://lore.kernel.org/linux-media/20230913185528.770634-1-umang.jain@ideasonboard.com/
Umang Jain (4):
staging: vc04: Convert vchiq_log_error() to use dynamic debug
staging: vc04: Convert vchiq_log_warning() to use dynamic debug
staging: vc04: Convert(and rename) vchiq_log_info() to use dynamic
debug
staging: vc04: Convert vchiq_log_trace() to use dynamic debug
.../interface/vchiq_arm/vchiq_arm.c | 143 ++++----
.../interface/vchiq_arm/vchiq_connected.c | 2 +-
.../interface/vchiq_arm/vchiq_core.c | 329 +++++++++---------
.../interface/vchiq_arm/vchiq_core.h | 53 ++-
.../interface/vchiq_arm/vchiq_dev.c | 59 ++--
5 files changed, 307 insertions(+), 279 deletions(-)
--
2.40.1
^ permalink raw reply [flat|nested] 10+ messages in thread
* [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug
2023-10-19 8:21 [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Umang Jain
@ 2023-10-19 8:21 ` Umang Jain
2023-10-19 13:32 ` Kieran Bingham
2023-10-21 9:59 ` Greg Kroah-Hartman
2023-10-19 8:21 ` [PATCH v1 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
` (3 subsequent siblings)
4 siblings, 2 replies; 10+ messages in thread
From: Umang Jain @ 2023-10-19 8:21 UTC (permalink / raw)
To: linux-staging, linux-rpi-kernel, linux-media, linux-arm-kernel
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Kieran Bingham, Laurent Pinchart, Umang Jain
Move vchiq_log_error() custom logging wrapper based on printk,
to use dynamic debug. To categorise, enum vchiq_log_category
has been introduced, which will become the part of the error
string format that will be logged to dynamic debug (for grep).
All the vchiq_log_error() calls are adjusted to use the
dynamic debug wrapper. vchiq_loud_error_*() has been removed
as a part of this patch and replaced with dev_err (so that
they directly end up in kernel log, even if dynamic debug
isn't enabled), which serves the purpose.
For cases where struct device pointer `dev` is not available,
NULL can be passed to vchiq_log_error() to log to dynamic debug
using pr_debug().
Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
.../interface/vchiq_arm/vchiq_arm.c | 36 ++++---
.../interface/vchiq_arm/vchiq_connected.c | 2 +-
.../interface/vchiq_arm/vchiq_core.c | 100 +++++++-----------
.../interface/vchiq_arm/vchiq_core.h | 33 ++++--
.../interface/vchiq_arm/vchiq_dev.c | 14 +--
5 files changed, 91 insertions(+), 94 deletions(-)
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
index eef9c8c06e66..fa4463bfc117 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -690,7 +690,8 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
usleep_range(500, 600);
}
if (i == VCHIQ_INIT_RETRIES) {
- vchiq_log_error(vchiq_core_log_level, "%s: videocore not initialized\n", __func__);
+ vchiq_log_error(state->dev, VCHIQ_CORE, "%s: videocore not initialized\n",
+ __func__);
ret = -ENOTCONN;
goto failed;
} else if (i > 0) {
@@ -700,7 +701,7 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
instance = kzalloc(sizeof(*instance), GFP_KERNEL);
if (!instance) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"%s: error allocating vchiq instance\n", __func__);
ret = -ENOMEM;
goto failed;
@@ -966,7 +967,8 @@ vchiq_blocking_bulk_transfer(struct vchiq_instance *instance, unsigned int handl
} else {
waiter = kzalloc(sizeof(*waiter), GFP_KERNEL);
if (!waiter) {
- vchiq_log_error(vchiq_core_log_level, "%s - out of memory", __func__);
+ vchiq_log_error(service->state->dev, VCHIQ_CORE,
+ "%s - out of memory", __func__);
return -ENOMEM;
}
}
@@ -1333,7 +1335,8 @@ vchiq_keepalive_vchiq_callback(struct vchiq_instance *instance,
struct vchiq_header *header,
unsigned int service_user, void *bulk_user)
{
- vchiq_log_error(vchiq_susp_log_level, "%s callback reason %d", __func__, reason);
+ vchiq_log_error(instance->state->dev, VCHIQ_SUSPEND,
+ "%s callback reason %d", __func__, reason);
return 0;
}
@@ -1357,22 +1360,22 @@ vchiq_keepalive_thread_func(void *v)
ret = vchiq_initialise(&instance);
if (ret) {
- vchiq_log_error(vchiq_susp_log_level, "%s vchiq_initialise failed %d", __func__,
- ret);
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
+ "%s vchiq_initialise failed %d", __func__, ret);
goto exit;
}
status = vchiq_connect(instance);
if (status) {
- vchiq_log_error(vchiq_susp_log_level, "%s vchiq_connect failed %d", __func__,
- status);
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
+ "%s vchiq_connect failed %d", __func__, status);
goto shutdown;
}
status = vchiq_add_service(instance, ¶ms, &ka_handle);
if (status) {
- vchiq_log_error(vchiq_susp_log_level, "%s vchiq_open_service failed %d", __func__,
- status);
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
+ "%s vchiq_open_service failed %d", __func__, status);
goto shutdown;
}
@@ -1380,7 +1383,8 @@ vchiq_keepalive_thread_func(void *v)
long rc = 0, uc = 0;
if (wait_for_completion_interruptible(&arm_state->ka_evt)) {
- vchiq_log_error(vchiq_susp_log_level, "%s interrupted", __func__);
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
+ "%s interrupted", __func__);
flush_signals(current);
continue;
}
@@ -1400,14 +1404,14 @@ vchiq_keepalive_thread_func(void *v)
atomic_inc(&arm_state->ka_use_ack_count);
status = vchiq_use_service(instance, ka_handle);
if (status) {
- vchiq_log_error(vchiq_susp_log_level,
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
"%s vchiq_use_service error %d", __func__, status);
}
}
while (rc--) {
status = vchiq_release_service(instance, ka_handle);
if (status) {
- vchiq_log_error(vchiq_susp_log_level,
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
"%s vchiq_release_service error %d", __func__,
status);
}
@@ -1444,7 +1448,7 @@ vchiq_use_internal(struct vchiq_state *state, struct vchiq_service *service,
service->client_id);
entity_uc = &service->service_use_count;
} else {
- vchiq_log_error(vchiq_susp_log_level, "%s null service ptr", __func__);
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND, "%s null service ptr", __func__);
ret = -EINVAL;
goto out;
}
@@ -1725,7 +1729,7 @@ vchiq_check_service(struct vchiq_service *service)
read_unlock_bh(&arm_state->susp_res_lock);
if (ret) {
- vchiq_log_error(vchiq_susp_log_level,
+ vchiq_log_error(service->state->dev, VCHIQ_SUSPEND,
"%s ERROR - %c%c%c%c:%d service count %d, state count %d", __func__,
VCHIQ_FOURCC_AS_4CHARS(service->base.fourcc), service->client_id,
service->service_use_count, arm_state->videocore_use_count);
@@ -1761,7 +1765,7 @@ void vchiq_platform_conn_state_changed(struct vchiq_state *state,
(void *)state,
threadname);
if (IS_ERR(arm_state->ka_thread)) {
- vchiq_log_error(vchiq_susp_log_level,
+ vchiq_log_error(state->dev, VCHIQ_SUSPEND,
"vchiq: FATAL: couldn't create thread %s",
threadname);
} else {
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
index bdb0ab617d8b..b3928bd8c9c6 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
@@ -39,7 +39,7 @@ void vchiq_add_connected_callback(void (*callback)(void))
callback();
} else {
if (g_num_deferred_callbacks >= MAX_CALLBACKS) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(NULL, VCHIQ_CORE,
"There already %d callback registered - please increase MAX_CALLBACKS",
g_num_deferred_callbacks);
} else {
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
index 596894338cb4..f6032c6022cb 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
@@ -751,7 +751,7 @@ process_free_data_message(struct vchiq_state *state, u32 *service_found,
*/
complete("a->quota_event);
} else if (count == 0) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"service %d message_use_count=%d (header %pK, msgid %x, header->msgid %x, header->size %x)",
port, quota->message_use_count, header, msgid, header->msgid,
header->size);
@@ -776,7 +776,7 @@ process_free_data_message(struct vchiq_state *state, u32 *service_found,
vchiq_log_trace(vchiq_core_log_level, "%d: pfq:%d %x@%pK - slot_use->%d",
state->id, port, header->size, header, count - 1);
} else {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"service %d slot_use_count=%d (header %pK, msgid %x, header->msgid %x, header->size %x)",
port, count, header, msgid, header->msgid, header->size);
WARN(1, "bad slot use count\n");
@@ -841,7 +841,7 @@ process_free_queue(struct vchiq_state *state, u32 *service_found,
pos += calc_stride(header->size);
if (pos > VCHIQ_SLOT_SIZE) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"pfq - pos %x: header %pK, msgid %x, header->msgid %x, header->size %x",
pos, header, msgid, header->msgid, header->size);
WARN(1, "invalid slot position\n");
@@ -1178,7 +1178,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
int oldmsgid = header->msgid;
if (oldmsgid != VCHIQ_MSGID_PADDING)
- vchiq_log_error(vchiq_core_log_level, "%d: qms - msgid %x, not PADDING",
+ vchiq_log_error(state->dev, VCHIQ_CORE, "%d: qms - msgid %x, not PADDING",
state->id, oldmsgid);
}
@@ -1512,11 +1512,9 @@ parse_open(struct vchiq_state *state, struct vchiq_header *header)
if ((service->version < version_min) || (version < service->version_min)) {
/* Version mismatch */
- vchiq_loud_error_header();
- vchiq_loud_error("%d: service %d (%c%c%c%c) version mismatch - local (%d, min %d) vs. remote (%d, min %d)",
- state->id, service->localport, VCHIQ_FOURCC_AS_4CHARS(fourcc),
- service->version, service->version_min, version, version_min);
- vchiq_loud_error_footer();
+ dev_err(state->dev, "%d: service %d (%c%c%c%c) version mismatch - local (%d, min %d) vs. remote (%d, min %d)",
+ state->id, service->localport, VCHIQ_FOURCC_AS_4CHARS(fourcc),
+ service->version, service->version_min, version, version_min);
vchiq_service_put(service);
service = NULL;
goto fail_open;
@@ -1631,7 +1629,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
}
if (!service) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"%d: prs %s@%pK (%d->%d) - invalid/closed service %d",
state->id, msg_type_str(type), header, remoteport,
localport, localport);
@@ -1658,7 +1656,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
if (((unsigned long)header & VCHIQ_SLOT_MASK) +
calc_stride(size) > VCHIQ_SLOT_SIZE) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"header %pK (msgid %x) - size %x too big for slot",
header, (unsigned int)msgid, (unsigned int)size);
WARN(1, "oversized for slot\n");
@@ -1685,7 +1683,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
set_service_state(service, VCHIQ_SRVSTATE_OPEN);
complete(&service->remove_event);
} else {
- vchiq_log_error(vchiq_core_log_level, "OPENACK received in state %s",
+ vchiq_log_error(state->dev, VCHIQ_CORE, "OPENACK received in state %s",
srvstate_names[service->srvstate]);
}
break;
@@ -1756,7 +1754,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
}
if ((int)(queue->remote_insert -
queue->local_insert) >= 0) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"%d: prs %s@%pK (%d->%d) unexpected (ri=%d,li=%d)",
state->id, msg_type_str(type), header, remoteport,
localport, queue->remote_insert,
@@ -1805,8 +1803,8 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
vchiq_log_trace(vchiq_core_log_level, "%d: prs PAUSE@%pK,%x",
state->id, header, size);
if (state->conn_state == VCHIQ_CONNSTATE_PAUSED) {
- vchiq_log_error(vchiq_core_log_level, "%d: PAUSE received in state PAUSED",
- state->id);
+ vchiq_log_error(state->dev, VCHIQ_CORE,
+ "%d: PAUSE received in state PAUSED", state->id);
break;
}
if (state->conn_state != VCHIQ_CONNSTATE_PAUSE_SENT) {
@@ -1836,7 +1834,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
break;
default:
- vchiq_log_error(vchiq_core_log_level, "%d: prs invalid msgid %x@%pK,%x",
+ vchiq_log_error(state->dev, VCHIQ_CORE, "%d: prs invalid msgid %x@%pK,%x",
state->id, msgid, header, size);
WARN(1, "invalid message\n");
break;
@@ -1947,7 +1945,7 @@ handle_poll(struct vchiq_state *state)
* since the PAUSE should have flushed
* through outstanding messages.
*/
- vchiq_log_error(vchiq_core_log_level, "Failed to send RESUME message");
+ vchiq_log_error(state->dev, VCHIQ_CORE, "Failed to send RESUME message");
}
break;
default:
@@ -2046,7 +2044,7 @@ sync_func(void *v)
service = find_service_by_port(state, localport);
if (!service) {
- vchiq_log_error(vchiq_sync_log_level,
+ vchiq_log_error(state->dev, VCHIQ_SYNC,
"%d: sf %s@%pK (%d->%d) - invalid/closed service %d",
state->id, msg_type_str(type), header,
remoteport, localport, localport);
@@ -2096,14 +2094,14 @@ sync_func(void *v)
(service->srvstate == VCHIQ_SRVSTATE_OPENSYNC)) {
if (make_service_callback(service, VCHIQ_MESSAGE_AVAILABLE, header,
NULL) == -EAGAIN)
- vchiq_log_error(vchiq_sync_log_level,
+ vchiq_log_error(state->dev, VCHIQ_SYNC,
"synchronous callback to service %d returns -EAGAIN",
localport);
}
break;
default:
- vchiq_log_error(vchiq_sync_log_level, "%d: sf unexpected msgid %x@%pK,%x",
+ vchiq_log_error(state->dev, VCHIQ_SYNC, "%d: sf unexpected msgid %x@%pK,%x",
state->id, msgid, header, size);
release_message_sync(state, header);
break;
@@ -2137,7 +2135,7 @@ vchiq_init_slots(void *mem_base, int mem_size)
num_slots -= first_data_slot;
if (num_slots < 4) {
- vchiq_log_error(vchiq_core_log_level, "%s - insufficient memory %x bytes",
+ vchiq_log_error(NULL, VCHIQ_CORE, "%s - insufficient memory %x bytes",
__func__, mem_size);
return NULL;
}
@@ -2174,12 +2172,11 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
remote = &slot_zero->master;
if (local->initialised) {
- vchiq_loud_error_header();
if (remote->initialised)
- vchiq_loud_error("local state has already been initialised");
+ dev_err(dev, "local state has already been initialised\n");
else
- vchiq_loud_error("master/slave mismatch two slaves");
- vchiq_loud_error_footer();
+ dev_err(dev, "master/slave mismatch two slaves\n");
+
return -EINVAL;
}
@@ -2257,9 +2254,7 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
state->slot_handler_thread = kthread_create(&slot_handler_func, (void *)state, threadname);
if (IS_ERR(state->slot_handler_thread)) {
- vchiq_loud_error_header();
- vchiq_loud_error("couldn't create thread %s", threadname);
- vchiq_loud_error_footer();
+ dev_err(state->dev, "couldn't create thread %s\n", threadname);
return PTR_ERR(state->slot_handler_thread);
}
set_user_nice(state->slot_handler_thread, -19);
@@ -2267,9 +2262,7 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
snprintf(threadname, sizeof(threadname), "vchiq-recy/%d", state->id);
state->recycle_thread = kthread_create(&recycle_func, (void *)state, threadname);
if (IS_ERR(state->recycle_thread)) {
- vchiq_loud_error_header();
- vchiq_loud_error("couldn't create thread %s", threadname);
- vchiq_loud_error_footer();
+ dev_err(state->dev, "couldn't create thread %s\n", threadname);
ret = PTR_ERR(state->recycle_thread);
goto fail_free_handler_thread;
}
@@ -2278,9 +2271,7 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
snprintf(threadname, sizeof(threadname), "vchiq-sync/%d", state->id);
state->sync_thread = kthread_create(&sync_func, (void *)state, threadname);
if (IS_ERR(state->sync_thread)) {
- vchiq_loud_error_header();
- vchiq_loud_error("couldn't create thread %s", threadname);
- vchiq_loud_error_footer();
+ dev_err(state->dev, "couldn't create thread %s\n", threadname);
ret = PTR_ERR(state->sync_thread);
goto fail_free_recycle_thread;
}
@@ -2353,10 +2344,11 @@ struct vchiq_header *vchiq_msg_hold(struct vchiq_instance *instance, unsigned in
}
EXPORT_SYMBOL(vchiq_msg_hold);
-static int vchiq_validate_params(const struct vchiq_service_params_kernel *params)
+static int vchiq_validate_params(struct vchiq_state *state,
+ const struct vchiq_service_params_kernel *params)
{
if (!params->callback || !params->fourcc) {
- vchiq_loud_error("Can't add service, invalid params\n");
+ dev_err(state->dev, "Can't add service, invalid params\n");
return -EINVAL;
}
@@ -2376,7 +2368,7 @@ vchiq_add_service_internal(struct vchiq_state *state,
int ret;
int i;
- ret = vchiq_validate_params(params);
+ ret = vchiq_validate_params(state, params);
if (ret)
return NULL;
@@ -2525,7 +2517,7 @@ vchiq_open_service_internal(struct vchiq_service *service, int client_id)
} else if ((service->srvstate != VCHIQ_SRVSTATE_OPEN) &&
(service->srvstate != VCHIQ_SRVSTATE_OPENSYNC)) {
if (service->srvstate != VCHIQ_SRVSTATE_CLOSEWAIT)
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(service->state->dev, VCHIQ_CORE,
"%d: osi - srvstate = %s (ref %u)",
service->state->id,
srvstate_names[service->srvstate],
@@ -2589,7 +2581,7 @@ release_service_messages(struct vchiq_service *service)
}
pos += calc_stride(header->size);
if (pos > VCHIQ_SLOT_SIZE) {
- vchiq_log_error(vchiq_core_log_level,
+ vchiq_log_error(state->dev, VCHIQ_CORE,
"fsi - pos %x: header %pK, msgid %x, header->msgid %x, header->size %x",
pos, header, msgid, header->msgid, header->size);
WARN(1, "invalid slot position\n");
@@ -2645,8 +2637,8 @@ close_service_complete(struct vchiq_service *service, int failstate)
case VCHIQ_SRVSTATE_LISTENING:
break;
default:
- vchiq_log_error(vchiq_core_log_level, "%s(%x) called in state %s", __func__,
- service->handle, srvstate_names[service->srvstate]);
+ vchiq_log_error(service->state->dev, VCHIQ_CORE, "%s(%x) called in state %s",
+ __func__, service->handle, srvstate_names[service->srvstate]);
WARN(1, "%s in unexpected state\n", __func__);
return -EINVAL;
}
@@ -2701,7 +2693,7 @@ vchiq_close_service_internal(struct vchiq_service *service, int close_recvd)
case VCHIQ_SRVSTATE_LISTENING:
case VCHIQ_SRVSTATE_CLOSEWAIT:
if (close_recvd) {
- vchiq_log_error(vchiq_core_log_level, "%s(1) called in state %s",
+ vchiq_log_error(state->dev, VCHIQ_CORE, "%s(1) called in state %s",
__func__, srvstate_names[service->srvstate]);
} else if (is_server) {
if (service->srvstate == VCHIQ_SRVSTATE_LISTENING) {
@@ -2789,7 +2781,7 @@ vchiq_close_service_internal(struct vchiq_service *service, int close_recvd)
break;
default:
- vchiq_log_error(vchiq_core_log_level, "%s(%d) called in state %s", __func__,
+ vchiq_log_error(state->dev, VCHIQ_CORE, "%s(%d) called in state %s", __func__,
close_recvd, srvstate_names[service->srvstate]);
break;
}
@@ -2828,7 +2820,7 @@ vchiq_free_service_internal(struct vchiq_service *service)
case VCHIQ_SRVSTATE_CLOSEWAIT:
break;
default:
- vchiq_log_error(vchiq_core_log_level, "%d: fsi - (%d) in state %s", state->id,
+ vchiq_log_error(state->dev, VCHIQ_CORE, "%d: fsi - (%d) in state %s", state->id,
service->localport, srvstate_names[service->srvstate]);
return;
}
@@ -3628,26 +3620,6 @@ int vchiq_dump_service_state(void *dump_context, struct vchiq_service *service)
return err;
}
-void
-vchiq_loud_error_header(void)
-{
- vchiq_log_error(vchiq_core_log_level,
- "============================================================================");
- vchiq_log_error(vchiq_core_log_level,
- "============================================================================");
- vchiq_log_error(vchiq_core_log_level, "=====");
-}
-
-void
-vchiq_loud_error_footer(void)
-{
- vchiq_log_error(vchiq_core_log_level, "=====");
- vchiq_log_error(vchiq_core_log_level,
- "============================================================================");
- vchiq_log_error(vchiq_core_log_level,
- "============================================================================");
-}
-
int vchiq_send_remote_use(struct vchiq_state *state)
{
if (state->conn_state == VCHIQ_CONNSTATE_DISCONNECTED)
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
index ec1a3caefaea..c74c3647ef60 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -6,6 +6,7 @@
#include <linux/mutex.h>
#include <linux/completion.h>
+#include <linux/dev_printk.h>
#include <linux/kthread.h>
#include <linux/kref.h>
#include <linux/rcupdate.h>
@@ -39,10 +40,33 @@
#define VCHIQ_LOG_PREFIX KERN_INFO "vchiq: "
+enum vchiq_log_category {
+ VCHIQ_ARM,
+ VCHIQ_CORE,
+ VCHIQ_CORE_MSG,
+ VCHIQ_SYNC,
+ VCHIQ_SUSPEND,
+};
+
+static inline const char *log_category_str(enum vchiq_log_category c)
+{
+ static const char * const strings[] = {
+ "vchiq_arm",
+ "vchiq_core",
+ "vchiq_core_msg",
+ "vchiq_sync",
+ "vchiq_suspend",
+ };
+
+ return strings[c];
+};
+
#ifndef vchiq_log_error
-#define vchiq_log_error(cat, fmt, ...) \
- do { if (cat >= VCHIQ_LOG_ERROR) \
- printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
+#define vchiq_log_error(dev, cat, fmt, ...) \
+ do { if (dev != NULL) \
+ dev_dbg(dev, "%s error: " fmt, log_category_str(cat), ##__VA_ARGS__); \
+ else \
+ pr_debug("%s error: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
#ifndef vchiq_log_warning
#define vchiq_log_warning(cat, fmt, ...) \
@@ -60,9 +84,6 @@
printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
#endif
-#define vchiq_loud_error(...) \
- vchiq_log_error(vchiq_core_log_level, "===== " __VA_ARGS__)
-
#define VCHIQ_SLOT_MASK (VCHIQ_SLOT_SIZE - 1)
#define VCHIQ_SLOT_QUEUE_MASK (VCHIQ_MAX_SLOTS_PER_SIDE - 1)
#define VCHIQ_SLOT_ZERO_SLOTS DIV_ROUND_UP(sizeof(struct vchiq_slot_zero), \
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
index 841e1a535642..c89dc6d82fd2 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
@@ -271,7 +271,7 @@ static int vchiq_ioc_dequeue_message(struct vchiq_instance *instance,
ret = -EFAULT;
}
} else {
- vchiq_log_error(vchiq_arm_log_level,
+ vchiq_log_error(service->state->dev, VCHIQ_ARM,
"header %pK: bufsize %x < size %x",
header, args->bufsize, header->size);
WARN(1, "invalid size\n");
@@ -318,7 +318,7 @@ static int vchiq_irq_queue_bulk_tx_rx(struct vchiq_instance *instance,
}
mutex_unlock(&instance->bulk_waiter_list_mutex);
if (!waiter) {
- vchiq_log_error(vchiq_arm_log_level,
+ vchiq_log_error(service->state->dev, VCHIQ_ARM,
"no bulk_waiter found for pid %d", current->pid);
ret = -ESRCH;
goto out;
@@ -501,7 +501,7 @@ static int vchiq_ioc_await_completion(struct vchiq_instance *instance,
msglen = header->size + sizeof(struct vchiq_header);
/* This must be a VCHIQ-style service */
if (args->msgbufsize < msglen) {
- vchiq_log_error(vchiq_arm_log_level,
+ vchiq_log_error(service->state->dev, VCHIQ_ARM,
"header %pK: msgbufsize %x < msglen %x",
header, args->msgbufsize, msglen);
WARN(1, "invalid message size\n");
@@ -618,7 +618,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
}
rc = mutex_lock_killable(&instance->state->mutex);
if (rc) {
- vchiq_log_error(vchiq_arm_log_level,
+ vchiq_log_error(instance->state->dev, VCHIQ_ARM,
"vchiq: connect: could not lock mutex for state %d: %d",
instance->state->id, rc);
ret = -EINTR;
@@ -630,7 +630,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
if (!status)
instance->connected = 1;
else
- vchiq_log_error(vchiq_arm_log_level,
+ vchiq_log_error(instance->state->dev, VCHIQ_ARM,
"vchiq: could not connect: %d", status);
break;
@@ -700,7 +700,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
vchiq_use_service_internal(service) :
vchiq_release_service_internal(service);
if (ret) {
- vchiq_log_error(vchiq_susp_log_level,
+ vchiq_log_error(service->state->dev, VCHIQ_SUSPEND,
"%s: cmd %s returned error %ld for service %c%c%c%c:%03d",
__func__, (cmd == VCHIQ_IOC_USE_SERVICE) ?
"VCHIQ_IOC_USE_SERVICE" :
@@ -1173,7 +1173,7 @@ static int vchiq_open(struct inode *inode, struct file *file)
vchiq_log_info(vchiq_arm_log_level, "vchiq_open");
if (!state) {
- vchiq_log_error(vchiq_arm_log_level,
+ vchiq_log_error(state->dev, VCHIQ_ARM,
"vchiq has no connection to VideoCore");
return -ENOTCONN;
}
--
2.40.1
^ permalink raw reply related [flat|nested] 10+ messages in thread
* [PATCH v1 2/4] staging: vc04: Convert vchiq_log_warning() to use dynamic debug
2023-10-19 8:21 [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Umang Jain
2023-10-19 8:21 ` [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
@ 2023-10-19 8:21 ` Umang Jain
2023-10-19 13:50 ` Kieran Bingham
2023-10-19 8:21 ` [PATCH v1 3/4] staging: vc04: Convert(and rename) vchiq_log_info() " Umang Jain
` (2 subsequent siblings)
4 siblings, 1 reply; 10+ messages in thread
From: Umang Jain @ 2023-10-19 8:21 UTC (permalink / raw)
To: linux-staging, linux-rpi-kernel, linux-media, linux-arm-kernel
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Kieran Bingham, Laurent Pinchart, Umang Jain
Move vchiq_log_warning() custom logging wrapper based on printk to use
dynamic debug. The log category is dictated by vchiq_log_category
which will become the part of the warning string format that will be
logged to dynamic debug (for grep).
All the vchiq_log_warning() calls are adjusted to use the
modified wrapper.
While at that, remove the extraneous "----" from few of the
warning string text.
Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
.../interface/vchiq_arm/vchiq_arm.c | 16 +++++++++-------
.../interface/vchiq_arm/vchiq_core.c | 8 ++++----
.../interface/vchiq_arm/vchiq_core.h | 5 ++---
3 files changed, 15 insertions(+), 14 deletions(-)
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
index fa4463bfc117..cfc06ca2e228 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -695,7 +695,7 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
ret = -ENOTCONN;
goto failed;
} else if (i > 0) {
- vchiq_log_warning(vchiq_core_log_level,
+ vchiq_log_warning(state->dev, VCHIQ_CORE,
"%s: videocore initialized after %d retries\n", __func__, i);
}
@@ -1696,17 +1696,19 @@ vchiq_dump_service_use_state(struct vchiq_state *state)
read_unlock_bh(&arm_state->susp_res_lock);
if (only_nonzero)
- vchiq_log_warning(vchiq_susp_log_level, "Too many active services (%d). Only dumping up to first %d services with non-zero use-count",
+ vchiq_log_warning(state->dev, VCHIQ_SUSPEND,
+ "Too many active services (%d). Only dumping up to first %d services with non-zero use-count",
active_services, found);
for (i = 0; i < found; i++) {
- vchiq_log_warning(vchiq_susp_log_level, "----- %c%c%c%c:%d service count %d %s",
+ vchiq_log_warning(state->dev, VCHIQ_SUSPEND,
+ "%c%c%c%c:%d service count %d %s",
VCHIQ_FOURCC_AS_4CHARS(service_data[i].fourcc),
service_data[i].clientid, service_data[i].use_count,
service_data[i].use_count ? nz : "");
}
- vchiq_log_warning(vchiq_susp_log_level, "----- VCHIQ use count %d", peer_count);
- vchiq_log_warning(vchiq_susp_log_level, "--- Overall vchiq instance use count %d",
+ vchiq_log_warning(state->dev, VCHIQ_SUSPEND, "VCHIQ use count %d", peer_count);
+ vchiq_log_warning(state->dev, VCHIQ_SUSPEND, "Overall vchiq instance use count %d",
vc_use_count);
kfree(service_data);
@@ -1822,7 +1824,7 @@ static int vchiq_probe(struct platform_device *pdev)
*/
err = vchiq_register_chrdev(&pdev->dev);
if (err) {
- vchiq_log_warning(vchiq_arm_log_level,
+ vchiq_log_warning(&pdev->dev, VCHIQ_ARM,
"Failed to initialize vchiq cdev");
goto error_exit;
}
@@ -1833,7 +1835,7 @@ static int vchiq_probe(struct platform_device *pdev)
return 0;
failed_platform_init:
- vchiq_log_warning(vchiq_arm_log_level, "could not initialize vchiq platform");
+ vchiq_log_warning(&pdev->dev, VCHIQ_ARM, "could not initialize vchiq platform");
error_exit:
return err;
}
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
index f6032c6022cb..43e292512491 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
@@ -475,7 +475,7 @@ make_service_callback(struct vchiq_service *service, enum vchiq_reason reason,
status = service->base.callback(service->instance, reason, header, service->handle,
bulk_userdata);
if (status && (status != -EAGAIN)) {
- vchiq_log_warning(vchiq_core_log_level,
+ vchiq_log_warning(service->state->dev, VCHIQ_CORE,
"%d: ignoring ERROR from callback to service %x",
service->state->id, service->handle);
status = 0;
@@ -1622,7 +1622,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
vchiq_service_put(service);
service = get_connected_service(state, remoteport);
if (service)
- vchiq_log_warning(vchiq_core_log_level,
+ vchiq_log_warning(state->dev, VCHIQ_CORE,
"%d: prs %s@%pK (%d->%d) - found connected service %d",
state->id, msg_type_str(type), header,
remoteport, localport, service->localport);
@@ -2921,7 +2921,7 @@ vchiq_close_service(struct vchiq_instance *instance, unsigned int handle)
(service->srvstate == VCHIQ_SRVSTATE_OPEN))
break;
- vchiq_log_warning(vchiq_core_log_level,
+ vchiq_log_warning(service->state->dev, VCHIQ_CORE,
"%d: close_service:%d - waiting in state %s",
service->state->id, service->localport,
srvstate_names[service->srvstate]);
@@ -2982,7 +2982,7 @@ vchiq_remove_service(struct vchiq_instance *instance, unsigned int handle)
(service->srvstate == VCHIQ_SRVSTATE_OPEN))
break;
- vchiq_log_warning(vchiq_core_log_level,
+ vchiq_log_warning(service->state->dev, VCHIQ_CORE,
"%d: remove_service:%d - waiting in state %s",
service->state->id, service->localport,
srvstate_names[service->srvstate]);
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
index c74c3647ef60..3dbb1964839b 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -69,9 +69,8 @@ static inline const char *log_category_str(enum vchiq_log_category c)
pr_debug("%s error: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
#ifndef vchiq_log_warning
-#define vchiq_log_warning(cat, fmt, ...) \
- do { if (cat >= VCHIQ_LOG_WARNING) \
- printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
+#define vchiq_log_warning(dev, cat, fmt, ...) \
+ do { dev_dbg(dev, "%s warning: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
#ifndef vchiq_log_info
#define vchiq_log_info(cat, fmt, ...) \
--
2.40.1
^ permalink raw reply related [flat|nested] 10+ messages in thread
* [PATCH v1 3/4] staging: vc04: Convert(and rename) vchiq_log_info() to use dynamic debug
2023-10-19 8:21 [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Umang Jain
2023-10-19 8:21 ` [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
2023-10-19 8:21 ` [PATCH v1 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
@ 2023-10-19 8:21 ` Umang Jain
2023-10-19 8:21 ` [PATCH v1 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
2023-10-19 13:58 ` [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Kieran Bingham
4 siblings, 0 replies; 10+ messages in thread
From: Umang Jain @ 2023-10-19 8:21 UTC (permalink / raw)
To: linux-staging, linux-rpi-kernel, linux-media, linux-arm-kernel
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Kieran Bingham, Laurent Pinchart, Umang Jain
Convert(and rename) vchiq_log_info() custom logging wrapping based on
printk to use dynamic debug. The wrapper is now renamed to
vchiq_log_debug() since most of the usage is around printing debug
information. The log category is dictated by enum vchiq_log_category
which will become the part of the debug string format that will be
logged to dynamic debug (for grep).
All the vchiq_log_info() calls are adjusted to use the
modified wrapper vchiq_log_debug().
The existing custom logging for vchiq_log_info() also tries
to log trace messages using SRVTRACE_LEVEL. This is simply
moved to use the vchiq_log_debug() directly.
Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
.../interface/vchiq_arm/vchiq_arm.c | 46 +++--
.../interface/vchiq_arm/vchiq_core.c | 171 +++++++++---------
.../interface/vchiq_arm/vchiq_core.h | 7 +-
.../interface/vchiq_arm/vchiq_dev.c | 41 +++--
4 files changed, 137 insertions(+), 128 deletions(-)
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
index cfc06ca2e228..b4d20f9a4e47 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -314,9 +314,9 @@ create_pagelist(struct vchiq_instance *instance, char *buf, char __user *ubuf,
type == PAGELIST_READ, pages);
if (actual_pages != num_pages) {
- vchiq_log_info(vchiq_arm_log_level,
- "%s - only %d/%d pages locked",
- __func__, actual_pages, num_pages);
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "%s - only %d/%d pages locked",
+ __func__, actual_pages, num_pages);
/* This is probably due to the process being killed */
if (actual_pages > 0)
@@ -559,8 +559,8 @@ static int vchiq_platform_init(struct platform_device *pdev, struct vchiq_state
return -ENXIO;
}
- vchiq_log_info(vchiq_arm_log_level, "vchiq_init - done (slots %pK, phys %pad)",
- vchiq_slot_zero, &slot_phys);
+ vchiq_log_debug(&pdev->dev, VCHIQ_ARM, "vchiq_init - done (slots %pK, phys %pad)",
+ vchiq_slot_zero, &slot_phys);
vchiq_call_connected_callbacks();
@@ -730,8 +730,9 @@ void free_bulk_waiter(struct vchiq_instance *instance)
list_for_each_entry_safe(waiter, next,
&instance->bulk_waiter_list, list) {
list_del(&waiter->list);
- vchiq_log_info(vchiq_arm_log_level, "bulk_waiter - cleaned up %pK for pid %d",
- waiter, waiter->pid);
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "bulk_waiter - cleaned up %pK for pid %d",
+ waiter, waiter->pid);
kfree(waiter);
}
}
@@ -991,8 +992,9 @@ vchiq_blocking_bulk_transfer(struct vchiq_instance *instance, unsigned int handl
mutex_lock(&instance->bulk_waiter_list_mutex);
list_add(&waiter->list, &instance->bulk_waiter_list);
mutex_unlock(&instance->bulk_waiter_list_mutex);
- vchiq_log_info(vchiq_arm_log_level, "saved bulk_waiter %pK for pid %d", waiter,
- current->pid);
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "saved bulk_waiter %pK for pid %d", waiter,
+ current->pid);
}
return status;
@@ -1015,10 +1017,12 @@ add_completion(struct vchiq_instance *instance, enum vchiq_reason reason,
vchiq_log_trace(vchiq_arm_log_level, "%s - completion queue full", __func__);
DEBUG_COUNT(COMPLETION_QUEUE_FULL_COUNT);
if (wait_for_completion_interruptible(&instance->remove_event)) {
- vchiq_log_info(vchiq_arm_log_level, "service_callback interrupted");
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "service_callback interrupted");
return -EAGAIN;
} else if (instance->closing) {
- vchiq_log_info(vchiq_arm_log_level, "service_callback closing");
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "service_callback closing");
return 0;
}
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
@@ -1120,8 +1124,8 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
instance->completion_remove) < 0) {
int status;
- vchiq_log_info(vchiq_arm_log_level,
- "Inserting extra MESSAGE_AVAILABLE");
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "Inserting extra MESSAGE_AVAILABLE");
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
status = add_completion(instance, reason, NULL, user_service,
bulk_userdata);
@@ -1134,12 +1138,14 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
if (wait_for_completion_interruptible(&user_service->remove_event)) {
- vchiq_log_info(vchiq_arm_log_level, "%s interrupted", __func__);
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "%s interrupted", __func__);
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
vchiq_service_put(service);
return -EAGAIN;
} else if (instance->closing) {
- vchiq_log_info(vchiq_arm_log_level, "%s closing", __func__);
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "%s closing", __func__);
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
vchiq_service_put(service);
return -EINVAL;
@@ -1748,8 +1754,8 @@ void vchiq_platform_conn_state_changed(struct vchiq_state *state,
struct vchiq_arm_state *arm_state = vchiq_platform_get_arm_state(state);
char threadname[16];
- vchiq_log_info(vchiq_susp_log_level, "%d: %s->%s", state->id,
- get_conn_state_name(oldstate), get_conn_state_name(newstate));
+ vchiq_log_debug(state->dev, VCHIQ_SUSPEND, "%d: %s->%s", state->id,
+ get_conn_state_name(oldstate), get_conn_state_name(newstate));
if (state->conn_state != VCHIQ_CONNSTATE_CONNECTED)
return;
@@ -1814,9 +1820,9 @@ static int vchiq_probe(struct platform_device *pdev)
vchiq_debugfs_init();
- vchiq_log_info(vchiq_arm_log_level,
- "vchiq: platform initialised - version %d (min %d)",
- VCHIQ_VERSION, VCHIQ_VERSION_MIN);
+ vchiq_log_debug(&pdev->dev, VCHIQ_ARM,
+ "vchiq: platform initialised - version %d (min %d)",
+ VCHIQ_VERSION, VCHIQ_VERSION_MIN);
/*
* Simply exit on error since the function handles cleanup in
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
index 43e292512491..43c900b0729b 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
@@ -103,8 +103,6 @@ static_assert((unsigned int)VCHIQ_PORT_MAX <
#define BULK_INDEX(x) ((x) & (VCHIQ_NUM_SERVICE_BULKS - 1))
-#define SRVTRACE_LEVEL(srv) \
- (((srv) && (srv)->trace) ? VCHIQ_LOG_TRACE : vchiq_core_msg_log_level)
#define SRVTRACE_ENABLED(srv, lev) \
(((srv) && (srv)->trace) || (vchiq_core_msg_log_level >= (lev)))
@@ -227,10 +225,10 @@ static const char *msg_type_str(unsigned int msg_type)
static inline void
set_service_state(struct vchiq_service *service, int newstate)
{
- vchiq_log_info(vchiq_core_log_level, "%d: srv:%d %s->%s",
- service->state->id, service->localport,
- srvstate_names[service->srvstate],
- srvstate_names[newstate]);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: srv:%d %s->%s",
+ service->state->id, service->localport,
+ srvstate_names[service->srvstate],
+ srvstate_names[newstate]);
service->srvstate = newstate;
}
@@ -255,8 +253,8 @@ find_service_by_handle(struct vchiq_instance *instance, unsigned int handle)
return service;
}
rcu_read_unlock();
- vchiq_log_info(vchiq_core_log_level,
- "Invalid service handle 0x%x", handle);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE,
+ "Invalid service handle 0x%x", handle);
return NULL;
}
@@ -276,8 +274,8 @@ find_service_by_port(struct vchiq_state *state, unsigned int localport)
}
rcu_read_unlock();
}
- vchiq_log_info(vchiq_core_log_level,
- "Invalid port %u", localport);
+ vchiq_log_debug(state->dev, VCHIQ_CORE,
+ "Invalid port %u", localport);
return NULL;
}
@@ -297,8 +295,8 @@ find_service_for_instance(struct vchiq_instance *instance, unsigned int handle)
return service;
}
rcu_read_unlock();
- vchiq_log_info(vchiq_core_log_level,
- "Invalid service handle 0x%x", handle);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE,
+ "Invalid service handle 0x%x", handle);
return NULL;
}
@@ -320,8 +318,8 @@ find_closed_service_for_instance(struct vchiq_instance *instance, unsigned int h
return service;
}
rcu_read_unlock();
- vchiq_log_info(vchiq_core_log_level,
- "Invalid service handle 0x%x", handle);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE,
+ "Invalid service handle 0x%x", handle);
return service;
}
@@ -492,8 +490,8 @@ vchiq_set_conn_state(struct vchiq_state *state, enum vchiq_connstate newstate)
{
enum vchiq_connstate oldstate = state->conn_state;
- vchiq_log_info(vchiq_core_log_level, "%d: %s->%s", state->id, conn_state_names[oldstate],
- conn_state_names[newstate]);
+ vchiq_log_debug(state->dev, VCHIQ_CORE, "%d: %s->%s", state->id, conn_state_names[oldstate],
+ conn_state_names[newstate]);
state->conn_state = newstate;
vchiq_platform_conn_state_changed(state, oldstate, newstate);
}
@@ -1033,9 +1031,9 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
int tx_end_index;
int slot_use_count;
- vchiq_log_info(vchiq_core_log_level, "%d: qm %s@%pK,%zx (%d->%d)", state->id,
- msg_type_str(VCHIQ_MSG_TYPE(msgid)), header, size,
- VCHIQ_MSG_SRCPORT(msgid), VCHIQ_MSG_DSTPORT(msgid));
+ vchiq_log_debug(state->dev, VCHIQ_CORE, "%d: qm %s@%pK,%zx (%d->%d)", state->id,
+ msg_type_str(VCHIQ_MSG_TYPE(msgid)), header, size,
+ VCHIQ_MSG_SRCPORT(msgid), VCHIQ_MSG_DSTPORT(msgid));
WARN_ON(flags & (QMFLAGS_NO_MUTEX_LOCK |
QMFLAGS_NO_MUTEX_UNLOCK));
@@ -1093,9 +1091,9 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
VCHIQ_SERVICE_STATS_INC(service, ctrl_tx_count);
VCHIQ_SERVICE_STATS_ADD(service, ctrl_tx_bytes, size);
} else {
- vchiq_log_info(vchiq_core_log_level, "%d: qm %s@%pK,%zx (%d->%d)", state->id,
- msg_type_str(VCHIQ_MSG_TYPE(msgid)), header, size,
- VCHIQ_MSG_SRCPORT(msgid), VCHIQ_MSG_DSTPORT(msgid));
+ vchiq_log_debug(state->dev, VCHIQ_CORE, "%d: qm %s@%pK,%zx (%d->%d)", state->id,
+ msg_type_str(VCHIQ_MSG_TYPE(msgid)), header, size,
+ VCHIQ_MSG_SRCPORT(msgid), VCHIQ_MSG_DSTPORT(msgid));
if (size != 0) {
/*
* It is assumed for now that this code path
@@ -1123,11 +1121,11 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
? service->base.fourcc
: VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
- vchiq_log_info(SRVTRACE_LEVEL(service),
- "Sent Msg %s(%u) to %c%c%c%c s:%u d:%d len:%zu",
- msg_type_str(VCHIQ_MSG_TYPE(msgid)), VCHIQ_MSG_TYPE(msgid),
- VCHIQ_FOURCC_AS_4CHARS(svc_fourcc), VCHIQ_MSG_SRCPORT(msgid),
- VCHIQ_MSG_DSTPORT(msgid), size);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE_MSG,
+ "Sent Msg %s(%u) to %c%c%c%c s:%u d:%d len:%zu",
+ msg_type_str(VCHIQ_MSG_TYPE(msgid)), VCHIQ_MSG_TYPE(msgid),
+ VCHIQ_FOURCC_AS_4CHARS(svc_fourcc), VCHIQ_MSG_SRCPORT(msgid),
+ VCHIQ_MSG_DSTPORT(msgid), size);
}
/* Make sure the new header is visible to the peer. */
@@ -1182,11 +1180,11 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
state->id, oldmsgid);
}
- vchiq_log_info(vchiq_sync_log_level,
- "%d: qms %s@%pK,%x (%d->%d)", state->id,
- msg_type_str(VCHIQ_MSG_TYPE(msgid)),
- header, size, VCHIQ_MSG_SRCPORT(msgid),
- VCHIQ_MSG_DSTPORT(msgid));
+ vchiq_log_debug(state->dev, VCHIQ_SYNC,
+ "%d: qms %s@%pK,%x (%d->%d)", state->id,
+ msg_type_str(VCHIQ_MSG_TYPE(msgid)),
+ header, size, VCHIQ_MSG_SRCPORT(msgid),
+ VCHIQ_MSG_DSTPORT(msgid));
callback_result =
copy_message_data(copy_callback, context,
@@ -1278,9 +1276,9 @@ release_slot(struct vchiq_state *state, struct vchiq_slot_info *slot_info,
VCHIQ_SLOT_QUEUE_MASK] =
SLOT_INDEX_FROM_INFO(state, slot_info);
state->remote->slot_queue_recycle = slot_queue_recycle + 1;
- vchiq_log_info(vchiq_core_log_level, "%d: %s %d - recycle->%x", state->id, __func__,
- SLOT_INDEX_FROM_INFO(state, slot_info),
- state->remote->slot_queue_recycle);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: %s %d - recycle->%x",
+ state->id, __func__, SLOT_INDEX_FROM_INFO(state, slot_info),
+ state->remote->slot_queue_recycle);
/*
* A write barrier is necessary, but remote_event_signal
@@ -1397,9 +1395,8 @@ poll_services_of_group(struct vchiq_state *state, int group)
service_flags = atomic_xchg(&service->poll_flags, 0);
if (service_flags & BIT(VCHIQ_POLL_REMOVE)) {
- vchiq_log_info(vchiq_core_log_level, "%d: ps - remove %d<->%d",
- state->id, service->localport,
- service->remoteport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: ps - remove %d<->%d",
+ state->id, service->localport, service->remoteport);
/*
* Make it look like a client, because
@@ -1411,8 +1408,8 @@ poll_services_of_group(struct vchiq_state *state, int group)
if (vchiq_close_service_internal(service, NO_CLOSE_RECVD))
request_poll(state, service, VCHIQ_POLL_REMOVE);
} else if (service_flags & BIT(VCHIQ_POLL_TERMINATE)) {
- vchiq_log_info(vchiq_core_log_level, "%d: ps - terminate %d<->%d",
- state->id, service->localport, service->remoteport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: ps - terminate %d<->%d",
+ state->id, service->localport, service->remoteport);
if (vchiq_close_service_internal(service, NO_CLOSE_RECVD))
request_poll(state, service, VCHIQ_POLL_TERMINATE);
}
@@ -1462,11 +1459,11 @@ abort_outstanding_bulks(struct vchiq_service *service,
if (queue->process != queue->local_insert) {
vchiq_complete_bulk(service->instance, bulk);
- vchiq_log_info(SRVTRACE_LEVEL(service),
- "%s %c%c%c%c d:%d ABORTED - tx len:%d, rx len:%d",
- is_tx ? "Send Bulk to" : "Recv Bulk from",
- VCHIQ_FOURCC_AS_4CHARS(service->base.fourcc),
- service->remoteport, bulk->size, bulk->remote_size);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE_MSG,
+ "%s %c%c%c%c d:%d ABORTED - tx len:%d, rx len:%d",
+ is_tx ? "Send Bulk to" : "Recv Bulk from",
+ VCHIQ_FOURCC_AS_4CHARS(service->base.fourcc),
+ service->remoteport, bulk->size, bulk->remote_size);
} else {
/* fabricate a matching dummy bulk */
bulk->data = 0;
@@ -1499,8 +1496,8 @@ parse_open(struct vchiq_state *state, struct vchiq_header *header)
payload = (struct vchiq_open_payload *)header->data;
fourcc = payload->fourcc;
- vchiq_log_info(vchiq_core_log_level, "%d: prs OPEN@%pK (%d->'%c%c%c%c')",
- state->id, header, localport, VCHIQ_FOURCC_AS_4CHARS(fourcc));
+ vchiq_log_debug(state->dev, VCHIQ_CORE, "%d: prs OPEN@%pK (%d->'%c%c%c%c')",
+ state->id, header, localport, VCHIQ_FOURCC_AS_4CHARS(fourcc));
service = get_listening_service(state, fourcc);
if (!service)
@@ -1646,10 +1643,11 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
svc_fourcc = service
? service->base.fourcc
: VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
- vchiq_log_info(SRVTRACE_LEVEL(service),
- "Rcvd Msg %s(%u) from %c%c%c%c s:%d d:%d len:%d",
- msg_type_str(type), type, VCHIQ_FOURCC_AS_4CHARS(svc_fourcc),
- remoteport, localport, size);
+
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE_MSG,
+ "Rcvd Msg %s(%u) from %c%c%c%c s:%d d:%d len:%d",
+ msg_type_str(type), type, VCHIQ_FOURCC_AS_4CHARS(svc_fourcc),
+ remoteport, localport, size);
if (size > 0)
vchiq_log_dump_mem("Rcvd", 0, header->data, min(16, size));
}
@@ -1675,9 +1673,10 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
header->data;
service->peer_version = payload->version;
}
- vchiq_log_info(vchiq_core_log_level, "%d: prs OPENACK@%pK,%x (%d->%d) v:%d",
- state->id, header, size, remoteport, localport,
- service->peer_version);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE,
+ "%d: prs OPENACK@%pK,%x (%d->%d) v:%d",
+ state->id, header, size, remoteport, localport,
+ service->peer_version);
if (service->srvstate == VCHIQ_SRVSTATE_OPENING) {
service->remoteport = remoteport;
set_service_state(service, VCHIQ_SRVSTATE_OPEN);
@@ -1690,21 +1689,21 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
case VCHIQ_MSG_CLOSE:
WARN_ON(size); /* There should be no data */
- vchiq_log_info(vchiq_core_log_level, "%d: prs CLOSE@%pK (%d->%d)",
- state->id, header, remoteport, localport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: prs CLOSE@%pK (%d->%d)",
+ state->id, header, remoteport, localport);
mark_service_closing_internal(service, 1);
if (vchiq_close_service_internal(service, CLOSE_RECVD) == -EAGAIN)
goto bail_not_ready;
- vchiq_log_info(vchiq_core_log_level, "Close Service %c%c%c%c s:%u d:%d",
- VCHIQ_FOURCC_AS_4CHARS(service->base.fourcc),
- service->localport, service->remoteport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "Close Service %c%c%c%c s:%u d:%d",
+ VCHIQ_FOURCC_AS_4CHARS(service->base.fourcc),
+ service->localport, service->remoteport);
break;
case VCHIQ_MSG_DATA:
- vchiq_log_info(vchiq_core_log_level, "%d: prs DATA@%pK,%x (%d->%d)",
- state->id, header, size, remoteport, localport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: prs DATA@%pK,%x (%d->%d)",
+ state->id, header, size, remoteport, localport);
if ((service->remoteport == remoteport) &&
(service->srvstate == VCHIQ_SRVSTATE_OPEN)) {
@@ -1723,7 +1722,8 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
}
break;
case VCHIQ_MSG_CONNECT:
- vchiq_log_info(vchiq_core_log_level, "%d: prs CONNECT@%pK", state->id, header);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: prs CONNECT@%pK",
+ state->id, header);
state->version_common = ((struct vchiq_slot_zero *)
state->slot_data)->version;
complete(&state->connect);
@@ -1775,9 +1775,10 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
bulk->actual = *(int *)header->data;
queue->remote_insert++;
- vchiq_log_info(vchiq_core_log_level, "%d: prs %s@%pK (%d->%d) %x@%pad",
- state->id, msg_type_str(type), header, remoteport, localport,
- bulk->actual, &bulk->data);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE,
+ "%d: prs %s@%pK (%d->%d) %x@%pad",
+ state->id, msg_type_str(type), header, remoteport,
+ localport, bulk->actual, &bulk->data);
vchiq_log_trace(vchiq_core_log_level, "%d: prs:%d %cx li=%x ri=%x p=%x",
state->id, localport,
@@ -2074,9 +2075,9 @@ sync_func(void *v)
header->data;
service->peer_version = payload->version;
}
- vchiq_log_info(vchiq_sync_log_level, "%d: sf OPENACK@%pK,%x (%d->%d) v:%d",
- state->id, header, size, remoteport, localport,
- service->peer_version);
+ vchiq_log_debug(state->dev, VCHIQ_SYNC, "%d: sf OPENACK@%pK,%x (%d->%d) v:%d",
+ state->id, header, size, remoteport, localport,
+ service->peer_version);
if (service->srvstate == VCHIQ_SRVSTATE_OPENING) {
service->remoteport = remoteport;
set_service_state(service, VCHIQ_SRVSTATE_OPENSYNC);
@@ -2478,9 +2479,9 @@ vchiq_add_service_internal(struct vchiq_state *state,
/* Bring this service online */
set_service_state(service, srvstate);
- vchiq_log_info(vchiq_core_msg_log_level, "%s Service %c%c%c%c SrcPort:%d",
- (srvstate == VCHIQ_SRVSTATE_OPENING) ? "Open" : "Add",
- VCHIQ_FOURCC_AS_4CHARS(params->fourcc), service->localport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE_MSG, "%s Service %c%c%c%c SrcPort:%d",
+ (srvstate == VCHIQ_SRVSTATE_OPENING) ? "Open" : "Add",
+ VCHIQ_FOURCC_AS_4CHARS(params->fourcc), service->localport);
/* Don't unlock the service - leave it with a ref_count of 1. */
@@ -2576,7 +2577,8 @@ release_service_messages(struct vchiq_service *service)
int port = VCHIQ_MSG_DSTPORT(msgid);
if ((port == service->localport) && (msgid & VCHIQ_MSGID_CLAIMED)) {
- vchiq_log_info(vchiq_core_log_level, " fsi - hdr %pK", header);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE,
+ " fsi - hdr %pK", header);
release_slot(state, slot_info, header, NULL);
}
pos += calc_stride(header->size);
@@ -2684,8 +2686,8 @@ vchiq_close_service_internal(struct vchiq_service *service, int close_recvd)
int close_id = MAKE_CLOSE(service->localport,
VCHIQ_MSG_DSTPORT(service->remoteport));
- vchiq_log_info(vchiq_core_log_level, "%d: csi:%d,%d (%s)", service->state->id,
- service->localport, close_recvd, srvstate_names[service->srvstate]);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: csi:%d,%d (%s)", service->state->id,
+ service->localport, close_recvd, srvstate_names[service->srvstate]);
switch (service->srvstate) {
case VCHIQ_SRVSTATE_CLOSED:
@@ -2795,8 +2797,8 @@ vchiq_terminate_service_internal(struct vchiq_service *service)
{
struct vchiq_state *state = service->state;
- vchiq_log_info(vchiq_core_log_level, "%d: tsi - (%d<->%d)", state->id,
- service->localport, service->remoteport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: tsi - (%d<->%d)", state->id,
+ service->localport, service->remoteport);
mark_service_closing(service);
@@ -2810,7 +2812,8 @@ vchiq_free_service_internal(struct vchiq_service *service)
{
struct vchiq_state *state = service->state;
- vchiq_log_info(vchiq_core_log_level, "%d: fsi - (%d)", state->id, service->localport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: fsi - (%d)",
+ state->id, service->localport);
switch (service->srvstate) {
case VCHIQ_SRVSTATE_OPENING:
@@ -2890,8 +2893,8 @@ vchiq_close_service(struct vchiq_instance *instance, unsigned int handle)
if (!service)
return -EINVAL;
- vchiq_log_info(vchiq_core_log_level, "%d: close_service:%d",
- service->state->id, service->localport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: close_service:%d",
+ service->state->id, service->localport);
if ((service->srvstate == VCHIQ_SRVSTATE_FREE) ||
(service->srvstate == VCHIQ_SRVSTATE_LISTENING) ||
@@ -2948,8 +2951,8 @@ vchiq_remove_service(struct vchiq_instance *instance, unsigned int handle)
if (!service)
return -EINVAL;
- vchiq_log_info(vchiq_core_log_level, "%d: remove_service:%d",
- service->state->id, service->localport);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: remove_service:%d",
+ service->state->id, service->localport);
if (service->srvstate == VCHIQ_SRVSTATE_FREE) {
vchiq_service_put(service);
@@ -3092,9 +3095,9 @@ int vchiq_bulk_transfer(struct vchiq_instance *instance, unsigned int handle,
*/
wmb();
- vchiq_log_info(vchiq_core_log_level, "%d: bt (%d->%d) %cx %x@%pad %pK",
- state->id, service->localport, service->remoteport,
- dir_char, size, &bulk->data, userdata);
+ vchiq_log_debug(service->state->dev, VCHIQ_CORE, "%d: bt (%d->%d) %cx %x@%pad %pK",
+ state->id, service->localport, service->remoteport,
+ dir_char, size, &bulk->data, userdata);
/*
* The slot mutex must be held when the service is being closed, so
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
index 3dbb1964839b..d0682a3e7a46 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -72,10 +72,9 @@ static inline const char *log_category_str(enum vchiq_log_category c)
#define vchiq_log_warning(dev, cat, fmt, ...) \
do { dev_dbg(dev, "%s warning: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
-#ifndef vchiq_log_info
-#define vchiq_log_info(cat, fmt, ...) \
- do { if (cat >= VCHIQ_LOG_INFO) \
- printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
+#ifndef vchiq_log_debug
+#define vchiq_log_debug(dev, cat, fmt, ...) \
+ do { dev_dbg(dev, "%s debug: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
#ifndef vchiq_log_trace
#define vchiq_log_trace(cat, fmt, ...) \
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
index c89dc6d82fd2..4aea0a8fca49 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
@@ -47,9 +47,9 @@ user_service_free(void *userdata)
static void close_delivered(struct user_service *user_service)
{
- vchiq_log_info(vchiq_arm_log_level,
- "%s(handle=%x)",
- __func__, user_service->service->handle);
+ vchiq_log_debug(user_service->service->state->dev, VCHIQ_ARM,
+ "%s(handle=%x)",
+ __func__, user_service->service->handle);
if (user_service->close_pending) {
/* Allow the underlying service to be culled */
@@ -235,8 +235,8 @@ static int vchiq_ioc_dequeue_message(struct vchiq_instance *instance,
spin_unlock(&msg_queue_spinlock);
DEBUG_TRACE(DEQUEUE_MESSAGE_LINE);
if (wait_for_completion_interruptible(&user_service->insert_event)) {
- vchiq_log_info(vchiq_arm_log_level,
- "DEQUEUE_MESSAGE interrupted");
+ vchiq_log_debug(service->state->dev, VCHIQ_ARM,
+ "DEQUEUE_MESSAGE interrupted");
ret = -EINTR;
break;
}
@@ -323,8 +323,8 @@ static int vchiq_irq_queue_bulk_tx_rx(struct vchiq_instance *instance,
ret = -ESRCH;
goto out;
}
- vchiq_log_info(vchiq_arm_log_level,
- "found bulk_waiter %pK for pid %d", waiter, current->pid);
+ vchiq_log_debug(service->state->dev, VCHIQ_ARM,
+ "found bulk_waiter %pK for pid %d", waiter, current->pid);
userdata = &waiter->bulk_waiter;
} else {
userdata = args->userdata;
@@ -355,8 +355,8 @@ static int vchiq_irq_queue_bulk_tx_rx(struct vchiq_instance *instance,
mutex_lock(&instance->bulk_waiter_list_mutex);
list_add(&waiter->list, &instance->bulk_waiter_list);
mutex_unlock(&instance->bulk_waiter_list_mutex);
- vchiq_log_info(vchiq_arm_log_level,
- "saved bulk_waiter %pK for pid %d", waiter, current->pid);
+ vchiq_log_debug(service->state->dev, VCHIQ_ARM,
+ "saved bulk_waiter %pK for pid %d", waiter, current->pid);
ret = put_user(mode_waiting, mode);
}
@@ -455,8 +455,8 @@ static int vchiq_ioc_await_completion(struct vchiq_instance *instance,
mutex_lock(&instance->completion_mutex);
if (rc) {
DEBUG_TRACE(AWAIT_COMPLETION_LINE);
- vchiq_log_info(vchiq_arm_log_level,
- "AWAIT_COMPLETION interrupted");
+ vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
+ "AWAIT_COMPLETION interrupted");
ret = -EINTR;
goto out;
}
@@ -868,16 +868,17 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
ret = -EINTR;
}
- if (!status && (ret < 0) && (ret != -EINTR) && (ret != -EWOULDBLOCK))
- vchiq_log_info(vchiq_arm_log_level,
- " ioctl instance %pK, cmd %s -> status %d, %ld",
- instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
- ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
- else
+ if (!status && (ret < 0) && (ret != -EINTR) && (ret != -EWOULDBLOCK)) {
+ vchiq_log_debug(service->state->dev, VCHIQ_ARM,
+ " ioctl instance %pK, cmd %s -> status %d, %ld",
+ instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
+ ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
+ } else {
vchiq_log_trace(vchiq_arm_log_level,
" ioctl instance %pK, cmd %s -> status %d, %ld",
instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
+ }
return ret;
}
@@ -1170,7 +1171,7 @@ static int vchiq_open(struct inode *inode, struct file *file)
struct vchiq_state *state = vchiq_get_state();
struct vchiq_instance *instance;
- vchiq_log_info(vchiq_arm_log_level, "vchiq_open");
+ vchiq_log_debug(state->dev, VCHIQ_ARM, "vchiq_open");
if (!state) {
vchiq_log_error(state->dev, VCHIQ_ARM,
@@ -1206,8 +1207,8 @@ static int vchiq_release(struct inode *inode, struct file *file)
int ret = 0;
int i;
- vchiq_log_info(vchiq_arm_log_level, "%s: instance=%lx", __func__,
- (unsigned long)instance);
+ vchiq_log_debug(state->dev, VCHIQ_ARM, "%s: instance=%lx", __func__,
+ (unsigned long)instance);
if (!state) {
ret = -EPERM;
--
2.40.1
^ permalink raw reply related [flat|nested] 10+ messages in thread
* [PATCH v1 4/4] staging: vc04: Convert vchiq_log_trace() to use dynamic debug
2023-10-19 8:21 [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Umang Jain
` (2 preceding siblings ...)
2023-10-19 8:21 ` [PATCH v1 3/4] staging: vc04: Convert(and rename) vchiq_log_info() " Umang Jain
@ 2023-10-19 8:21 ` Umang Jain
2023-10-19 13:56 ` Kieran Bingham
2023-10-19 13:58 ` [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Kieran Bingham
4 siblings, 1 reply; 10+ messages in thread
From: Umang Jain @ 2023-10-19 8:21 UTC (permalink / raw)
To: linux-staging, linux-rpi-kernel, linux-media, linux-arm-kernel
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Kieran Bingham, Laurent Pinchart, Umang Jain
Move vchiq_log_trace() custom logging wrapper based on printk
to use dynamic debug. The log category is dictated by enum
vchiq_log_category which will become the part of the trace
string format that will be logged to dynamic debug (for grep).
All the vchiq_log_trace() calls are adjusted to use the
modified wrapper.
vchiq_log_dump_mem() doesn't has access to struct device pointer.
It will be logged to dynamic debug by passing NULL to vchiq_log_trace()
which shall log it using pr_debug().
Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
.../interface/vchiq_arm/vchiq_arm.c | 45 ++++++++++-------
.../interface/vchiq_arm/vchiq_core.c | 50 +++++++++++--------
.../interface/vchiq_arm/vchiq_core.h | 8 +--
.../interface/vchiq_arm/vchiq_dev.c | 4 +-
4 files changed, 64 insertions(+), 43 deletions(-)
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
index b4d20f9a4e47..61e7e9b0dd2f 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -259,7 +259,8 @@ create_pagelist(struct vchiq_instance *instance, char *buf, char __user *ubuf,
pagelist = dma_alloc_coherent(instance->state->dev, pagelist_size, &dma_addr,
GFP_KERNEL);
- vchiq_log_trace(vchiq_arm_log_level, "%s - %pK", __func__, pagelist);
+ vchiq_log_trace(instance->state->dev, VCHIQ_ARM,
+ "%s - %pK", __func__, pagelist);
if (!pagelist)
return NULL;
@@ -410,8 +411,8 @@ free_pagelist(struct vchiq_instance *instance, struct vchiq_pagelist_info *pagel
struct page **pages = pagelistinfo->pages;
unsigned int num_pages = pagelistinfo->num_pages;
- vchiq_log_trace(vchiq_arm_log_level, "%s - %pK, %d",
- __func__, pagelistinfo->pagelist, actual);
+ vchiq_log_trace(instance->state->dev, VCHIQ_ARM,
+ "%s - %pK, %d", __func__, pagelistinfo->pagelist, actual);
/*
* NOTE: dma_unmap_sg must be called before the
@@ -717,7 +718,8 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
ret = 0;
failed:
- vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, ret);
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
+ "%s(%p): returning %d", __func__, instance, ret);
return ret;
}
@@ -750,7 +752,8 @@ int vchiq_shutdown(struct vchiq_instance *instance)
mutex_unlock(&state->mutex);
- vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
+ "%s(%p): returning %d", __func__, instance, status);
free_bulk_waiter(instance);
kfree(instance);
@@ -770,7 +773,8 @@ int vchiq_connect(struct vchiq_instance *instance)
struct vchiq_state *state = instance->state;
if (mutex_lock_killable(&state->mutex)) {
- vchiq_log_trace(vchiq_core_log_level, "%s: call to mutex_lock failed", __func__);
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
+ "%s: call to mutex_lock failed", __func__);
status = -EAGAIN;
goto failed;
}
@@ -782,7 +786,8 @@ int vchiq_connect(struct vchiq_instance *instance)
mutex_unlock(&state->mutex);
failed:
- vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
+ "%s(%p): returning %d", __func__, instance, status);
return status;
}
@@ -813,7 +818,8 @@ vchiq_add_service(struct vchiq_instance *instance,
status = -EINVAL;
}
- vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
+ "%s(%p): returning %d", __func__, instance, status);
return status;
}
@@ -844,7 +850,8 @@ vchiq_open_service(struct vchiq_instance *instance,
}
failed:
- vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
+ "%s(%p): returning %d", __func__, instance, status);
return status;
}
@@ -1014,7 +1021,8 @@ add_completion(struct vchiq_instance *instance, enum vchiq_reason reason,
while ((insert - instance->completion_remove) >= MAX_COMPLETIONS) {
/* Out of space - wait for the client */
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
- vchiq_log_trace(vchiq_arm_log_level, "%s - completion queue full", __func__);
+ vchiq_log_trace(instance->state->dev, VCHIQ_CORE,
+ "%s - completion queue full", __func__);
DEBUG_COUNT(COMPLETION_QUEUE_FULL_COUNT);
if (wait_for_completion_interruptible(&instance->remove_event)) {
vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
@@ -1102,7 +1110,7 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
vchiq_service_get(service);
rcu_read_unlock();
- vchiq_log_trace(vchiq_arm_log_level,
+ vchiq_log_trace(service->state->dev, VCHIQ_ARM,
"%s - service %lx(%d,%p), reason %d, header %lx, instance %lx, bulk_userdata %lx",
__func__, (unsigned long)user_service, service->localport,
user_service->userdata, reason, (unsigned long)header,
@@ -1115,7 +1123,8 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
spin_unlock(&msg_queue_spinlock);
DEBUG_TRACE(SERVICE_CALLBACK_LINE);
DEBUG_COUNT(MSG_QUEUE_FULL_COUNT);
- vchiq_log_trace(vchiq_arm_log_level, "%s - msg queue full", __func__);
+ vchiq_log_trace(service->state->dev, VCHIQ_ARM,
+ "%s - msg queue full", __func__);
/*
* If there is no MESSAGE_AVAILABLE in the completion
* queue, add one
@@ -1463,8 +1472,8 @@ vchiq_use_internal(struct vchiq_state *state, struct vchiq_service *service,
local_uc = ++arm_state->videocore_use_count;
++(*entity_uc);
- vchiq_log_trace(vchiq_susp_log_level, "%s %s count %d, state count %d", __func__, entity,
- *entity_uc, local_uc);
+ vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s %s count %d, state count %d",
+ __func__, entity, *entity_uc, local_uc);
write_unlock_bh(&arm_state->susp_res_lock);
@@ -1483,7 +1492,7 @@ vchiq_use_internal(struct vchiq_state *state, struct vchiq_service *service,
}
out:
- vchiq_log_trace(vchiq_susp_log_level, "%s exit %d", __func__, ret);
+ vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s exit %d", __func__, ret);
return ret;
}
@@ -1521,14 +1530,14 @@ vchiq_release_internal(struct vchiq_state *state, struct vchiq_service *service)
--arm_state->videocore_use_count;
--(*entity_uc);
- vchiq_log_trace(vchiq_susp_log_level, "%s %s count %d, state count %d", __func__, entity,
- *entity_uc, arm_state->videocore_use_count);
+ vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s %s count %d, state count %d",
+ __func__, entity, *entity_uc, arm_state->videocore_use_count);
unlock:
write_unlock_bh(&arm_state->susp_res_lock);
out:
- vchiq_log_trace(vchiq_susp_log_level, "%s exit %d", __func__, ret);
+ vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s exit %d", __func__, ret);
return ret;
}
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
index 43c900b0729b..fb1a57bb0178 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
@@ -467,7 +467,7 @@ make_service_callback(struct vchiq_service *service, enum vchiq_reason reason,
{
int status;
- vchiq_log_trace(vchiq_core_log_level, "%d: callback:%d (%s, %pK, %pK)",
+ vchiq_log_trace(service->state->dev, VCHIQ_CORE, "%d: callback:%d (%s, %pK, %pK)",
service->state->id, service->localport, reason_names[reason],
header, bulk_userdata);
status = service->base.callback(service->instance, reason, header, service->handle,
@@ -771,7 +771,7 @@ process_free_data_message(struct vchiq_state *state, u32 *service_found,
* it has dropped below its quota
*/
complete("a->quota_event);
- vchiq_log_trace(vchiq_core_log_level, "%d: pfq:%d %x@%pK - slot_use->%d",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: pfq:%d %x@%pK - slot_use->%d",
state->id, port, header->size, header, count - 1);
} else {
vchiq_log_error(state->dev, VCHIQ_CORE,
@@ -817,7 +817,7 @@ process_free_queue(struct vchiq_state *state, u32 *service_found,
*/
rmb();
- vchiq_log_trace(vchiq_core_log_level, "%d: pfq %d=%pK %x %x",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: pfq %d=%pK %x %x",
state->id, slot_index, data, local->slot_queue_recycle,
slot_queue_available);
@@ -988,7 +988,7 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
((tx_end_index != quota->previous_tx_index) &&
(quota->slot_use_count == quota->slot_quota))) {
spin_unlock("a_spinlock);
- vchiq_log_trace(vchiq_core_log_level,
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
"%d: qm:%d %s,%zx - quota stall (msg %d, slot %d)",
state->id, service->localport, msg_type_str(type), size,
quota->message_use_count, quota->slot_use_count);
@@ -1083,7 +1083,7 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
spin_unlock("a_spinlock);
if (slot_use_count)
- vchiq_log_trace(vchiq_core_log_level,
+ vchiq_log_trace(state->dev, VCHIQ_CORE,
"%d: qm:%d %s,%zx - slot_use->%d (hdr %p)", state->id,
service->localport, msg_type_str(VCHIQ_MSG_TYPE(msgid)),
size, slot_use_count, header);
@@ -1219,7 +1219,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
? service->base.fourcc
: VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
- vchiq_log_trace(vchiq_sync_log_level,
+ vchiq_log_trace(state->dev, VCHIQ_SYNC,
"Sent Sync Msg %s(%u) to %c%c%c%c s:%u d:%d len:%d",
msg_type_str(VCHIQ_MSG_TYPE(msgid)), VCHIQ_MSG_TYPE(msgid),
VCHIQ_FOURCC_AS_4CHARS(svc_fourcc), VCHIQ_MSG_SRCPORT(msgid),
@@ -1313,8 +1313,10 @@ notify_bulks(struct vchiq_service *service, struct vchiq_bulk_queue *queue,
{
int status = 0;
- vchiq_log_trace(vchiq_core_log_level, "%d: nb:%d %cx - p=%x rn=%x r=%x", service->state->id,
- service->localport, (queue == &service->bulk_tx) ? 't' : 'r',
+ vchiq_log_trace(service->state->dev, VCHIQ_CORE,
+ "%d: nb:%d %cx - p=%x rn=%x r=%x",
+ service->state->id, service->localport,
+ (queue == &service->bulk_tx) ? 't' : 'r',
queue->process, queue->remote_notify, queue->remove);
queue->remote_notify = queue->process;
@@ -1438,9 +1440,11 @@ abort_outstanding_bulks(struct vchiq_service *service,
{
int is_tx = (queue == &service->bulk_tx);
- vchiq_log_trace(vchiq_core_log_level, "%d: aob:%d %cx - li=%x ri=%x p=%x",
- service->state->id, service->localport, is_tx ? 't' : 'r',
- queue->local_insert, queue->remote_insert, queue->process);
+ vchiq_log_trace(service->state->dev, VCHIQ_CORE,
+ "%d: aob:%d %cx - li=%x ri=%x p=%x",
+ service->state->id, service->localport,
+ is_tx ? 't' : 'r', queue->local_insert,
+ queue->remote_insert, queue->process);
WARN_ON((int)(queue->local_insert - queue->process) < 0);
WARN_ON((int)(queue->remote_insert - queue->process) < 0);
@@ -1780,7 +1784,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
state->id, msg_type_str(type), header, remoteport,
localport, bulk->actual, &bulk->data);
- vchiq_log_trace(vchiq_core_log_level, "%d: prs:%d %cx li=%x ri=%x p=%x",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs:%d %cx li=%x ri=%x p=%x",
state->id, localport,
(type == VCHIQ_MSG_BULK_RX_DONE) ? 'r' : 't',
queue->local_insert, queue->remote_insert, queue->process);
@@ -1796,12 +1800,12 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
}
break;
case VCHIQ_MSG_PADDING:
- vchiq_log_trace(vchiq_core_log_level, "%d: prs PADDING@%pK,%x",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs PADDING@%pK,%x",
state->id, header, size);
break;
case VCHIQ_MSG_PAUSE:
/* If initiated, signal the application thread */
- vchiq_log_trace(vchiq_core_log_level, "%d: prs PAUSE@%pK,%x",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs PAUSE@%pK,%x",
state->id, header, size);
if (state->conn_state == VCHIQ_CONNSTATE_PAUSED) {
vchiq_log_error(state->dev, VCHIQ_CORE,
@@ -1818,7 +1822,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
vchiq_set_conn_state(state, VCHIQ_CONNSTATE_PAUSED);
break;
case VCHIQ_MSG_RESUME:
- vchiq_log_trace(vchiq_core_log_level, "%d: prs RESUME@%pK,%x",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs RESUME@%pK,%x",
state->id, header, size);
/* Release the slot mutex */
mutex_unlock(&state->slot_mutex);
@@ -2059,7 +2063,7 @@ sync_func(void *v)
svc_fourcc = service
? service->base.fourcc
: VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
- vchiq_log_trace(vchiq_sync_log_level,
+ vchiq_log_trace(state->dev, VCHIQ_SYNC,
"Rcvd Msg %s from %c%c%c%c s:%d d:%d len:%d",
msg_type_str(type), VCHIQ_FOURCC_AS_4CHARS(svc_fourcc),
remoteport, localport, size);
@@ -2088,7 +2092,7 @@ sync_func(void *v)
break;
case VCHIQ_MSG_DATA:
- vchiq_log_trace(vchiq_sync_log_level, "%d: sf DATA@%pK,%x (%d->%d)",
+ vchiq_log_trace(state->dev, VCHIQ_SYNC, "%d: sf DATA@%pK,%x (%d->%d)",
state->id, header, size, remoteport, localport);
if ((service->remoteport == remoteport) &&
@@ -3132,7 +3136,7 @@ int vchiq_bulk_transfer(struct vchiq_instance *instance, unsigned int handle,
mutex_unlock(&state->slot_mutex);
mutex_unlock(&service->bulk_mutex);
- vchiq_log_trace(vchiq_core_log_level, "%d: bt:%d %cx li=%x ri=%x p=%x",
+ vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: bt:%d %cx li=%x ri=%x p=%x",
state->id, service->localport, dir_char, queue->local_insert,
queue->remote_insert, queue->process);
@@ -3668,10 +3672,16 @@ void vchiq_log_dump_mem(const char *label, u32 addr, const void *void_mem, size_
}
*s++ = '\0';
+ /* TODO: Since this is memory dump, it is better suited as debugfs entry only
+ * and prevent it from getting in dynamic debug log?
+ *
+ * In any case, some suggestions are required here.
+ * Convert to pr_debug() for now.
+ */
if (label && (*label != '\0'))
- vchiq_log_trace(VCHIQ_LOG_TRACE, "%s: %08x: %s", label, addr, line_buf);
+ vchiq_log_trace(NULL, VCHIQ_CORE, "%s: %08x: %s", label, addr, line_buf);
else
- vchiq_log_trace(VCHIQ_LOG_TRACE, "%08x: %s", addr, line_buf);
+ vchiq_log_trace(NULL, VCHIQ_CORE, "%s: %08x: %s", label, addr, line_buf);
addr += 16;
mem += 16;
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
index d0682a3e7a46..6f78527774b8 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -77,9 +77,11 @@ static inline const char *log_category_str(enum vchiq_log_category c)
do { dev_dbg(dev, "%s debug: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
#ifndef vchiq_log_trace
-#define vchiq_log_trace(cat, fmt, ...) \
- do { if (cat >= VCHIQ_LOG_TRACE) \
- printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
+#define vchiq_log_trace(dev, cat, fmt, ...) \
+ do { if (dev != NULL) \
+ dev_dbg(dev, "%s trace: " fmt, log_category_str(cat), ##__VA_ARGS__); \
+ else \
+ pr_debug("%s trace: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
#endif
#define VCHIQ_SLOT_MASK (VCHIQ_SLOT_SIZE - 1)
diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
index 4aea0a8fca49..f3208ea61e1d 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
@@ -582,7 +582,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
long ret = 0;
int i, rc;
- vchiq_log_trace(vchiq_arm_log_level,
+ vchiq_log_trace(instance->state->dev, VCHIQ_ARM,
"%s - instance %pK, cmd %s, arg %lx", __func__, instance,
((_IOC_TYPE(cmd) == VCHIQ_IOC_MAGIC) && (_IOC_NR(cmd) <= VCHIQ_IOC_MAX)) ?
ioctl_names[_IOC_NR(cmd)] : "<invalid>", arg);
@@ -874,7 +874,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
} else {
- vchiq_log_trace(vchiq_arm_log_level,
+ vchiq_log_trace(service->state->dev, VCHIQ_ARM,
" ioctl instance %pK, cmd %s -> status %d, %ld",
instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
--
2.40.1
^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug
2023-10-19 8:21 ` [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
@ 2023-10-19 13:32 ` Kieran Bingham
2023-10-21 9:59 ` Greg Kroah-Hartman
1 sibling, 0 replies; 10+ messages in thread
From: Kieran Bingham @ 2023-10-19 13:32 UTC (permalink / raw)
To: Umang Jain, linux-arm-kernel, linux-media, linux-rpi-kernel,
linux-staging
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Laurent Pinchart, Umang Jain
Quoting Umang Jain (2023-10-19 09:21:44)
> Move vchiq_log_error() custom logging wrapper based on printk,
> to use dynamic debug. To categorise, enum vchiq_log_category
> has been introduced, which will become the part of the error
> string format that will be logged to dynamic debug (for grep).
>
> All the vchiq_log_error() calls are adjusted to use the
> dynamic debug wrapper. vchiq_loud_error_*() has been removed
> as a part of this patch and replaced with dev_err (so that
> they directly end up in kernel log, even if dynamic debug
> isn't enabled), which serves the purpose.
So far that looks quite reasonable to me. They all look like they are
'real error' messages indeed.
>
> For cases where struct device pointer `dev` is not available,
> NULL can be passed to vchiq_log_error() to log to dynamic debug
> using pr_debug().
That sounds reasonable.
I see two uses below. Maybe they could be inlined, but this way keeps
the category strings which may help a developer when grepping...
>
> Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
> ---
> .../interface/vchiq_arm/vchiq_arm.c | 36 ++++---
> .../interface/vchiq_arm/vchiq_connected.c | 2 +-
> .../interface/vchiq_arm/vchiq_core.c | 100 +++++++-----------
> .../interface/vchiq_arm/vchiq_core.h | 33 ++++--
> .../interface/vchiq_arm/vchiq_dev.c | 14 +--
> 5 files changed, 91 insertions(+), 94 deletions(-)
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> index eef9c8c06e66..fa4463bfc117 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> @@ -690,7 +690,8 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
> usleep_range(500, 600);
> }
> if (i == VCHIQ_INIT_RETRIES) {
> - vchiq_log_error(vchiq_core_log_level, "%s: videocore not initialized\n", __func__);
> + vchiq_log_error(state->dev, VCHIQ_CORE, "%s: videocore not initialized\n",
> + __func__);
> ret = -ENOTCONN;
> goto failed;
> } else if (i > 0) {
> @@ -700,7 +701,7 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
>
> instance = kzalloc(sizeof(*instance), GFP_KERNEL);
> if (!instance) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "%s: error allocating vchiq instance\n", __func__);
> ret = -ENOMEM;
> goto failed;
> @@ -966,7 +967,8 @@ vchiq_blocking_bulk_transfer(struct vchiq_instance *instance, unsigned int handl
> } else {
> waiter = kzalloc(sizeof(*waiter), GFP_KERNEL);
> if (!waiter) {
> - vchiq_log_error(vchiq_core_log_level, "%s - out of memory", __func__);
> + vchiq_log_error(service->state->dev, VCHIQ_CORE,
> + "%s - out of memory", __func__);
> return -ENOMEM;
> }
> }
> @@ -1333,7 +1335,8 @@ vchiq_keepalive_vchiq_callback(struct vchiq_instance *instance,
> struct vchiq_header *header,
> unsigned int service_user, void *bulk_user)
> {
> - vchiq_log_error(vchiq_susp_log_level, "%s callback reason %d", __func__, reason);
> + vchiq_log_error(instance->state->dev, VCHIQ_SUSPEND,
> + "%s callback reason %d", __func__, reason);
> return 0;
> }
>
> @@ -1357,22 +1360,22 @@ vchiq_keepalive_thread_func(void *v)
>
> ret = vchiq_initialise(&instance);
> if (ret) {
> - vchiq_log_error(vchiq_susp_log_level, "%s vchiq_initialise failed %d", __func__,
> - ret);
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> + "%s vchiq_initialise failed %d", __func__, ret);
> goto exit;
> }
>
> status = vchiq_connect(instance);
> if (status) {
> - vchiq_log_error(vchiq_susp_log_level, "%s vchiq_connect failed %d", __func__,
> - status);
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> + "%s vchiq_connect failed %d", __func__, status);
> goto shutdown;
> }
>
> status = vchiq_add_service(instance, ¶ms, &ka_handle);
> if (status) {
> - vchiq_log_error(vchiq_susp_log_level, "%s vchiq_open_service failed %d", __func__,
> - status);
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> + "%s vchiq_open_service failed %d", __func__, status);
> goto shutdown;
> }
>
> @@ -1380,7 +1383,8 @@ vchiq_keepalive_thread_func(void *v)
> long rc = 0, uc = 0;
>
> if (wait_for_completion_interruptible(&arm_state->ka_evt)) {
> - vchiq_log_error(vchiq_susp_log_level, "%s interrupted", __func__);
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> + "%s interrupted", __func__);
> flush_signals(current);
> continue;
> }
> @@ -1400,14 +1404,14 @@ vchiq_keepalive_thread_func(void *v)
> atomic_inc(&arm_state->ka_use_ack_count);
> status = vchiq_use_service(instance, ka_handle);
> if (status) {
> - vchiq_log_error(vchiq_susp_log_level,
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> "%s vchiq_use_service error %d", __func__, status);
> }
> }
> while (rc--) {
> status = vchiq_release_service(instance, ka_handle);
> if (status) {
> - vchiq_log_error(vchiq_susp_log_level,
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> "%s vchiq_release_service error %d", __func__,
> status);
> }
> @@ -1444,7 +1448,7 @@ vchiq_use_internal(struct vchiq_state *state, struct vchiq_service *service,
> service->client_id);
> entity_uc = &service->service_use_count;
> } else {
> - vchiq_log_error(vchiq_susp_log_level, "%s null service ptr", __func__);
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND, "%s null service ptr", __func__);
> ret = -EINVAL;
> goto out;
> }
> @@ -1725,7 +1729,7 @@ vchiq_check_service(struct vchiq_service *service)
> read_unlock_bh(&arm_state->susp_res_lock);
>
> if (ret) {
> - vchiq_log_error(vchiq_susp_log_level,
> + vchiq_log_error(service->state->dev, VCHIQ_SUSPEND,
> "%s ERROR - %c%c%c%c:%d service count %d, state count %d", __func__,
> VCHIQ_FOURCC_AS_4CHARS(service->base.fourcc), service->client_id,
> service->service_use_count, arm_state->videocore_use_count);
> @@ -1761,7 +1765,7 @@ void vchiq_platform_conn_state_changed(struct vchiq_state *state,
> (void *)state,
> threadname);
> if (IS_ERR(arm_state->ka_thread)) {
> - vchiq_log_error(vchiq_susp_log_level,
> + vchiq_log_error(state->dev, VCHIQ_SUSPEND,
> "vchiq: FATAL: couldn't create thread %s",
> threadname);
> } else {
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
> index bdb0ab617d8b..b3928bd8c9c6 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
> @@ -39,7 +39,7 @@ void vchiq_add_connected_callback(void (*callback)(void))
> callback();
> } else {
> if (g_num_deferred_callbacks >= MAX_CALLBACKS) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(NULL, VCHIQ_CORE,
> "There already %d callback registered - please increase MAX_CALLBACKS",
> g_num_deferred_callbacks);
Aha, here's a second use where we don't have access to a dev pointer.
> } else {
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> index 596894338cb4..f6032c6022cb 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> @@ -751,7 +751,7 @@ process_free_data_message(struct vchiq_state *state, u32 *service_found,
> */
> complete("a->quota_event);
> } else if (count == 0) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "service %d message_use_count=%d (header %pK, msgid %x, header->msgid %x, header->size %x)",
> port, quota->message_use_count, header, msgid, header->msgid,
> header->size);
> @@ -776,7 +776,7 @@ process_free_data_message(struct vchiq_state *state, u32 *service_found,
> vchiq_log_trace(vchiq_core_log_level, "%d: pfq:%d %x@%pK - slot_use->%d",
> state->id, port, header->size, header, count - 1);
> } else {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "service %d slot_use_count=%d (header %pK, msgid %x, header->msgid %x, header->size %x)",
> port, count, header, msgid, header->msgid, header->size);
> WARN(1, "bad slot use count\n");
> @@ -841,7 +841,7 @@ process_free_queue(struct vchiq_state *state, u32 *service_found,
>
> pos += calc_stride(header->size);
> if (pos > VCHIQ_SLOT_SIZE) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "pfq - pos %x: header %pK, msgid %x, header->msgid %x, header->size %x",
> pos, header, msgid, header->msgid, header->size);
> WARN(1, "invalid slot position\n");
> @@ -1178,7 +1178,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
> int oldmsgid = header->msgid;
>
> if (oldmsgid != VCHIQ_MSGID_PADDING)
> - vchiq_log_error(vchiq_core_log_level, "%d: qms - msgid %x, not PADDING",
> + vchiq_log_error(state->dev, VCHIQ_CORE, "%d: qms - msgid %x, not PADDING",
> state->id, oldmsgid);
> }
>
> @@ -1512,11 +1512,9 @@ parse_open(struct vchiq_state *state, struct vchiq_header *header)
>
> if ((service->version < version_min) || (version < service->version_min)) {
> /* Version mismatch */
> - vchiq_loud_error_header();
> - vchiq_loud_error("%d: service %d (%c%c%c%c) version mismatch - local (%d, min %d) vs. remote (%d, min %d)",
> - state->id, service->localport, VCHIQ_FOURCC_AS_4CHARS(fourcc),
> - service->version, service->version_min, version, version_min);
> - vchiq_loud_error_footer();
> + dev_err(state->dev, "%d: service %d (%c%c%c%c) version mismatch - local (%d, min %d) vs. remote (%d, min %d)",
> + state->id, service->localport, VCHIQ_FOURCC_AS_4CHARS(fourcc),
> + service->version, service->version_min, version, version_min);
> vchiq_service_put(service);
> service = NULL;
> goto fail_open;
> @@ -1631,7 +1629,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> }
>
> if (!service) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "%d: prs %s@%pK (%d->%d) - invalid/closed service %d",
> state->id, msg_type_str(type), header, remoteport,
> localport, localport);
> @@ -1658,7 +1656,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
>
> if (((unsigned long)header & VCHIQ_SLOT_MASK) +
> calc_stride(size) > VCHIQ_SLOT_SIZE) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "header %pK (msgid %x) - size %x too big for slot",
> header, (unsigned int)msgid, (unsigned int)size);
> WARN(1, "oversized for slot\n");
> @@ -1685,7 +1683,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> set_service_state(service, VCHIQ_SRVSTATE_OPEN);
> complete(&service->remove_event);
> } else {
> - vchiq_log_error(vchiq_core_log_level, "OPENACK received in state %s",
> + vchiq_log_error(state->dev, VCHIQ_CORE, "OPENACK received in state %s",
> srvstate_names[service->srvstate]);
> }
> break;
> @@ -1756,7 +1754,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> }
> if ((int)(queue->remote_insert -
> queue->local_insert) >= 0) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "%d: prs %s@%pK (%d->%d) unexpected (ri=%d,li=%d)",
> state->id, msg_type_str(type), header, remoteport,
> localport, queue->remote_insert,
> @@ -1805,8 +1803,8 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> vchiq_log_trace(vchiq_core_log_level, "%d: prs PAUSE@%pK,%x",
> state->id, header, size);
> if (state->conn_state == VCHIQ_CONNSTATE_PAUSED) {
> - vchiq_log_error(vchiq_core_log_level, "%d: PAUSE received in state PAUSED",
> - state->id);
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> + "%d: PAUSE received in state PAUSED", state->id);
> break;
> }
> if (state->conn_state != VCHIQ_CONNSTATE_PAUSE_SENT) {
> @@ -1836,7 +1834,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> break;
>
> default:
> - vchiq_log_error(vchiq_core_log_level, "%d: prs invalid msgid %x@%pK,%x",
> + vchiq_log_error(state->dev, VCHIQ_CORE, "%d: prs invalid msgid %x@%pK,%x",
> state->id, msgid, header, size);
> WARN(1, "invalid message\n");
> break;
> @@ -1947,7 +1945,7 @@ handle_poll(struct vchiq_state *state)
> * since the PAUSE should have flushed
> * through outstanding messages.
> */
> - vchiq_log_error(vchiq_core_log_level, "Failed to send RESUME message");
> + vchiq_log_error(state->dev, VCHIQ_CORE, "Failed to send RESUME message");
> }
> break;
> default:
> @@ -2046,7 +2044,7 @@ sync_func(void *v)
> service = find_service_by_port(state, localport);
>
> if (!service) {
> - vchiq_log_error(vchiq_sync_log_level,
> + vchiq_log_error(state->dev, VCHIQ_SYNC,
> "%d: sf %s@%pK (%d->%d) - invalid/closed service %d",
> state->id, msg_type_str(type), header,
> remoteport, localport, localport);
> @@ -2096,14 +2094,14 @@ sync_func(void *v)
> (service->srvstate == VCHIQ_SRVSTATE_OPENSYNC)) {
> if (make_service_callback(service, VCHIQ_MESSAGE_AVAILABLE, header,
> NULL) == -EAGAIN)
> - vchiq_log_error(vchiq_sync_log_level,
> + vchiq_log_error(state->dev, VCHIQ_SYNC,
> "synchronous callback to service %d returns -EAGAIN",
> localport);
> }
> break;
>
> default:
> - vchiq_log_error(vchiq_sync_log_level, "%d: sf unexpected msgid %x@%pK,%x",
> + vchiq_log_error(state->dev, VCHIQ_SYNC, "%d: sf unexpected msgid %x@%pK,%x",
> state->id, msgid, header, size);
> release_message_sync(state, header);
> break;
> @@ -2137,7 +2135,7 @@ vchiq_init_slots(void *mem_base, int mem_size)
> num_slots -= first_data_slot;
>
> if (num_slots < 4) {
> - vchiq_log_error(vchiq_core_log_level, "%s - insufficient memory %x bytes",
> + vchiq_log_error(NULL, VCHIQ_CORE, "%s - insufficient memory %x bytes",
> __func__, mem_size);
Is this the only call without a 'dev' pointer?
I wonder if this could just as easily be a pr_error directly.
<edit - no it's not the only one>
> return NULL;
> }
> @@ -2174,12 +2172,11 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
> remote = &slot_zero->master;
>
> if (local->initialised) {
> - vchiq_loud_error_header();
> if (remote->initialised)
> - vchiq_loud_error("local state has already been initialised");
> + dev_err(dev, "local state has already been initialised\n");
> else
> - vchiq_loud_error("master/slave mismatch two slaves");
> - vchiq_loud_error_footer();
> + dev_err(dev, "master/slave mismatch two slaves\n");
> +
> return -EINVAL;
> }
>
> @@ -2257,9 +2254,7 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
> state->slot_handler_thread = kthread_create(&slot_handler_func, (void *)state, threadname);
>
> if (IS_ERR(state->slot_handler_thread)) {
> - vchiq_loud_error_header();
> - vchiq_loud_error("couldn't create thread %s", threadname);
> - vchiq_loud_error_footer();
> + dev_err(state->dev, "couldn't create thread %s\n", threadname);
> return PTR_ERR(state->slot_handler_thread);
> }
> set_user_nice(state->slot_handler_thread, -19);
> @@ -2267,9 +2262,7 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
> snprintf(threadname, sizeof(threadname), "vchiq-recy/%d", state->id);
> state->recycle_thread = kthread_create(&recycle_func, (void *)state, threadname);
> if (IS_ERR(state->recycle_thread)) {
> - vchiq_loud_error_header();
> - vchiq_loud_error("couldn't create thread %s", threadname);
> - vchiq_loud_error_footer();
> + dev_err(state->dev, "couldn't create thread %s\n", threadname);
> ret = PTR_ERR(state->recycle_thread);
> goto fail_free_handler_thread;
> }
> @@ -2278,9 +2271,7 @@ vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, s
> snprintf(threadname, sizeof(threadname), "vchiq-sync/%d", state->id);
> state->sync_thread = kthread_create(&sync_func, (void *)state, threadname);
> if (IS_ERR(state->sync_thread)) {
> - vchiq_loud_error_header();
> - vchiq_loud_error("couldn't create thread %s", threadname);
> - vchiq_loud_error_footer();
> + dev_err(state->dev, "couldn't create thread %s\n", threadname);
> ret = PTR_ERR(state->sync_thread);
> goto fail_free_recycle_thread;
> }
> @@ -2353,10 +2344,11 @@ struct vchiq_header *vchiq_msg_hold(struct vchiq_instance *instance, unsigned in
> }
> EXPORT_SYMBOL(vchiq_msg_hold);
>
> -static int vchiq_validate_params(const struct vchiq_service_params_kernel *params)
> +static int vchiq_validate_params(struct vchiq_state *state,
> + const struct vchiq_service_params_kernel *params)
> {
> if (!params->callback || !params->fourcc) {
> - vchiq_loud_error("Can't add service, invalid params\n");
> + dev_err(state->dev, "Can't add service, invalid params\n");
> return -EINVAL;
> }
>
> @@ -2376,7 +2368,7 @@ vchiq_add_service_internal(struct vchiq_state *state,
> int ret;
> int i;
>
> - ret = vchiq_validate_params(params);
> + ret = vchiq_validate_params(state, params);
> if (ret)
> return NULL;
>
> @@ -2525,7 +2517,7 @@ vchiq_open_service_internal(struct vchiq_service *service, int client_id)
> } else if ((service->srvstate != VCHIQ_SRVSTATE_OPEN) &&
> (service->srvstate != VCHIQ_SRVSTATE_OPENSYNC)) {
> if (service->srvstate != VCHIQ_SRVSTATE_CLOSEWAIT)
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(service->state->dev, VCHIQ_CORE,
> "%d: osi - srvstate = %s (ref %u)",
> service->state->id,
> srvstate_names[service->srvstate],
> @@ -2589,7 +2581,7 @@ release_service_messages(struct vchiq_service *service)
> }
> pos += calc_stride(header->size);
> if (pos > VCHIQ_SLOT_SIZE) {
> - vchiq_log_error(vchiq_core_log_level,
> + vchiq_log_error(state->dev, VCHIQ_CORE,
> "fsi - pos %x: header %pK, msgid %x, header->msgid %x, header->size %x",
> pos, header, msgid, header->msgid, header->size);
> WARN(1, "invalid slot position\n");
> @@ -2645,8 +2637,8 @@ close_service_complete(struct vchiq_service *service, int failstate)
> case VCHIQ_SRVSTATE_LISTENING:
> break;
> default:
> - vchiq_log_error(vchiq_core_log_level, "%s(%x) called in state %s", __func__,
> - service->handle, srvstate_names[service->srvstate]);
> + vchiq_log_error(service->state->dev, VCHIQ_CORE, "%s(%x) called in state %s",
> + __func__, service->handle, srvstate_names[service->srvstate]);
> WARN(1, "%s in unexpected state\n", __func__);
> return -EINVAL;
> }
> @@ -2701,7 +2693,7 @@ vchiq_close_service_internal(struct vchiq_service *service, int close_recvd)
> case VCHIQ_SRVSTATE_LISTENING:
> case VCHIQ_SRVSTATE_CLOSEWAIT:
> if (close_recvd) {
> - vchiq_log_error(vchiq_core_log_level, "%s(1) called in state %s",
> + vchiq_log_error(state->dev, VCHIQ_CORE, "%s(1) called in state %s",
> __func__, srvstate_names[service->srvstate]);
> } else if (is_server) {
> if (service->srvstate == VCHIQ_SRVSTATE_LISTENING) {
> @@ -2789,7 +2781,7 @@ vchiq_close_service_internal(struct vchiq_service *service, int close_recvd)
> break;
>
> default:
> - vchiq_log_error(vchiq_core_log_level, "%s(%d) called in state %s", __func__,
> + vchiq_log_error(state->dev, VCHIQ_CORE, "%s(%d) called in state %s", __func__,
> close_recvd, srvstate_names[service->srvstate]);
> break;
> }
> @@ -2828,7 +2820,7 @@ vchiq_free_service_internal(struct vchiq_service *service)
> case VCHIQ_SRVSTATE_CLOSEWAIT:
> break;
> default:
> - vchiq_log_error(vchiq_core_log_level, "%d: fsi - (%d) in state %s", state->id,
> + vchiq_log_error(state->dev, VCHIQ_CORE, "%d: fsi - (%d) in state %s", state->id,
> service->localport, srvstate_names[service->srvstate]);
> return;
> }
> @@ -3628,26 +3620,6 @@ int vchiq_dump_service_state(void *dump_context, struct vchiq_service *service)
> return err;
> }
>
> -void
> -vchiq_loud_error_header(void)
> -{
> - vchiq_log_error(vchiq_core_log_level,
> - "============================================================================");
> - vchiq_log_error(vchiq_core_log_level,
> - "============================================================================");
> - vchiq_log_error(vchiq_core_log_level, "=====");
> -}
> -
> -void
> -vchiq_loud_error_footer(void)
> -{
> - vchiq_log_error(vchiq_core_log_level, "=====");
> - vchiq_log_error(vchiq_core_log_level,
> - "============================================================================");
> - vchiq_log_error(vchiq_core_log_level,
> - "============================================================================");
> -}
> -
> int vchiq_send_remote_use(struct vchiq_state *state)
> {
> if (state->conn_state == VCHIQ_CONNSTATE_DISCONNECTED)
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> index ec1a3caefaea..c74c3647ef60 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> @@ -6,6 +6,7 @@
>
> #include <linux/mutex.h>
> #include <linux/completion.h>
> +#include <linux/dev_printk.h>
> #include <linux/kthread.h>
> #include <linux/kref.h>
> #include <linux/rcupdate.h>
> @@ -39,10 +40,33 @@
>
> #define VCHIQ_LOG_PREFIX KERN_INFO "vchiq: "
>
> +enum vchiq_log_category {
> + VCHIQ_ARM,
> + VCHIQ_CORE,
> + VCHIQ_CORE_MSG,
> + VCHIQ_SYNC,
> + VCHIQ_SUSPEND,
> +};
> +
> +static inline const char *log_category_str(enum vchiq_log_category c)
> +{
> + static const char * const strings[] = {
> + "vchiq_arm",
> + "vchiq_core",
> + "vchiq_core_msg",
> + "vchiq_sync",
> + "vchiq_suspend",
> + };
> +
> + return strings[c];
> +};
> +
> #ifndef vchiq_log_error
> -#define vchiq_log_error(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_ERROR) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> +#define vchiq_log_error(dev, cat, fmt, ...) \
> + do { if (dev != NULL) \
> + dev_dbg(dev, "%s error: " fmt, log_category_str(cat), ##__VA_ARGS__); \
> + else \
> + pr_debug("%s error: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
> #endif
> #ifndef vchiq_log_warning
> #define vchiq_log_warning(cat, fmt, ...) \
> @@ -60,9 +84,6 @@
> printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> #endif
>
> -#define vchiq_loud_error(...) \
> - vchiq_log_error(vchiq_core_log_level, "===== " __VA_ARGS__)
> -
> #define VCHIQ_SLOT_MASK (VCHIQ_SLOT_SIZE - 1)
> #define VCHIQ_SLOT_QUEUE_MASK (VCHIQ_MAX_SLOTS_PER_SIDE - 1)
> #define VCHIQ_SLOT_ZERO_SLOTS DIV_ROUND_UP(sizeof(struct vchiq_slot_zero), \
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
> index 841e1a535642..c89dc6d82fd2 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
> @@ -271,7 +271,7 @@ static int vchiq_ioc_dequeue_message(struct vchiq_instance *instance,
> ret = -EFAULT;
> }
> } else {
> - vchiq_log_error(vchiq_arm_log_level,
> + vchiq_log_error(service->state->dev, VCHIQ_ARM,
> "header %pK: bufsize %x < size %x",
> header, args->bufsize, header->size);
> WARN(1, "invalid size\n");
> @@ -318,7 +318,7 @@ static int vchiq_irq_queue_bulk_tx_rx(struct vchiq_instance *instance,
> }
> mutex_unlock(&instance->bulk_waiter_list_mutex);
> if (!waiter) {
> - vchiq_log_error(vchiq_arm_log_level,
> + vchiq_log_error(service->state->dev, VCHIQ_ARM,
> "no bulk_waiter found for pid %d", current->pid);
> ret = -ESRCH;
> goto out;
> @@ -501,7 +501,7 @@ static int vchiq_ioc_await_completion(struct vchiq_instance *instance,
> msglen = header->size + sizeof(struct vchiq_header);
> /* This must be a VCHIQ-style service */
> if (args->msgbufsize < msglen) {
> - vchiq_log_error(vchiq_arm_log_level,
> + vchiq_log_error(service->state->dev, VCHIQ_ARM,
> "header %pK: msgbufsize %x < msglen %x",
> header, args->msgbufsize, msglen);
> WARN(1, "invalid message size\n");
> @@ -618,7 +618,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
> }
> rc = mutex_lock_killable(&instance->state->mutex);
> if (rc) {
> - vchiq_log_error(vchiq_arm_log_level,
> + vchiq_log_error(instance->state->dev, VCHIQ_ARM,
> "vchiq: connect: could not lock mutex for state %d: %d",
> instance->state->id, rc);
> ret = -EINTR;
> @@ -630,7 +630,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
> if (!status)
> instance->connected = 1;
> else
> - vchiq_log_error(vchiq_arm_log_level,
> + vchiq_log_error(instance->state->dev, VCHIQ_ARM,
> "vchiq: could not connect: %d", status);
> break;
>
> @@ -700,7 +700,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
> vchiq_use_service_internal(service) :
> vchiq_release_service_internal(service);
> if (ret) {
> - vchiq_log_error(vchiq_susp_log_level,
> + vchiq_log_error(service->state->dev, VCHIQ_SUSPEND,
> "%s: cmd %s returned error %ld for service %c%c%c%c:%03d",
> __func__, (cmd == VCHIQ_IOC_USE_SERVICE) ?
> "VCHIQ_IOC_USE_SERVICE" :
> @@ -1173,7 +1173,7 @@ static int vchiq_open(struct inode *inode, struct file *file)
> vchiq_log_info(vchiq_arm_log_level, "vchiq_open");
>
> if (!state) {
> - vchiq_log_error(vchiq_arm_log_level,
> + vchiq_log_error(state->dev, VCHIQ_ARM,
> "vchiq has no connection to VideoCore");
> return -ENOTCONN;
> }
> --
> 2.40.1
>
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v1 2/4] staging: vc04: Convert vchiq_log_warning() to use dynamic debug
2023-10-19 8:21 ` [PATCH v1 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
@ 2023-10-19 13:50 ` Kieran Bingham
0 siblings, 0 replies; 10+ messages in thread
From: Kieran Bingham @ 2023-10-19 13:50 UTC (permalink / raw)
To: Umang Jain, linux-arm-kernel, linux-media, linux-rpi-kernel,
linux-staging
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Laurent Pinchart, Umang Jain, Phil Elwell
Quoting Umang Jain (2023-10-19 09:21:45)
> Move vchiq_log_warning() custom logging wrapper based on printk to use
> dynamic debug. The log category is dictated by vchiq_log_category
> which will become the part of the warning string format that will be
> logged to dynamic debug (for grep).
>
> All the vchiq_log_warning() calls are adjusted to use the
> modified wrapper.
>
> While at that, remove the extraneous "----" from few of the
> warning string text.
>
> Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
> ---
> .../interface/vchiq_arm/vchiq_arm.c | 16 +++++++++-------
> .../interface/vchiq_arm/vchiq_core.c | 8 ++++----
> .../interface/vchiq_arm/vchiq_core.h | 5 ++---
> 3 files changed, 15 insertions(+), 14 deletions(-)
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> index fa4463bfc117..cfc06ca2e228 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> @@ -695,7 +695,7 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
> ret = -ENOTCONN;
> goto failed;
> } else if (i > 0) {
> - vchiq_log_warning(vchiq_core_log_level,
> + vchiq_log_warning(state->dev, VCHIQ_CORE,
> "%s: videocore initialized after %d retries\n", __func__, i);
> }
>
> @@ -1696,17 +1696,19 @@ vchiq_dump_service_use_state(struct vchiq_state *state)
> read_unlock_bh(&arm_state->susp_res_lock);
>
> if (only_nonzero)
> - vchiq_log_warning(vchiq_susp_log_level, "Too many active services (%d). Only dumping up to first %d services with non-zero use-count",
> + vchiq_log_warning(state->dev, VCHIQ_SUSPEND,
> + "Too many active services (%d). Only dumping up to first %d services with non-zero use-count",
> active_services, found);
>
> for (i = 0; i < found; i++) {
> - vchiq_log_warning(vchiq_susp_log_level, "----- %c%c%c%c:%d service count %d %s",
> + vchiq_log_warning(state->dev, VCHIQ_SUSPEND,
> + "%c%c%c%c:%d service count %d %s",
> VCHIQ_FOURCC_AS_4CHARS(service_data[i].fourcc),
I suspect VCHIQ_FOURCC_AS_4CHARS can now be replaced by "%p4cc"
vchiq_log_warning(state->dev, VCHIQ_SUSPEND, "%p4cc:%d service count %d %s",
service_data[i].fourcc, service_data[i].clientid, ...
But that can be a patch on top of this I think (including the removal of
VCHIQ_FOURCC_AS_4CHARS).
Otherwise, this is following the same pattern as before and looks ok to
me. I suspect an ack from Phil Elwell on the approach here would be
welcome, as looking back at the RFC that's where the concerns were on
the categories.
Reviewed-by: Kieran Bingham <kieran.bingham@ideasonboard.com>
> service_data[i].clientid, service_data[i].use_count,
> service_data[i].use_count ? nz : "");
> }
> - vchiq_log_warning(vchiq_susp_log_level, "----- VCHIQ use count %d", peer_count);
> - vchiq_log_warning(vchiq_susp_log_level, "--- Overall vchiq instance use count %d",
> + vchiq_log_warning(state->dev, VCHIQ_SUSPEND, "VCHIQ use count %d", peer_count);
> + vchiq_log_warning(state->dev, VCHIQ_SUSPEND, "Overall vchiq instance use count %d",
> vc_use_count);
>
> kfree(service_data);
> @@ -1822,7 +1824,7 @@ static int vchiq_probe(struct platform_device *pdev)
> */
> err = vchiq_register_chrdev(&pdev->dev);
> if (err) {
> - vchiq_log_warning(vchiq_arm_log_level,
> + vchiq_log_warning(&pdev->dev, VCHIQ_ARM,
> "Failed to initialize vchiq cdev");
> goto error_exit;
> }
> @@ -1833,7 +1835,7 @@ static int vchiq_probe(struct platform_device *pdev)
> return 0;
>
> failed_platform_init:
> - vchiq_log_warning(vchiq_arm_log_level, "could not initialize vchiq platform");
> + vchiq_log_warning(&pdev->dev, VCHIQ_ARM, "could not initialize vchiq platform");
> error_exit:
> return err;
> }
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> index f6032c6022cb..43e292512491 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> @@ -475,7 +475,7 @@ make_service_callback(struct vchiq_service *service, enum vchiq_reason reason,
> status = service->base.callback(service->instance, reason, header, service->handle,
> bulk_userdata);
> if (status && (status != -EAGAIN)) {
> - vchiq_log_warning(vchiq_core_log_level,
> + vchiq_log_warning(service->state->dev, VCHIQ_CORE,
> "%d: ignoring ERROR from callback to service %x",
> service->state->id, service->handle);
> status = 0;
> @@ -1622,7 +1622,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> vchiq_service_put(service);
> service = get_connected_service(state, remoteport);
> if (service)
> - vchiq_log_warning(vchiq_core_log_level,
> + vchiq_log_warning(state->dev, VCHIQ_CORE,
> "%d: prs %s@%pK (%d->%d) - found connected service %d",
> state->id, msg_type_str(type), header,
> remoteport, localport, service->localport);
> @@ -2921,7 +2921,7 @@ vchiq_close_service(struct vchiq_instance *instance, unsigned int handle)
> (service->srvstate == VCHIQ_SRVSTATE_OPEN))
> break;
>
> - vchiq_log_warning(vchiq_core_log_level,
> + vchiq_log_warning(service->state->dev, VCHIQ_CORE,
> "%d: close_service:%d - waiting in state %s",
> service->state->id, service->localport,
> srvstate_names[service->srvstate]);
> @@ -2982,7 +2982,7 @@ vchiq_remove_service(struct vchiq_instance *instance, unsigned int handle)
> (service->srvstate == VCHIQ_SRVSTATE_OPEN))
> break;
>
> - vchiq_log_warning(vchiq_core_log_level,
> + vchiq_log_warning(service->state->dev, VCHIQ_CORE,
> "%d: remove_service:%d - waiting in state %s",
> service->state->id, service->localport,
> srvstate_names[service->srvstate]);
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> index c74c3647ef60..3dbb1964839b 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> @@ -69,9 +69,8 @@ static inline const char *log_category_str(enum vchiq_log_category c)
> pr_debug("%s error: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
> #endif
> #ifndef vchiq_log_warning
> -#define vchiq_log_warning(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_WARNING) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> +#define vchiq_log_warning(dev, cat, fmt, ...) \
> + do { dev_dbg(dev, "%s warning: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
> #endif
> #ifndef vchiq_log_info
> #define vchiq_log_info(cat, fmt, ...) \
> --
> 2.40.1
>
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v1 4/4] staging: vc04: Convert vchiq_log_trace() to use dynamic debug
2023-10-19 8:21 ` [PATCH v1 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
@ 2023-10-19 13:56 ` Kieran Bingham
0 siblings, 0 replies; 10+ messages in thread
From: Kieran Bingham @ 2023-10-19 13:56 UTC (permalink / raw)
To: Umang Jain, linux-arm-kernel, linux-media, linux-rpi-kernel,
linux-staging
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Laurent Pinchart, Umang Jain
Quoting Umang Jain (2023-10-19 09:21:47)
> Move vchiq_log_trace() custom logging wrapper based on printk
> to use dynamic debug. The log category is dictated by enum
> vchiq_log_category which will become the part of the trace
> string format that will be logged to dynamic debug (for grep).
>
> All the vchiq_log_trace() calls are adjusted to use the
> modified wrapper.
>
> vchiq_log_dump_mem() doesn't has access to struct device pointer.
> It will be logged to dynamic debug by passing NULL to vchiq_log_trace()
> which shall log it using pr_debug().
>
> Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
> ---
> .../interface/vchiq_arm/vchiq_arm.c | 45 ++++++++++-------
> .../interface/vchiq_arm/vchiq_core.c | 50 +++++++++++--------
> .../interface/vchiq_arm/vchiq_core.h | 8 +--
> .../interface/vchiq_arm/vchiq_dev.c | 4 +-
> 4 files changed, 64 insertions(+), 43 deletions(-)
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> index b4d20f9a4e47..61e7e9b0dd2f 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> @@ -259,7 +259,8 @@ create_pagelist(struct vchiq_instance *instance, char *buf, char __user *ubuf,
> pagelist = dma_alloc_coherent(instance->state->dev, pagelist_size, &dma_addr,
> GFP_KERNEL);
>
> - vchiq_log_trace(vchiq_arm_log_level, "%s - %pK", __func__, pagelist);
> + vchiq_log_trace(instance->state->dev, VCHIQ_ARM,
> + "%s - %pK", __func__, pagelist);
>
> if (!pagelist)
> return NULL;
> @@ -410,8 +411,8 @@ free_pagelist(struct vchiq_instance *instance, struct vchiq_pagelist_info *pagel
> struct page **pages = pagelistinfo->pages;
> unsigned int num_pages = pagelistinfo->num_pages;
>
> - vchiq_log_trace(vchiq_arm_log_level, "%s - %pK, %d",
> - __func__, pagelistinfo->pagelist, actual);
> + vchiq_log_trace(instance->state->dev, VCHIQ_ARM,
> + "%s - %pK, %d", __func__, pagelistinfo->pagelist, actual);
>
> /*
> * NOTE: dma_unmap_sg must be called before the
> @@ -717,7 +718,8 @@ int vchiq_initialise(struct vchiq_instance **instance_out)
> ret = 0;
>
> failed:
> - vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, ret);
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> + "%s(%p): returning %d", __func__, instance, ret);
>
> return ret;
> }
> @@ -750,7 +752,8 @@ int vchiq_shutdown(struct vchiq_instance *instance)
>
> mutex_unlock(&state->mutex);
>
> - vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> + "%s(%p): returning %d", __func__, instance, status);
>
> free_bulk_waiter(instance);
> kfree(instance);
> @@ -770,7 +773,8 @@ int vchiq_connect(struct vchiq_instance *instance)
> struct vchiq_state *state = instance->state;
>
> if (mutex_lock_killable(&state->mutex)) {
> - vchiq_log_trace(vchiq_core_log_level, "%s: call to mutex_lock failed", __func__);
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> + "%s: call to mutex_lock failed", __func__);
> status = -EAGAIN;
> goto failed;
> }
> @@ -782,7 +786,8 @@ int vchiq_connect(struct vchiq_instance *instance)
> mutex_unlock(&state->mutex);
>
> failed:
> - vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> + "%s(%p): returning %d", __func__, instance, status);
>
> return status;
> }
> @@ -813,7 +818,8 @@ vchiq_add_service(struct vchiq_instance *instance,
> status = -EINVAL;
> }
>
> - vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> + "%s(%p): returning %d", __func__, instance, status);
>
> return status;
> }
> @@ -844,7 +850,8 @@ vchiq_open_service(struct vchiq_instance *instance,
> }
>
> failed:
> - vchiq_log_trace(vchiq_core_log_level, "%s(%p): returning %d", __func__, instance, status);
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> + "%s(%p): returning %d", __func__, instance, status);
>
> return status;
> }
> @@ -1014,7 +1021,8 @@ add_completion(struct vchiq_instance *instance, enum vchiq_reason reason,
> while ((insert - instance->completion_remove) >= MAX_COMPLETIONS) {
> /* Out of space - wait for the client */
> DEBUG_TRACE(SERVICE_CALLBACK_LINE);
> - vchiq_log_trace(vchiq_arm_log_level, "%s - completion queue full", __func__);
> + vchiq_log_trace(instance->state->dev, VCHIQ_CORE,
> + "%s - completion queue full", __func__);
> DEBUG_COUNT(COMPLETION_QUEUE_FULL_COUNT);
> if (wait_for_completion_interruptible(&instance->remove_event)) {
> vchiq_log_debug(instance->state->dev, VCHIQ_ARM,
> @@ -1102,7 +1110,7 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
> vchiq_service_get(service);
> rcu_read_unlock();
>
> - vchiq_log_trace(vchiq_arm_log_level,
> + vchiq_log_trace(service->state->dev, VCHIQ_ARM,
> "%s - service %lx(%d,%p), reason %d, header %lx, instance %lx, bulk_userdata %lx",
> __func__, (unsigned long)user_service, service->localport,
> user_service->userdata, reason, (unsigned long)header,
> @@ -1115,7 +1123,8 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
> spin_unlock(&msg_queue_spinlock);
> DEBUG_TRACE(SERVICE_CALLBACK_LINE);
> DEBUG_COUNT(MSG_QUEUE_FULL_COUNT);
> - vchiq_log_trace(vchiq_arm_log_level, "%s - msg queue full", __func__);
> + vchiq_log_trace(service->state->dev, VCHIQ_ARM,
> + "%s - msg queue full", __func__);
> /*
> * If there is no MESSAGE_AVAILABLE in the completion
> * queue, add one
> @@ -1463,8 +1472,8 @@ vchiq_use_internal(struct vchiq_state *state, struct vchiq_service *service,
> local_uc = ++arm_state->videocore_use_count;
> ++(*entity_uc);
>
> - vchiq_log_trace(vchiq_susp_log_level, "%s %s count %d, state count %d", __func__, entity,
> - *entity_uc, local_uc);
> + vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s %s count %d, state count %d",
> + __func__, entity, *entity_uc, local_uc);
>
> write_unlock_bh(&arm_state->susp_res_lock);
>
> @@ -1483,7 +1492,7 @@ vchiq_use_internal(struct vchiq_state *state, struct vchiq_service *service,
> }
>
> out:
> - vchiq_log_trace(vchiq_susp_log_level, "%s exit %d", __func__, ret);
> + vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s exit %d", __func__, ret);
> return ret;
> }
>
> @@ -1521,14 +1530,14 @@ vchiq_release_internal(struct vchiq_state *state, struct vchiq_service *service)
> --arm_state->videocore_use_count;
> --(*entity_uc);
>
> - vchiq_log_trace(vchiq_susp_log_level, "%s %s count %d, state count %d", __func__, entity,
> - *entity_uc, arm_state->videocore_use_count);
> + vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s %s count %d, state count %d",
> + __func__, entity, *entity_uc, arm_state->videocore_use_count);
>
> unlock:
> write_unlock_bh(&arm_state->susp_res_lock);
>
> out:
> - vchiq_log_trace(vchiq_susp_log_level, "%s exit %d", __func__, ret);
> + vchiq_log_trace(state->dev, VCHIQ_SUSPEND, "%s exit %d", __func__, ret);
> return ret;
> }
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> index 43c900b0729b..fb1a57bb0178 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> @@ -467,7 +467,7 @@ make_service_callback(struct vchiq_service *service, enum vchiq_reason reason,
> {
> int status;
>
> - vchiq_log_trace(vchiq_core_log_level, "%d: callback:%d (%s, %pK, %pK)",
> + vchiq_log_trace(service->state->dev, VCHIQ_CORE, "%d: callback:%d (%s, %pK, %pK)",
> service->state->id, service->localport, reason_names[reason],
> header, bulk_userdata);
> status = service->base.callback(service->instance, reason, header, service->handle,
> @@ -771,7 +771,7 @@ process_free_data_message(struct vchiq_state *state, u32 *service_found,
> * it has dropped below its quota
> */
> complete("a->quota_event);
> - vchiq_log_trace(vchiq_core_log_level, "%d: pfq:%d %x@%pK - slot_use->%d",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: pfq:%d %x@%pK - slot_use->%d",
> state->id, port, header->size, header, count - 1);
> } else {
> vchiq_log_error(state->dev, VCHIQ_CORE,
> @@ -817,7 +817,7 @@ process_free_queue(struct vchiq_state *state, u32 *service_found,
> */
> rmb();
>
> - vchiq_log_trace(vchiq_core_log_level, "%d: pfq %d=%pK %x %x",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: pfq %d=%pK %x %x",
> state->id, slot_index, data, local->slot_queue_recycle,
> slot_queue_available);
>
> @@ -988,7 +988,7 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
> ((tx_end_index != quota->previous_tx_index) &&
> (quota->slot_use_count == quota->slot_quota))) {
> spin_unlock("a_spinlock);
> - vchiq_log_trace(vchiq_core_log_level,
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> "%d: qm:%d %s,%zx - quota stall (msg %d, slot %d)",
> state->id, service->localport, msg_type_str(type), size,
> quota->message_use_count, quota->slot_use_count);
> @@ -1083,7 +1083,7 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
> spin_unlock("a_spinlock);
>
> if (slot_use_count)
> - vchiq_log_trace(vchiq_core_log_level,
> + vchiq_log_trace(state->dev, VCHIQ_CORE,
> "%d: qm:%d %s,%zx - slot_use->%d (hdr %p)", state->id,
> service->localport, msg_type_str(VCHIQ_MSG_TYPE(msgid)),
> size, slot_use_count, header);
> @@ -1219,7 +1219,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
> ? service->base.fourcc
> : VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
>
> - vchiq_log_trace(vchiq_sync_log_level,
> + vchiq_log_trace(state->dev, VCHIQ_SYNC,
> "Sent Sync Msg %s(%u) to %c%c%c%c s:%u d:%d len:%d",
> msg_type_str(VCHIQ_MSG_TYPE(msgid)), VCHIQ_MSG_TYPE(msgid),
> VCHIQ_FOURCC_AS_4CHARS(svc_fourcc), VCHIQ_MSG_SRCPORT(msgid),
> @@ -1313,8 +1313,10 @@ notify_bulks(struct vchiq_service *service, struct vchiq_bulk_queue *queue,
> {
> int status = 0;
>
> - vchiq_log_trace(vchiq_core_log_level, "%d: nb:%d %cx - p=%x rn=%x r=%x", service->state->id,
> - service->localport, (queue == &service->bulk_tx) ? 't' : 'r',
> + vchiq_log_trace(service->state->dev, VCHIQ_CORE,
> + "%d: nb:%d %cx - p=%x rn=%x r=%x",
> + service->state->id, service->localport,
> + (queue == &service->bulk_tx) ? 't' : 'r',
> queue->process, queue->remote_notify, queue->remove);
>
> queue->remote_notify = queue->process;
> @@ -1438,9 +1440,11 @@ abort_outstanding_bulks(struct vchiq_service *service,
> {
> int is_tx = (queue == &service->bulk_tx);
>
> - vchiq_log_trace(vchiq_core_log_level, "%d: aob:%d %cx - li=%x ri=%x p=%x",
> - service->state->id, service->localport, is_tx ? 't' : 'r',
> - queue->local_insert, queue->remote_insert, queue->process);
> + vchiq_log_trace(service->state->dev, VCHIQ_CORE,
> + "%d: aob:%d %cx - li=%x ri=%x p=%x",
> + service->state->id, service->localport,
> + is_tx ? 't' : 'r', queue->local_insert,
> + queue->remote_insert, queue->process);
>
> WARN_ON((int)(queue->local_insert - queue->process) < 0);
> WARN_ON((int)(queue->remote_insert - queue->process) < 0);
> @@ -1780,7 +1784,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> state->id, msg_type_str(type), header, remoteport,
> localport, bulk->actual, &bulk->data);
>
> - vchiq_log_trace(vchiq_core_log_level, "%d: prs:%d %cx li=%x ri=%x p=%x",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs:%d %cx li=%x ri=%x p=%x",
> state->id, localport,
> (type == VCHIQ_MSG_BULK_RX_DONE) ? 'r' : 't',
> queue->local_insert, queue->remote_insert, queue->process);
> @@ -1796,12 +1800,12 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> }
> break;
> case VCHIQ_MSG_PADDING:
> - vchiq_log_trace(vchiq_core_log_level, "%d: prs PADDING@%pK,%x",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs PADDING@%pK,%x",
> state->id, header, size);
> break;
> case VCHIQ_MSG_PAUSE:
> /* If initiated, signal the application thread */
> - vchiq_log_trace(vchiq_core_log_level, "%d: prs PAUSE@%pK,%x",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs PAUSE@%pK,%x",
> state->id, header, size);
> if (state->conn_state == VCHIQ_CONNSTATE_PAUSED) {
> vchiq_log_error(state->dev, VCHIQ_CORE,
> @@ -1818,7 +1822,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> vchiq_set_conn_state(state, VCHIQ_CONNSTATE_PAUSED);
> break;
> case VCHIQ_MSG_RESUME:
> - vchiq_log_trace(vchiq_core_log_level, "%d: prs RESUME@%pK,%x",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: prs RESUME@%pK,%x",
> state->id, header, size);
> /* Release the slot mutex */
> mutex_unlock(&state->slot_mutex);
> @@ -2059,7 +2063,7 @@ sync_func(void *v)
> svc_fourcc = service
> ? service->base.fourcc
> : VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
> - vchiq_log_trace(vchiq_sync_log_level,
> + vchiq_log_trace(state->dev, VCHIQ_SYNC,
> "Rcvd Msg %s from %c%c%c%c s:%d d:%d len:%d",
> msg_type_str(type), VCHIQ_FOURCC_AS_4CHARS(svc_fourcc),
> remoteport, localport, size);
> @@ -2088,7 +2092,7 @@ sync_func(void *v)
> break;
>
> case VCHIQ_MSG_DATA:
> - vchiq_log_trace(vchiq_sync_log_level, "%d: sf DATA@%pK,%x (%d->%d)",
> + vchiq_log_trace(state->dev, VCHIQ_SYNC, "%d: sf DATA@%pK,%x (%d->%d)",
> state->id, header, size, remoteport, localport);
>
> if ((service->remoteport == remoteport) &&
> @@ -3132,7 +3136,7 @@ int vchiq_bulk_transfer(struct vchiq_instance *instance, unsigned int handle,
> mutex_unlock(&state->slot_mutex);
> mutex_unlock(&service->bulk_mutex);
>
> - vchiq_log_trace(vchiq_core_log_level, "%d: bt:%d %cx li=%x ri=%x p=%x",
> + vchiq_log_trace(state->dev, VCHIQ_CORE, "%d: bt:%d %cx li=%x ri=%x p=%x",
> state->id, service->localport, dir_char, queue->local_insert,
> queue->remote_insert, queue->process);
>
> @@ -3668,10 +3672,16 @@ void vchiq_log_dump_mem(const char *label, u32 addr, const void *void_mem, size_
> }
> *s++ = '\0';
>
> + /* TODO: Since this is memory dump, it is better suited as debugfs entry only
> + * and prevent it from getting in dynamic debug log?
> + *
> + * In any case, some suggestions are required here.
> + * Convert to pr_debug() for now.
> + */
I suspect it depends on how the callers are using this. Will they now
have lines which are off by default, while these memory dumps get
output?
What impact does basing this on top of Stefen Wahrens "[PATCH RFC]
staging: vchiq_arm: move state dump to debugfs" series have here?
> if (label && (*label != '\0'))
> - vchiq_log_trace(VCHIQ_LOG_TRACE, "%s: %08x: %s", label, addr, line_buf);
> + vchiq_log_trace(NULL, VCHIQ_CORE, "%s: %08x: %s", label, addr, line_buf);
> else
> - vchiq_log_trace(VCHIQ_LOG_TRACE, "%08x: %s", addr, line_buf);
> + vchiq_log_trace(NULL, VCHIQ_CORE, "%s: %08x: %s", label, addr, line_buf);
>
> addr += 16;
> mem += 16;
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> index d0682a3e7a46..6f78527774b8 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> @@ -77,9 +77,11 @@ static inline const char *log_category_str(enum vchiq_log_category c)
> do { dev_dbg(dev, "%s debug: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
> #endif
> #ifndef vchiq_log_trace
> -#define vchiq_log_trace(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_TRACE) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> +#define vchiq_log_trace(dev, cat, fmt, ...) \
> + do { if (dev != NULL) \
> + dev_dbg(dev, "%s trace: " fmt, log_category_str(cat), ##__VA_ARGS__); \
> + else \
> + pr_debug("%s trace: " fmt, log_category_str(cat), ##__VA_ARGS__); } while (0)
> #endif
>
> #define VCHIQ_SLOT_MASK (VCHIQ_SLOT_SIZE - 1)
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
> index 4aea0a8fca49..f3208ea61e1d 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_dev.c
> @@ -582,7 +582,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
> long ret = 0;
> int i, rc;
>
> - vchiq_log_trace(vchiq_arm_log_level,
> + vchiq_log_trace(instance->state->dev, VCHIQ_ARM,
> "%s - instance %pK, cmd %s, arg %lx", __func__, instance,
> ((_IOC_TYPE(cmd) == VCHIQ_IOC_MAGIC) && (_IOC_NR(cmd) <= VCHIQ_IOC_MAX)) ?
> ioctl_names[_IOC_NR(cmd)] : "<invalid>", arg);
> @@ -874,7 +874,7 @@ vchiq_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
> instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
> ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
> } else {
> - vchiq_log_trace(vchiq_arm_log_level,
> + vchiq_log_trace(service->state->dev, VCHIQ_ARM,
> " ioctl instance %pK, cmd %s -> status %d, %ld",
> instance, (_IOC_NR(cmd) <= VCHIQ_IOC_MAX) ?
> ioctl_names[_IOC_NR(cmd)] : "<invalid>", status, ret);
> --
> 2.40.1
>
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk
2023-10-19 8:21 [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Umang Jain
` (3 preceding siblings ...)
2023-10-19 8:21 ` [PATCH v1 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
@ 2023-10-19 13:58 ` Kieran Bingham
4 siblings, 0 replies; 10+ messages in thread
From: Kieran Bingham @ 2023-10-19 13:58 UTC (permalink / raw)
To: Umang Jain, linux-arm-kernel, linux-media, linux-rpi-kernel,
linux-staging
Cc: Stefan Wahren, Greg Kroah-Hartman, Dave Stevenson, Dan Carpenter,
Laurent Pinchart, Umang Jain
Quoting Umang Jain (2023-10-19 09:21:43)
> Hello,
>
> This series address the discussion on [1], i.e. removing the printk
> based logging mechanism and migrate it use dynamic debug.
Thank you - sounds like progress.
Is this series also already sufficient to consider the TODO at
drivers/staging/vc04_services/interface/TODO as addressed? if so - a
patch at the end of the series which removes the todo items would be
good to include in the series (and other cleanup series) so that the
TODO list gets updated as we progress.
--
Kieran
> Patch 1/4 targets migration of vchiq_log_error().
> Patch 2/4 targets migration of vchiq_log_warning().
> ... and so on.
>
> This series does not touch debugfs entries which are:
> DEBUG_INITIALISE, DEBUG_TRACE, DEBUG_VALUE and DEBUG_COUNT. As far as I
> understand from the previous discussions, those too should be moved
> to use dynamic debug as well (but is not part of this series yet), as
> I found there are more moving parts involved. I will build a series on
> top of this one, to move the debugfs entries to dynamic debug and remove
> all custom logging remanants (like VCHIQ_LOG_* macros, *_log_levels externs)
> because they do still tie into vchiq_debugfs.c.
>
> [1] https://lore.kernel.org/linux-media/20230913185528.770634-1-umang.jain@ideasonboard.com/
>
> Umang Jain (4):
> staging: vc04: Convert vchiq_log_error() to use dynamic debug
> staging: vc04: Convert vchiq_log_warning() to use dynamic debug
> staging: vc04: Convert(and rename) vchiq_log_info() to use dynamic
> debug
> staging: vc04: Convert vchiq_log_trace() to use dynamic debug
>
> .../interface/vchiq_arm/vchiq_arm.c | 143 ++++----
> .../interface/vchiq_arm/vchiq_connected.c | 2 +-
> .../interface/vchiq_arm/vchiq_core.c | 329 +++++++++---------
> .../interface/vchiq_arm/vchiq_core.h | 53 ++-
> .../interface/vchiq_arm/vchiq_dev.c | 59 ++--
> 5 files changed, 307 insertions(+), 279 deletions(-)
>
> --
> 2.40.1
>
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug
2023-10-19 8:21 ` [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
2023-10-19 13:32 ` Kieran Bingham
@ 2023-10-21 9:59 ` Greg Kroah-Hartman
1 sibling, 0 replies; 10+ messages in thread
From: Greg Kroah-Hartman @ 2023-10-21 9:59 UTC (permalink / raw)
To: Umang Jain
Cc: linux-staging, linux-rpi-kernel, linux-media, linux-arm-kernel,
Stefan Wahren, Dave Stevenson, Dan Carpenter, Kieran Bingham,
Laurent Pinchart
On Thu, Oct 19, 2023 at 01:51:44PM +0530, Umang Jain wrote:
> Move vchiq_log_error() custom logging wrapper based on printk,
> to use dynamic debug. To categorise, enum vchiq_log_category
> has been introduced, which will become the part of the error
> string format that will be logged to dynamic debug (for grep).
>
> All the vchiq_log_error() calls are adjusted to use the
> dynamic debug wrapper. vchiq_loud_error_*() has been removed
> as a part of this patch and replaced with dev_err (so that
> they directly end up in kernel log, even if dynamic debug
> isn't enabled), which serves the purpose.
>
> For cases where struct device pointer `dev` is not available,
> NULL can be passed to vchiq_log_error() to log to dynamic debug
> using pr_debug().
Ick, no, no need for that. Please don't have yet-another-logging-macro
for this subsystem, use the "real" ones, in the code, so that we don't
have to context-switch every time we come across one of these calls.
So use dev_*() for real, where all of these have device pointers. And
where they do not, use pr_*() so it stands out in bad ways so that those
places can then be fixed up to use the proper logging macros as well
(i.e. pass the device pointer into those functions in later patches.)
Same for the other patches in this series, let's make this simpler, not
more complex please.
thanks,
greg k-h
^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2023-10-21 9:59 UTC | newest]
Thread overview: 10+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-10-19 8:21 [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Umang Jain
2023-10-19 8:21 ` [PATCH v1 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
2023-10-19 13:32 ` Kieran Bingham
2023-10-21 9:59 ` Greg Kroah-Hartman
2023-10-19 8:21 ` [PATCH v1 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
2023-10-19 13:50 ` Kieran Bingham
2023-10-19 8:21 ` [PATCH v1 3/4] staging: vc04: Convert(and rename) vchiq_log_info() " Umang Jain
2023-10-19 8:21 ` [PATCH v1 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
2023-10-19 13:56 ` Kieran Bingham
2023-10-19 13:58 ` [PATCH v1 0/4] staging: vc04: Drop custom logging based on printk Kieran Bingham
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox