diff mbox series

media: v4l: subdev: Use dev_err() to print errors and clarify

Message ID 20241122153343.237308-1-demonsingur@gmail.com (mailing list archive)
State New
Headers show
Series media: v4l: subdev: Use dev_err() to print errors and clarify | expand

Commit Message

Cosmin Tanislav Nov. 22, 2024, 3:33 p.m. UTC
The error values end up being returned to userspace, it makes sense to
have some useful information printed when debugging them, even if the
reason for the errors are bad configs or internal driver issues.

Replace dev_dbg() with dev_err() for errors.

Also, when using complex pipelines with multiple bridges between the
video device and multiple source sub devices, printing just the video
device name for each error does not provide enough context as to which
operation failed.

Add sub device entity name to the messages where possible to clarify the
source of the errors.

Signed-off-by: Cosmin Tanislav <demonsingur@gmail.com>
---
 drivers/media/v4l2-core/v4l2-subdev.c | 22 ++++++++++++----------
 1 file changed, 12 insertions(+), 10 deletions(-)

Comments

Laurent Pinchart Nov. 23, 2024, 9:32 p.m. UTC | #1
Hi Cosmin,

On Fri, Nov 22, 2024 at 05:33:39PM +0200, Cosmin Tanislav wrote:
> The error values end up being returned to userspace, it makes sense to
> have some useful information printed when debugging them, even if the
> reason for the errors are bad configs or internal driver issues.
> 
> Replace dev_dbg() with dev_err() for errors.

We use dev_dbg() on purpose for all errors that can be triggered
directly by applications. This includes in particular all pipeline
validation errors.

The error paths in this specific patch shouldn't be in that category, as
all the validation should have been performed before starting subdevs
(assuming all drivers are correctly implemented, which is of course not
a given, but those issues should be fixed). I think we could therefore
switch to dev_err() here. However, I'm wondering what kind of issues
triggered this patch. What errors did you run into that would have
benefited from being reported more loudly, and were they caused by
driver bugs or userspace misconfiguring the device ?

> Also, when using complex pipelines with multiple bridges between the
> video device and multiple source sub devices, printing just the video
> device name for each error does not provide enough context as to which
> operation failed.
> 
> Add sub device entity name to the messages where possible to clarify the
> source of the errors.

This can be considered as a standalone patch.

