mirror of https://lore.kernel.org/lkml/
 help / color / mirror / Atom feed
* [RFC PATCH v2 0/4] staging: vc04: Drop custom logging
@ 2023-09-13 18:55 Umang Jain
  2023-09-13 18:55 ` [RFC PATCH v2 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
                   ` (4 more replies)
  0 siblings, 5 replies; 11+ messages in thread
From: Umang Jain @ 2023-09-13 18:55 UTC (permalink / raw)
  To: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel
  Cc: Stefan Wahren, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell, Umang Jain

Hello,

This series attempts to restart the discussion on custom logging used
in VC04. In the last feedback gathered in [1] it seems that the logging
would rather be moved to use dynamic debug. The series tries to move
in that direction.

The elephant in the room is the ability of turning on/off log levels,
which this series just drops. Compensated by a crude strings
("error", "warning", "info"... etc) for easier grepping.

The log category are also just strings (which probably can be transformed
to dynamic debug class names moving forwards?).

To move forwards, I would like feedback on the broader direction.
There are couple of TODOs in each of the patch (summarised in commit
messages) which require case-by-case discussion.

Additional high-level questions to move forwards:
1. Is loss of log levels by moving to dynamic debug, is actually a
   concern? Is dynamic debug a valid replacement?
2. Whether debugfs should be dropped as well, found vestigial in [2]
3. whether vchiq_log_trace() should actually be tracing support for VC04

All this is done to elimiate the TODO item in:
drivers/staging/vc04_services/interface/TODO
* Cleanup logging mechanism 

Addtional comments/questions are welcome.

Thank you.

Tested over media-tree master with dynamic debug configs enabled and
drivers/staging/vc04_services/interface/TESTING.

[1] https://lore.kernel.org/lkml/20230118115810.21979-1-umang.jain@ideasonboard.com/
[2] https://lore.kernel.org/lkml/Y8lHqd9FlxiXTLuW@kroah.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 vchiq_log_info() to use dynamic debug
  staging: vc04: Convert vchiq_log_trace() to use dynamic debug

 .../interface/vchiq_arm/vchiq_arm.c           | 127 +++++-----
 .../interface/vchiq_arm/vchiq_connected.c     |   6 +-
 .../interface/vchiq_arm/vchiq_core.c          | 225 ++++++++----------
 .../interface/vchiq_arm/vchiq_core.h          |  46 ++--
 .../interface/vchiq_arm/vchiq_dev.c           |  41 ++--
 5 files changed, 232 insertions(+), 213 deletions(-)


base-commit: 0bb80ecc33a8fb5a682236443c1e740d5c917d1d
-- 
2.40.1


^ permalink raw reply	[flat|nested] 11+ messages in thread