> Signed-off-by: Cosmin Tanislav <demonsingur@gmail.com>
> ---
>  drivers/media/v4l2-core/v4l2-subdev.c | 22 ++++++++++++----------
>  1 file changed, 12 insertions(+), 10 deletions(-)
> 
> diff --git a/drivers/media/v4l2-core/v4l2-subdev.c b/drivers/media/v4l2-core/v4l2-subdev.c
> index 4f0eecd7fd66f..d51b4594d11c5 100644
> --- a/drivers/media/v4l2-core/v4l2-subdev.c
> +++ b/drivers/media/v4l2-core/v4l2-subdev.c
> @@ -2303,20 +2303,21 @@ int v4l2_subdev_enable_streams(struct v4l2_subdev *sd, u32 pad,
>  				    &found_streams, &enabled_streams);
>  
>  	if (found_streams != streams_mask) {
> -		dev_dbg(dev, "streams 0x%llx not found on %s:%u\n",
> +		dev_err(dev, "streams 0x%llx not found on %s:%u\n",
>  			streams_mask & ~found_streams, sd->entity.name, pad);
>  		ret = -EINVAL;
>  		goto done;
>  	}
>  
>  	if (enabled_streams) {
> -		dev_dbg(dev, "streams 0x%llx already enabled on %s:%u\n",
> +		dev_err(dev, "streams 0x%llx already enabled on %s:%u\n",
>  			enabled_streams, sd->entity.name, pad);
>  		ret = -EALREADY;
>  		goto done;
>  	}
>  
> -	dev_dbg(dev, "enable streams %u:%#llx\n", pad, streams_mask);
> +	dev_dbg(dev, "enable streams %s:%u:%#llx\n",
> +		sd->entity.name, pad, streams_mask);
>  
>  	already_streaming = v4l2_subdev_is_streaming(sd);
>  
> @@ -2333,8 +2334,8 @@ int v4l2_subdev_enable_streams(struct v4l2_subdev *sd, u32 pad,
>  	}
>  
>  	if (ret) {
> -		dev_dbg(dev, "enable streams %u:%#llx failed: %d\n", pad,
> -			streams_mask, ret);
> +		dev_err(dev, "enable streams %s:%u:%#llx failed: %d\n",
> +			sd->entity.name, pad, streams_mask, ret);
>  		goto done;
>  	}
>  
> @@ -2403,20 +2404,21 @@ int v4l2_subdev_disable_streams(struct v4l2_subdev *sd, u32 pad,
>  				    &found_streams, &enabled_streams);
>  
>  	if (found_streams != streams_mask) {
> -		dev_dbg(dev, "streams 0x%llx not found on %s:%u\n",
> +		dev_err(dev, "streams 0x%llx not found on %s:%u\n",
>  			streams_mask & ~found_streams, sd->entity.name, pad);
>  		ret = -EINVAL;
>  		goto done;
>  	}
>  
>  	if (enabled_streams != streams_mask) {
> -		dev_dbg(dev, "streams 0x%llx already disabled on %s:%u\n",
> +		dev_err(dev, "streams 0x%llx already disabled on %s:%u\n",
>  			streams_mask & ~enabled_streams, sd->entity.name, pad);
>  		ret = -EALREADY;
>  		goto done;
>  	}
>  
> -	dev_dbg(dev, "disable streams %u:%#llx\n", pad, streams_mask);
> +	dev_dbg(dev, "disable streams %s:%u:%#llx\n",
> +		sd->entity.name, pad, streams_mask);
>  
>  	if (!use_s_stream) {
>  		/* Call the .disable_streams() operation. */
> @@ -2432,8 +2434,8 @@ int v4l2_subdev_disable_streams(struct v4l2_subdev *sd, u32 pad,
>  	}
>  
>  	if (ret) {
> -		dev_dbg(dev, "disable streams %u:%#llx failed: %d\n", pad,
> -			streams_mask, ret);
> +		dev_err(dev, "disable streams %s:%u:%#llx failed: %d\n",
> +			sd->entity.name, pad, streams_mask, ret);
>  		goto done;
>  	}
>
Cosmin Tanislav Nov. 25, 2024, 8:34 p.m. UTC | #2
On 11/23/24 11:32 PM, Laurent Pinchart wrote:
> Hi Cosmin,
> 
> On Fri, Nov 22, 2024 at 05:33:39PM +0200, Cosmin Tanislav wrote:
>> The error values end up being returned to userspace, it makes sense to
>> have some useful information printed when debugging them, even if the
>> reason for the errors are bad configs or internal driver issues.
>>
>> Replace dev_dbg() with dev_err() for errors.
> 
> We use dev_dbg() on purpose for all errors that can be triggered
> directly by applications. This includes in particular all pipeline
> validation errors.
> 
> The error paths in this specific patch shouldn't be in that category, as
> all the validation should have been performed before starting subdevs
> (assuming all drivers are correctly implemented, which is of course not
> a given, but those issues should be fixed). I think we could therefore
> switch to dev_err() here. However, I'm wondering what kind of issues
> triggered this patch. What errors did you run into that would have
> benefited from being reported more loudly, and were they caused by
> driver bugs or userspace misconfiguring the device ?
> 

I've had this patch in my GMSL2 tree for some time now, I believe indeed
the reasons why I've hit these error cases were the drivers being
slightly broken, but I still think it is worthwhile to show an error
message, to aid with debugging. Adding the entity name to the messages
makes it even more clear where exactly the code is breaking.

I can split it up into separate patches for dev_dbg() -> dev_err() and
adding the entity name to the print statements for V2.

>> Also, when using complex pipelines with multiple bridges between the
>> video device and multiple source sub devices, printing just the video
>> device name for each error does not provide enough context as to which
>> operation failed.
>>
>> Add sub device entity name to the messages where possible to clarify the
>> source of the errors.
> 
> This can be considered as a standalone patch.
> 
>> Signed-off-by: Cosmin Tanislav <demonsingur@gmail.com>
>> ---
>>   drivers/media/v4l2-core/v4l2-subdev.c | 22 ++++++++++++----------
>>   1 file changed, 12 insertions(+), 10 deletions(-)
>>
>> diff --git a/drivers/media/v4l2-core/v4l2-subdev.c b/drivers/media/v4l2-core/v4l2-subdev.c
>> index 4f0eecd7fd66f..d51b4594d11c5 100644
>> --- a/drivers/media/v4l2-core/v4l2-subdev.c
>> +++ b/drivers/media/v4l2-core/v4l2-subdev.c
>> @@ -2303,20 +2303,21 @@ int v4l2_subdev_enable_streams(struct v4l2_subdev *sd, u32 pad,
>>   				    &found_streams, &enabled_streams);
>>   
>>   	if (found_streams != streams_mask) {
>> -		dev_dbg(dev, "streams 0x%llx not found on %s:%u\n",
>> +		dev_err(dev, "streams 0x%llx not found on %s:%u\n",
>>   			streams_mask & ~found_streams, sd->entity.name, pad);
>>   		ret = -EINVAL;
>>   		goto done;
>>   	}
>>   
>>   	if (enabled_streams) {
>> -		dev_dbg(dev, "streams 0x%llx already enabled on %s:%u\n",
>> +		dev_err(dev, "streams 0x%llx already enabled on %s:%u\n",
>>   			enabled_streams, sd->entity.name, pad);
>>   		ret = -EALREADY;
>>   		goto done;
>>   	}
>>   
>> -	dev_dbg(dev, "enable streams %u:%#llx\n", pad, streams_mask);
>> +	dev_dbg(dev, "enable streams %s:%u:%#llx\n",
>> +		sd->entity.name, pad, streams_mask);
>>   
>>   	already_streaming = v4l2_subdev_is_streaming(sd);
>>   
>> @@ -2333,8 +2334,8 @@ int v4l2_subdev_enable_streams(struct v4l2_subdev *sd, u32 pad,
>>   	}
>>   
>>   	if (ret) {
>> -		dev_dbg(dev, "enable streams %u:%#llx failed: %d\n", pad,
>> -			streams_mask, ret);
>> +		dev_err(dev, "enable streams %s:%u:%#llx failed: %d\n",
>> +			sd->entity.name, pad, streams_mask, ret);
>>   		goto done;
>>   	}
>>   
>> @@ -2403,20 +2404,21 @@ int v4l2_subdev_disable_streams(struct v4l2_subdev *sd, u32 pad,
>>   				    &found_streams, &enabled_streams);
>>   
>>   	if (found_streams != streams_mask) {
>> -		dev_dbg(dev, "streams 0x%llx not found on %s:%u\n",
>> +		dev_err(dev, "streams 0x%llx not found on %s:%u\n",
>>   			streams_mask & ~found_streams, sd->entity.name, pad);
>>   		ret = -EINVAL;
>>   		goto done;
>>   	}
>>   
>>   	if (enabled_streams != streams_mask) {
>> -		dev_dbg(dev, "streams 0x%llx already disabled on %s:%u\n",
>> +		dev_err(dev, "streams 0x%llx already disabled on %s:%u\n",
>>   			streams_mask & ~enabled_streams, sd->entity.name, pad);
>>   		ret = -EALREADY;
>>   		goto done;
>>   	}
>>   
>> -	dev_dbg(dev, "disable streams %u:%#llx\n", pad, streams_mask);
>> +	dev_dbg(dev, "disable streams %s:%u:%#llx\n",
>> +		sd->entity.name, pad, streams_mask);
>>   
>>   	if (!use_s_stream) {
>>   		/* Call the .disable_streams() operation. */
>> @@ -2432,8 +2434,8 @@ int v4l2_subdev_disable_streams(struct v4l2_subdev *sd, u32 pad,
>>   	}
>>   
>>   	if (ret) {
>> -		dev_dbg(dev, "disable streams %u:%#llx failed: %d\n", pad,
>> -			streams_mask, ret);
>> +		dev_err(dev, "disable streams %s:%u:%#llx failed: %d\n",
>> +			sd->entity.name, pad, streams_mask, ret);
>>   		goto done;
>>   	}
>>   
>
diff mbox series

Patch

diff --git a/drivers/media/v4l2-core/v4l2-subdev.c b/drivers/media/v4l2-core/v4l2-subdev.c
index 4f0eecd7fd66f..d51b4594d11c5 100644
--- a/drivers/media/v4l2-core/v4l2-subdev.c
+++ b/drivers/media/v4l2-core/v4l2-subdev.c
@@ -2303,20 +2303,21 @@  int v4l2_subdev_enable_streams(struct v4l2_subdev *sd, u32 pad,
 				    &found_streams, &enabled_streams);
 
 	if (found_streams != streams_mask) {
-		dev_dbg(dev, "streams 0x%llx not found on %s:%u\n",
+		dev_err(dev, "streams 0x%llx not found on %s:%u\n",
 			streams_mask & ~found_streams, sd->entity.name, pad);
 		ret = -EINVAL;
 		goto done;
 	}
 
 	if (enabled_streams) {
-		dev_dbg(dev, "streams 0x%llx already enabled on %s:%u\n",
+		dev_err(dev, "streams 0x%llx already enabled on %s:%u\n",
 			enabled_streams, sd->entity.name, pad);
 		ret = -EALREADY;
 		goto done;
 	}
 
-	dev_dbg(dev, "enable streams %u:%#llx\n", pad, streams_mask);
+	dev_dbg(dev, "enable streams %s:%u:%#llx\n",
+		sd->entity.name, pad, streams_mask);
 
 	already_streaming = v4l2_subdev_is_streaming(sd);
 
@@ -2333,8 +2334,8 @@  int v4l2_subdev_enable_streams(struct v4l2_subdev *sd, u32 pad,
 	}
 
 	if (ret) {
-		dev_dbg(dev, "enable streams %u:%#llx failed: %d\n", pad,
-			streams_mask, ret);
+		dev_err(dev, "enable streams %s:%u:%#llx failed: %d\n",
+			sd->entity.name, pad, streams_mask, ret);
 		goto done;
 	}
 
@@ -2403,20 +2404,21 @@  int v4l2_subdev_disable_streams(struct v4l2_subdev *sd, u32 pad,
 				    &found_streams, &enabled_streams);
 
 	if (found_streams != streams_mask) {
-		dev_dbg(dev, "streams 0x%llx not found on %s:%u\n",
+		dev_err(dev, "streams 0x%llx not found on %s:%u\n",
 			streams_mask & ~found_streams, sd->entity.name, pad);
 		ret = -EINVAL;
 		goto done;
 	}
 
 	if (enabled_streams != streams_mask) {
-		dev_dbg(dev, "streams 0x%llx already disabled on %s:%u\n",
+		dev_err(dev, "streams 0x%llx already disabled on %s:%u\n",
 			streams_mask & ~enabled_streams, sd->entity.name, pad);
 		ret = -EALREADY;
 		goto done;
 	}
 
-	dev_dbg(dev, "disable streams %u:%#llx\n", pad, streams_mask);
+	dev_dbg(dev, "disable streams %s:%u:%#llx\n",
+		sd->entity.name, pad, streams_mask);
 
 	if (!use_s_stream) {
 		/* Call the .disable_streams() operation. */
@@ -2432,8 +2434,8 @@  int v4l2_subdev_disable_streams(struct v4l2_subdev *sd, u32 pad,
 	}
 
 	if (ret) {
-		dev_dbg(dev, "disable streams %u:%#llx failed: %d\n", pad,
-			streams_mask, ret);
+		dev_err(dev, "disable streams %s:%u:%#llx failed: %d\n",
+			sd->entity.name, pad, streams_mask, ret);
 		goto done;
 	}