* [RFC PATCH v2 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug
  2023-09-13 18:55 [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Umang Jain
@ 2023-09-13 18:55 ` Umang Jain
  2023-09-13 18:55 ` [RFC PATCH v2 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
                   ` (3 subsequent siblings)
  4 siblings, 0 replies; 11+ messages in thread
From: Umang Jain @ 2023-09-13 18:55 UTC (permalink / raw)
  To: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel
  Cc: Stefan Wahren, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell, Umang Jain

Move custom logging 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.

vchiq_init_slots() signature has been adjusted to include
a struct device pointer, to facililate vchiq_log_error().

vchiq_validate_params() signature has been adjusted to
include struct vchiq_state parameter to access the
struct device pointer.

Call to vchiq_log_error() in vchiq_connected.c does not fit here,
since lack of struct device pointer. For now, it has been changed
to use pr_err() directly (marked as TODO to take a look later).

Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
 .../interface/vchiq_arm/vchiq_arm.c           |  37 ++++---
 .../interface/vchiq_arm/vchiq_connected.c     |   6 +-
 .../interface/vchiq_arm/vchiq_core.c          | 100 +++++++-----------
 .../interface/vchiq_arm/vchiq_core.h          |  31 ++++--
 .../interface/vchiq_arm/vchiq_dev.c           |  14 +--
 5 files changed, 90 insertions(+), 98 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 aa2313f3bcab..6e3cf05d7f6b 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -499,7 +499,7 @@ static int vchiq_platform_init(struct platform_device *pdev, struct vchiq_state
 
 	WARN_ON(((unsigned long)slot_mem & (PAGE_SIZE - 1)) != 0);
 
-	vchiq_slot_zero = vchiq_init_slots(slot_mem, slot_mem_size);
+	vchiq_slot_zero = vchiq_init_slots(dev, slot_mem, slot_mem_size);
 	if (!vchiq_slot_zero)
 		return -ENOMEM;
 
@@ -683,7 +683,7 @@ 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) {
@@ -693,7 +693,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;
@@ -959,7 +959,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;
 		}
 	}
@@ -1326,7 +1327,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;
 }
 
@@ -1350,22 +1352,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, &params, &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;
 	}
 
@@ -1373,7 +1375,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;
 		}
@@ -1393,14 +1396,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);
 			}
@@ -1437,7 +1440,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;
 	}
@@ -1718,7 +1721,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);
@@ -1754,7 +1757,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..a154aebebb64 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_connected.c
@@ -39,9 +39,9 @@ void vchiq_add_connected_callback(void (*callback)(void))
 		callback();
 	} else {
 		if (g_num_deferred_callbacks >= MAX_CALLBACKS) {
-			vchiq_log_error(vchiq_core_log_level,
-					"There already %d callback registered - please increase MAX_CALLBACKS",
-					g_num_deferred_callbacks);
+			/* TODO: Should be using vchiq_log_error() too? */
+			pr_err("There already %d callback registered - please increase MAX_CALLBACKS",
+			       g_num_deferred_callbacks);
 		} else {
 			g_deferred_callback[g_num_deferred_callbacks] =
 				callback;
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..add4a1ccd918 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(&quota->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,7 +1803,7 @@ 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",
+			vchiq_log_error(state->dev, VCHIQ_CORE, "%d: PAUSE received in state PAUSED",
 					state->id);
 			break;
 		}
@@ -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;
@@ -2122,7 +2120,7 @@ get_conn_state_name(enum vchiq_connstate conn_state)
 }
 
 struct vchiq_slot_zero *
-vchiq_init_slots(void *mem_base, int mem_size)
+vchiq_init_slots(struct device *dev, void *mem_base, int mem_size)
 {
 	int mem_align =
 		(int)((VCHIQ_SLOT_SIZE - (long)mem_base) & VCHIQ_SLOT_MASK);
@@ -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(dev, 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..4e531a066e67 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -39,10 +39,30 @@
 
 #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 *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, ...) \
+       dev_dbg(dev, "%s error: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #endif
 #ifndef vchiq_log_warning
 #define vchiq_log_warning(cat, fmt, ...) \
@@ -60,9 +80,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), \
@@ -471,7 +488,7 @@ extern const char *
 get_conn_state_name(enum vchiq_connstate conn_state);
 
 extern struct vchiq_slot_zero *
-vchiq_init_slots(void *mem_base, int mem_size);
+vchiq_init_slots(struct device *dev, void *mem_base, int mem_size);
 
 extern int
 vchiq_init_state(struct vchiq_state *state, struct vchiq_slot_zero *slot_zero, struct device *dev);
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] 11+ messages in thread

* [RFC PATCH v2 2/4] staging: vc04: Convert vchiq_log_warning() to use dynamic debug
  2023-09-13 18:55 [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Umang Jain
  2023-09-13 18:55 ` [RFC PATCH v2 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
@ 2023-09-13 18:55 ` Umang Jain
  2023-09-13 18:55 ` [RFC PATCH v2 3/4] staging: vc04: Convert vchiq_log_info() " Umang Jain
                   ` (2 subsequent siblings)
  4 siblings, 0 replies; 11+ messages in thread
From: Umang Jain @ 2023-09-13 18:55 UTC (permalink / raw)
  To: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel
  Cc: Stefan Wahren, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell, Umang Jain

As part of ongoing series i.e. moving away from printk
based logging to dynamic debug logging mechanism, this patch
converts vchiq_log_warning() wrapper to use dynamic debug.
The log category is dictated by enum 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.

Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
 .../interface/vchiq_arm/vchiq_arm.c             | 17 ++++++++++-------
 .../interface/vchiq_arm/vchiq_core.c            |  8 ++++----
 .../interface/vchiq_arm/vchiq_core.h            |  5 ++---
 3 files changed, 16 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 6e3cf05d7f6b..bac3c324b6be 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -687,7 +687,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);
 	}
 
@@ -1688,17 +1688,20 @@ 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);
@@ -1836,7 +1839,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;
 	}
@@ -1847,7 +1850,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 add4a1ccd918..d25733fa296d 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 4e531a066e67..c7ae2efc33eb 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -65,9 +65,8 @@ static inline const char *log_category_str(enum vchiq_log_category c)
        dev_dbg(dev, "%s error: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #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, ...) \
+       dev_dbg(dev, "%s warning: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #endif
 #ifndef vchiq_log_info
 #define vchiq_log_info(cat, fmt, ...) \
-- 
2.40.1


^ permalink raw reply	[flat|nested] 11+ messages in thread

* [RFC PATCH v2 3/4] staging: vc04: Convert vchiq_log_info() to use dynamic debug
  2023-09-13 18:55 [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Umang Jain
  2023-09-13 18:55 ` [RFC PATCH v2 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
  2023-09-13 18:55 ` [RFC PATCH v2 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
@ 2023-09-13 18:55 ` Umang Jain
  2023-09-14  6:38   ` Dan Carpenter
  2023-09-13 18:55 ` [RFC PATCH v2 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
  2023-09-14  6:35 ` [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Dan Carpenter
  4 siblings, 1 reply; 11+ messages in thread
From: Umang Jain @ 2023-09-13 18:55 UTC (permalink / raw)
  To: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel
  Cc: Stefan Wahren, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell, Umang Jain

As part of ongoing series i.e. moving away from printk
based logging to dynamic debug logging mechanism, this patch
converts vchiq_log_info() wrapper to use dynamic debug.
The log category is dictated by enum 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_info() calls are adjusted to use the
modified wrapper.

The existing custom logging for vchiq_log_info() tries
to log trace messages using SRVTRACE_LEVEL, which has been
removed in this patch. For now, those messages will be logged
to vchiq_log_info() but perhaps, should be using vchiq_log_trace()
down the line. (Marking as TODO for comments)

Signed-off-by: Umang Jain <umang.jain@ideasonboard.com>
---
 .../interface/vchiq_arm/vchiq_arm.c           | 28 +++++---
 .../interface/vchiq_arm/vchiq_core.c          | 67 ++++++++++---------
 .../interface/vchiq_arm/vchiq_core.h          |  5 +-
 .../interface/vchiq_arm/vchiq_dev.c           | 23 ++++---
 4 files changed, 65 insertions(+), 58 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 bac3c324b6be..a7da2f15d5d4 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -307,7 +307,7 @@ 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,
+			vchiq_log_info(instance->state->dev, VCHIQ_ARM,
 				       "%s - only %d/%d pages locked",
 				       __func__, actual_pages, num_pages);
 
@@ -552,7 +552,7 @@ 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_log_info(&pdev->dev, VCHIQ_ARM, "vchiq_init - done (slots %pK, phys %pad)",
 		       vchiq_slot_zero, &slot_phys);
 
 	vchiq_call_connected_callbacks();
@@ -722,7 +722,8 @@ 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",
+		vchiq_log_info(instance->state->dev, VCHIQ_ARM,
+			       "bulk_waiter - cleaned up %pK for pid %d",
 			       waiter, waiter->pid);
 		kfree(waiter);
 	}
@@ -983,7 +984,8 @@ 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,
+		vchiq_log_info(instance->state->dev, VCHIQ_ARM,
+			       "saved bulk_waiter %pK for pid %d", waiter,
 			       current->pid);
 	}
 
@@ -1007,10 +1009,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_info(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_info(instance->state->dev, VCHIQ_ARM,
+				       "service_callback closing");
 			return 0;
 		}
 		DEBUG_TRACE(SERVICE_CALLBACK_LINE);
@@ -1112,7 +1116,7 @@ service_callback(struct vchiq_instance *instance, enum vchiq_reason reason,
 				instance->completion_remove) < 0) {
 				int status;
 
-				vchiq_log_info(vchiq_arm_log_level,
+				vchiq_log_info(instance->state->dev, VCHIQ_ARM,
 					       "Inserting extra MESSAGE_AVAILABLE");
 				DEBUG_TRACE(SERVICE_CALLBACK_LINE);
 				status = add_completion(instance, reason, NULL, user_service,
@@ -1126,12 +1130,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_info(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_info(instance->state->dev, VCHIQ_ARM,
+					       "%s closing", __func__);
 				DEBUG_TRACE(SERVICE_CALLBACK_LINE);
 				vchiq_service_put(service);
 				return -EINVAL;
@@ -1741,7 +1747,7 @@ 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,
+	vchiq_log_info(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;
@@ -1829,7 +1835,7 @@ static int vchiq_probe(struct platform_device *pdev)
 
 	vchiq_debugfs_init();
 
-	vchiq_log_info(vchiq_arm_log_level,
+	vchiq_log_info(&pdev->dev, VCHIQ_ARM,
 		       "vchiq: platform initialised - version %d (min %d)",
 		       VCHIQ_VERSION, VCHIQ_VERSION_MIN);
 
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 d25733fa296d..2e92853b9a4b 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,7 +225,7 @@ 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",
+	vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: srv:%d %s->%s",
 		       service->state->id, service->localport,
 		       srvstate_names[service->srvstate],
 		       srvstate_names[newstate]);
@@ -255,7 +253,7 @@ find_service_by_handle(struct vchiq_instance *instance, unsigned int handle)
 		return service;
 	}
 	rcu_read_unlock();
-	vchiq_log_info(vchiq_core_log_level,
+	vchiq_log_info(service->state->dev, VCHIQ_CORE,
 		       "Invalid service handle 0x%x", handle);
 	return NULL;
 }
@@ -276,7 +274,7 @@ find_service_by_port(struct vchiq_state *state, unsigned int localport)
 		}
 		rcu_read_unlock();
 	}
-	vchiq_log_info(vchiq_core_log_level,
+	vchiq_log_info(state->dev, VCHIQ_CORE,
 		       "Invalid port %u", localport);
 	return NULL;
 }
@@ -297,7 +295,7 @@ find_service_for_instance(struct vchiq_instance *instance, unsigned int handle)
 		return service;
 	}
 	rcu_read_unlock();
-	vchiq_log_info(vchiq_core_log_level,
+	vchiq_log_info(service->state->dev, VCHIQ_CORE,
 		       "Invalid service handle 0x%x", handle);
 	return NULL;
 }
@@ -320,7 +318,7 @@ find_closed_service_for_instance(struct vchiq_instance *instance, unsigned int h
 		return service;
 	}
 	rcu_read_unlock();
-	vchiq_log_info(vchiq_core_log_level,
+	vchiq_log_info(service->state->dev, VCHIQ_CORE,
 		       "Invalid service handle 0x%x", handle);
 	return service;
 }
@@ -492,7 +490,7 @@ 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],
+	vchiq_log_info(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,7 +1031,7 @@ 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,
+		vchiq_log_info(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));
 
@@ -1093,7 +1091,7 @@ 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,
+		vchiq_log_info(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) {
@@ -1123,7 +1121,8 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
 			? service->base.fourcc
 			: VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
 
-		vchiq_log_info(SRVTRACE_LEVEL(service),
+		/* TODO: Should be using vchiq_log_trace below? */
+		vchiq_log_info(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),
@@ -1182,7 +1181,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
 					state->id, oldmsgid);
 	}
 
-	vchiq_log_info(vchiq_sync_log_level,
+	vchiq_log_info(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),
@@ -1278,7 +1277,7 @@ 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__,
+		vchiq_log_info(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);
 
@@ -1397,7 +1396,7 @@ 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",
+			vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: ps - remove %d<->%d",
 				       state->id, service->localport,
 				       service->remoteport);
 
@@ -1411,7 +1410,7 @@ 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",
+			vchiq_log_info(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,7 +1461,8 @@ 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),
+			/* TODO: Should be using vchiq_log_trace below? */
+			vchiq_log_info(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),
@@ -1499,7 +1499,7 @@ 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')",
+	vchiq_log_info(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);
@@ -1646,7 +1646,8 @@ 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),
+		/* TODO: Should be using vchiq_log_trace below? */
+		vchiq_log_info(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);
@@ -1675,7 +1676,7 @@ 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",
+		vchiq_log_info(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) {
@@ -1690,7 +1691,7 @@ 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)",
+		vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: prs CLOSE@%pK (%d->%d)",
 			       state->id, header, remoteport, localport);
 
 		mark_service_closing_internal(service, 1);
@@ -1698,12 +1699,12 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
 		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_log_info(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)",
+		vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: prs DATA@%pK,%x (%d->%d)",
 			       state->id, header, size, remoteport, localport);
 
 		if ((service->remoteport == remoteport) &&
@@ -1723,7 +1724,7 @@ 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_info(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,7 +1776,7 @@ 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",
+			vchiq_log_info(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);
 
@@ -2074,7 +2075,7 @@ 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",
+			vchiq_log_info(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) {
@@ -2478,7 +2479,7 @@ 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",
+	vchiq_log_info(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);
 
@@ -2576,7 +2577,7 @@ 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_info(service->state->dev, VCHIQ_CORE, "  fsi - hdr %pK", header);
 				release_slot(state, slot_info, header, NULL);
 			}
 			pos += calc_stride(header->size);
@@ -2684,7 +2685,7 @@ 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,
+	vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: csi:%d,%d (%s)", service->state->id,
 		       service->localport, close_recvd, srvstate_names[service->srvstate]);
 
 	switch (service->srvstate) {
@@ -2795,7 +2796,7 @@ 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,
+	vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: tsi - (%d<->%d)", state->id,
 		       service->localport, service->remoteport);
 
 	mark_service_closing(service);
@@ -2810,7 +2811,7 @@ 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_info(service->state->dev, VCHIQ_CORE, "%d: fsi - (%d)", state->id, service->localport);
 
 	switch (service->srvstate) {
 	case VCHIQ_SRVSTATE_OPENING:
@@ -2890,7 +2891,7 @@ 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",
+	vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: close_service:%d",
 		       service->state->id, service->localport);
 
 	if ((service->srvstate == VCHIQ_SRVSTATE_FREE) ||
@@ -2948,7 +2949,7 @@ 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",
+	vchiq_log_info(service->state->dev, VCHIQ_CORE, "%d: remove_service:%d",
 		       service->state->id, service->localport);
 
 	if (service->srvstate == VCHIQ_SRVSTATE_FREE) {
@@ -3092,7 +3093,7 @@ 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",
+	vchiq_log_info(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);
 
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 c7ae2efc33eb..07ce55afb6cf 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)
        dev_dbg(dev, "%s warning: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #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)
+#define vchiq_log_info(dev, cat, fmt, ...) \
+       dev_dbg(dev, "%s info: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #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..c525051f460e 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,
+	vchiq_log_info(user_service->service->state->dev, VCHIQ_ARM,
 		       "%s(handle=%x)",
-		       __func__, user_service->service->handle);
+			__func__, user_service->service->handle);
 
 	if (user_service->close_pending) {
 		/* Allow the underlying service to be culled */
@@ -235,7 +235,7 @@ 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,
+				vchiq_log_info(service->state->dev, VCHIQ_ARM,
 					       "DEQUEUE_MESSAGE interrupted");
 				ret = -EINTR;
 				break;
@@ -323,7 +323,7 @@ static int vchiq_irq_queue_bulk_tx_rx(struct vchiq_instance *instance,
 			ret = -ESRCH;
 			goto out;
 		}
-		vchiq_log_info(vchiq_arm_log_level,
+		vchiq_log_info(service->state->dev, VCHIQ_ARM,
 			       "found bulk_waiter %pK for pid %d", waiter, current->pid);
 		userdata = &waiter->bulk_waiter;
 	} else {
@@ -355,7 +355,7 @@ 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,
+		vchiq_log_info(service->state->dev, VCHIQ_ARM,
 			       "saved bulk_waiter %pK for pid %d", waiter, current->pid);
 
 		ret = put_user(mode_waiting, mode);
@@ -455,7 +455,7 @@ 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,
+			vchiq_log_info(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,
+	if (!status && (ret < 0) && (ret != -EINTR) && (ret != -EWOULDBLOCK)) {
+		vchiq_log_info(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
+	} 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_info(state->dev, VCHIQ_ARM, "vchiq_open");
 
 	if (!state) {
 		vchiq_log_error(state->dev, VCHIQ_ARM,
@@ -1206,7 +1207,7 @@ 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__,
+	vchiq_log_info(state->dev, VCHIQ_ARM, "%s: instance=%lx", __func__,
 		       (unsigned long)instance);
 
 	if (!state) {
-- 
2.40.1


^ permalink raw reply	[flat|nested] 11+ messages in thread

* [RFC PATCH v2 4/4] staging: vc04: Convert vchiq_log_trace() to use dynamic debug
  2023-09-13 18:55 [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Umang Jain
                   ` (2 preceding siblings ...)
  2023-09-13 18:55 ` [RFC PATCH v2 3/4] staging: vc04: Convert vchiq_log_info() " Umang Jain
@ 2023-09-13 18:55 ` Umang Jain
  2023-09-14  6:35 ` [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Dan Carpenter
  4 siblings, 0 replies; 11+ messages in thread
From: Umang Jain @ 2023-09-13 18:55 UTC (permalink / raw)
  To: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel
  Cc: Stefan Wahren, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell, Umang Jain

As part of ongoing series i.e. moving away from printk
based logging to dynamic debug logging mechanism, this patch
converts vchiq_log_trace() wrapper to use dynamic debug.
The log category is dictated by enum vchiq_log_category
which will become the part of the warning string format that
will be logged to dynamic debug (for easier grep).

All the vchiq_log_trace() calls are adjusted to use the
modified wrapper.

vchiq_log_dump_mem() doesn't seem to fit with vchiq_log_trace(),
Add a TODO marker to discuss whether or not, this should be
debugfs entry only.

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          |  5 +-
 .../interface/vchiq_arm/vchiq_dev.c           |  4 +-
 4 files changed, 61 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 a7da2f15d5d4..fa3316b10767 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
@@ -252,7 +252,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;
@@ -403,8 +404,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
@@ -709,7 +710,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;
 }
@@ -742,7 +744,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);
@@ -762,7 +765,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;
 	}
@@ -774,7 +778,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;
 }
@@ -805,7 +810,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;
 }
@@ -836,7 +842,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;
 }
@@ -1006,7 +1013,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_info(instance->state->dev, VCHIQ_ARM,
@@ -1094,7 +1102,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,
@@ -1107,7 +1115,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
@@ -1455,8 +1464,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);
 
@@ -1475,7 +1484,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;
 }
 
@@ -1513,14 +1522,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 2e92853b9a4b..550ce7062145 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(&quota->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(&quota_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(&quota_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);
@@ -1220,7 +1220,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),
@@ -1314,8 +1314,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;
@@ -1440,9 +1442,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, "%d: PAUSE received in state PAUSED",
@@ -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) &&
@@ -3130,7 +3134,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);
 
@@ -3666,10 +3670,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);
+			pr_debug("%s: %08x: %s", label, addr, line_buf);
 		else
-			vchiq_log_trace(VCHIQ_LOG_TRACE, "%08x: %s", addr, line_buf);
+			pr_debug("%08x: %s", 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 07ce55afb6cf..c6e40bfc0a23 100644
--- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
+++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
@@ -73,9 +73,8 @@ static inline const char *log_category_str(enum vchiq_log_category c)
        dev_dbg(dev, "%s info: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #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, ...) \
+       dev_dbg(dev, "%s trace: " fmt, log_category_str(cat), ##__VA_ARGS__);
 #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 c525051f460e..922f4c5a10c1 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] 11+ messages in thread

* Re: [RFC PATCH v2 0/4] staging: vc04: Drop custom logging
  2023-09-13 18:55 [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Umang Jain
                   ` (3 preceding siblings ...)
  2023-09-13 18:55 ` [RFC PATCH v2 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
@ 2023-09-14  6:35 ` Dan Carpenter
  2023-09-17 15:36   ` Stefan Wahren
  4 siblings, 1 reply; 11+ messages in thread
From: Dan Carpenter @ 2023-09-14  6:35 UTC (permalink / raw)
  To: Umang Jain
  Cc: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel, Stefan Wahren, Greg Kroah-Hartman,
	Florian Fainelli, Adrien Thierry, Dan Carpenter, Dave Stevenson,
	Kieran Bingham, Laurent Pinchart, Phil Elwell

On Thu, Sep 14, 2023 at 12:25:24AM +0530, Umang Jain wrote:
> Hello,
> 
> This series attempts to restart the discussion on custom logging used
> in VC04. In the last feedback gathered in [1] it seems that the logging
> would rather be moved to use dynamic debug. The series tries to move
> in that direction.
> 
> The elephant in the room is the ability of turning on/off log levels,
> which this series just drops. Compensated by a crude strings
> ("error", "warning", "info"... etc) for easier grepping.
> 
> The log category are also just strings (which probably can be transformed
> to dynamic debug class names moving forwards?).
> 
> To move forwards, I would like feedback on the broader direction.
> There are couple of TODOs in each of the patch (summarised in commit
> messages) which require case-by-case discussion.
> 
> Additional high-level questions to move forwards:
> 1. Is loss of log levels by moving to dynamic debug, is actually a
>    concern? Is dynamic debug a valid replacement?

Dynamic debug is honestly going to be an improvement.  I guess, Greg and
I said this back in Jan.

> 2. Whether debugfs should be dropped as well, found vestigial in [2]

Yes. The "vchiq/log" should be removed.  Ideally as part of this
patchset so it's easier to understand.

> 3. whether vchiq_log_trace() should actually be tracing support for VC04

That can be done later if people want.  No need to discuss it now.

regards,
dan carpenter


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [RFC PATCH v2 3/4] staging: vc04: Convert vchiq_log_info() to use dynamic debug
  2023-09-13 18:55 ` [RFC PATCH v2 3/4] staging: vc04: Convert vchiq_log_info() " Umang Jain
@ 2023-09-14  6:38   ` Dan Carpenter
  0 siblings, 0 replies; 11+ messages in thread
From: Dan Carpenter @ 2023-09-14  6:38 UTC (permalink / raw)
  To: Umang Jain
  Cc: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel, Stefan Wahren, Greg Kroah-Hartman,
	Florian Fainelli, Adrien Thierry, Dan Carpenter, Dave Stevenson,
	Kieran Bingham, Laurent Pinchart, Phil Elwell

Please rename vchiq_log_info() to vchiq_log_dbg() or something.  When I
see "info", I think it's a KERN_INFO level.  This is all debug stuff and
it's done correctly but the name is misleading so it looks wrong.

regards,
dan carpenter


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [RFC PATCH v2 0/4] staging: vc04: Drop custom logging
  2023-09-14  6:35 ` [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Dan Carpenter
@ 2023-09-17 15:36   ` Stefan Wahren
  2023-09-23  9:39     ` Umang Jain
  0 siblings, 1 reply; 11+ messages in thread
From: Stefan Wahren @ 2023-09-17 15:36 UTC (permalink / raw)
  To: Umang Jain, Dan Carpenter
  Cc: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell

Hi,

Am 14.09.23 um 08:35 schrieb Dan Carpenter:
> On Thu, Sep 14, 2023 at 12:25:24AM +0530, Umang Jain wrote:
>> Hello,
>>
>> This series attempts to restart the discussion on custom logging used
>> in VC04. In the last feedback gathered in [1] it seems that the logging
>> would rather be moved to use dynamic debug. The series tries to move
>> in that direction.
>>
>> The elephant in the room is the ability of turning on/off log levels,
>> which this series just drops. Compensated by a crude strings
>> ("error", "warning", "info"... etc) for easier grepping.
>>
>> The log category are also just strings (which probably can be transformed
>> to dynamic debug class names moving forwards?).
>>
>> To move forwards, I would like feedback on the broader direction.
>> There are couple of TODOs in each of the patch (summarised in commit
>> messages) which require case-by-case discussion.
>>
>> Additional high-level questions to move forwards:
>> 1. Is loss of log levels by moving to dynamic debug, is actually a
>>     concern? Is dynamic debug a valid replacement?
> 
> Dynamic debug is honestly going to be an improvement.  I guess, Greg and
> I said this back in Jan.
> 
>> 2. Whether debugfs should be dropped as well, found vestigial in [2]
> 
> Yes. The "vchiq/log" should be removed.  Ideally as part of this
> patchset so it's easier to understand.

Yes, but please do not remote vchiq_debugfs entirely. I'm working on a 
patch to move the state dump (debug feature) from the character device 
/dev/vchiq to debugfs /sys/kernel/debug/vchiq/dump_state.

> 
>> 3. whether vchiq_log_trace() should actually be tracing support for VC04
> 
> That can be done later if people want.  No need to discuss it now.
> 
> regards,
> dan carpenter
> 

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [RFC PATCH v2 0/4] staging: vc04: Drop custom logging
  2023-09-17 15:36   ` Stefan Wahren
@ 2023-09-23  9:39     ` Umang Jain
  2023-09-23 10:19       ` Stefan Wahren
  0 siblings, 1 reply; 11+ messages in thread
From: Umang Jain @ 2023-09-23  9:39 UTC (permalink / raw)
  To: Stefan Wahren, Dan Carpenter
  Cc: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell

Hi Stefan,

On 9/17/23 9:06 PM, Stefan Wahren wrote:
> Hi,
>
> Am 14.09.23 um 08:35 schrieb Dan Carpenter:
>> On Thu, Sep 14, 2023 at 12:25:24AM +0530, Umang Jain wrote:
>>> Hello,
>>>
>>> This series attempts to restart the discussion on custom logging used
>>> in VC04. In the last feedback gathered in [1] it seems that the logging
>>> would rather be moved to use dynamic debug. The series tries to move
>>> in that direction.
>>>
>>> The elephant in the room is the ability of turning on/off log levels,
>>> which this series just drops. Compensated by a crude strings
>>> ("error", "warning", "info"... etc) for easier grepping.
>>>
>>> The log category are also just strings (which probably can be 
>>> transformed
>>> to dynamic debug class names moving forwards?).
>>>
>>> To move forwards, I would like feedback on the broader direction.
>>> There are couple of TODOs in each of the patch (summarised in commit
>>> messages) which require case-by-case discussion.
>>>
>>> Additional high-level questions to move forwards:
>>> 1. Is loss of log levels by moving to dynamic debug, is actually a
>>>     concern? Is dynamic debug a valid replacement?
>>
>> Dynamic debug is honestly going to be an improvement.  I guess, Greg and
>> I said this back in Jan.

+1
>>
>>> 2. Whether debugfs should be dropped as well, found vestigial in [2]
>>
>> Yes. The "vchiq/log" should be removed.  Ideally as part of this
>> patchset so it's easier to understand.
>
> Yes, but please do not remote vchiq_debugfs entirely. I'm working on a 
> patch to move the state dump (debug feature) from the character device 
> /dev/vchiq to debugfs /sys/kernel/debug/vchiq/dump_state.

Can't the state dump be printed to dev_dbg() ? Will it pollute the 
kernel log?  Having debugfs for a single dump doesn't seem worthwhile if 
the state dump can be incorporated to dev_dbg() too.
>
>>
>>> 3. whether vchiq_log_trace() should actually be tracing support for 
>>> VC04
>>
>> That can be done later if people want.  No need to discuss it now.

Thanks Dan.
>>
>> regards,
>> dan carpenter
>>


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [RFC PATCH v2 0/4] staging: vc04: Drop custom logging
  2023-09-23  9:39     ` Umang Jain
@ 2023-09-23 10:19       ` Stefan Wahren
  2023-09-25 12:13         ` Dan Carpenter
  0 siblings, 1 reply; 11+ messages in thread
From: Stefan Wahren @ 2023-09-23 10:19 UTC (permalink / raw)
  To: Umang Jain, Dan Carpenter
  Cc: linux-staging, linux-arm-kernel, linux-rpi-kernel, linux-media,
	linux-kernel, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell

Hi Umang,

Am 23.09.23 um 11:39 schrieb Umang Jain:
> Hi Stefan,
> 
> On 9/17/23 9:06 PM, Stefan Wahren wrote:
>> Hi,
>>
>> Am 14.09.23 um 08:35 schrieb Dan Carpenter:
>>> On Thu, Sep 14, 2023 at 12:25:24AM +0530, Umang Jain wrote:
>>>> Hello,
>>>>
>>>> This series attempts to restart the discussion on custom logging used
>>>> in VC04. In the last feedback gathered in [1] it seems that the logging
>>>> would rather be moved to use dynamic debug. The series tries to move
>>>> in that direction.
>>>>
>>>> The elephant in the room is the ability of turning on/off log levels,
>>>> which this series just drops. Compensated by a crude strings
>>>> ("error", "warning", "info"... etc) for easier grepping.
>>>>
>>>> The log category are also just strings (which probably can be 
>>>> transformed
>>>> to dynamic debug class names moving forwards?).
>>>>
>>>> To move forwards, I would like feedback on the broader direction.
>>>> There are couple of TODOs in each of the patch (summarised in commit
>>>> messages) which require case-by-case discussion.
>>>>
>>>> Additional high-level questions to move forwards:
>>>> 1. Is loss of log levels by moving to dynamic debug, is actually a
>>>>     concern? Is dynamic debug a valid replacement?
>>>
>>> Dynamic debug is honestly going to be an improvement.  I guess, Greg and
>>> I said this back in Jan.
> 
> +1
>>>
>>>> 2. Whether debugfs should be dropped as well, found vestigial in [2]
>>>
>>> Yes. The "vchiq/log" should be removed.  Ideally as part of this
>>> patchset so it's easier to understand.
>>
>> Yes, but please do not remote vchiq_debugfs entirely. I'm working on a 
>> patch to move the state dump (debug feature) from the character device 
>> /dev/vchiq to debugfs /sys/kernel/debug/vchiq/dump_state.
> 
> Can't the state dump be printed to dev_dbg() ? Will it pollute the 
> kernel log?  Having debugfs for a single dump doesn't seem worthwhile if 
> the state dump can be incorporated to dev_dbg() too.

debugfs was created for a good reason. dev_dbg() is a nice tool, but it 
isn't useful in every situation. In case of communication the usage of 
counter is quite popular and removing this ability would make debugging 
not easier.

Try to make "cat /dev/vchiq" you will see you don't want pollute the 
kernel log with this kind of information.

Actually i don't see a problem with have a single dump in debugfs.

Let me send a draft of my changes for a better discussion ...

Regards
Stefan

>>
>>>
>>>> 3. whether vchiq_log_trace() should actually be tracing support for 
>>>> VC04
>>>
>>> That can be done later if people want.  No need to discuss it now.
> 
> Thanks Dan.
>>>
>>> regards,
>>> dan carpenter
>>>
> 

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [RFC PATCH v2 0/4] staging: vc04: Drop custom logging
  2023-09-23 10:19       ` Stefan Wahren
@ 2023-09-25 12:13         ` Dan Carpenter
  0 siblings, 0 replies; 11+ messages in thread
From: Dan Carpenter @ 2023-09-25 12:13 UTC (permalink / raw)
  To: Stefan Wahren
  Cc: Umang Jain, linux-staging, linux-arm-kernel, linux-rpi-kernel,
	linux-media, linux-kernel, Greg Kroah-Hartman, Florian Fainelli,
	Adrien Thierry, Dan Carpenter, Dave Stevenson, Kieran Bingham,
	Laurent Pinchart, Phil Elwell

Just so it's clear, Stefan and I are on the same page on this.  State
dumps to debugfs are fine.

regards,
dan carpenter


^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2023-09-25 12:13 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-09-13 18:55 [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Umang Jain
2023-09-13 18:55 ` [RFC PATCH v2 1/4] staging: vc04: Convert vchiq_log_error() to use dynamic debug Umang Jain
2023-09-13 18:55 ` [RFC PATCH v2 2/4] staging: vc04: Convert vchiq_log_warning() " Umang Jain
2023-09-13 18:55 ` [RFC PATCH v2 3/4] staging: vc04: Convert vchiq_log_info() " Umang Jain
2023-09-14  6:38   ` Dan Carpenter
2023-09-13 18:55 ` [RFC PATCH v2 4/4] staging: vc04: Convert vchiq_log_trace() " Umang Jain
2023-09-14  6:35 ` [RFC PATCH v2 0/4] staging: vc04: Drop custom logging Dan Carpenter
2023-09-17 15:36   ` Stefan Wahren
2023-09-23  9:39     ` Umang Jain
2023-09-23 10:19       ` Stefan Wahren
2023-09-25 12:13         ` Dan Carpenter

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox

all inboxes | Powered by JetHome®