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

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

[Cosmin Tanislav]

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(-)

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;
 	}
 
-- 
2.47.0

Re: [PATCH] media: v4l: subdev: Use dev_err() to print errors and clarify

[Laurent Pinchart]

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;
>  	}
>  

-- 
Regards,

Laurent Pinchart

Re: [PATCH] media: v4l: subdev: Use dev_err() to print errors and clarify

[Cosmin Tanislav]

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;
>>   	}
>>   
> 

Re: [PATCH] media: v4l: subdev: Use dev_err() to print errors and clarify

[Laurent Pinchart]

On Mon, Nov 25, 2024 at 10:34:40PM +0200, Cosmin Tanislav wrote:
> On 11/23/24 11:32 PM, Laurent Pinchart wrote:
> > 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.

I'm OK either way. If other people prefer keeping dev_dbg() then
splitting the patch in two would make sense.

> >> 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;
> >>   	}
> >>   

-- 
Regards,

Laurent Pinchart

Re: [PATCH] media: v4l: subdev: Use dev_err() to print errors and clarify

[Sakari Ailus]

Hi Cosmin, Laurent,

On Wed, Nov 27, 2024 at 09:20:33AM +0200, Laurent Pinchart wrote:
> On Mon, Nov 25, 2024 at 10:34:40PM +0200, Cosmin Tanislav wrote:
> > On 11/23/24 11:32 PM, Laurent Pinchart wrote:
> > > 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.
> 
> I'm OK either way. If other people prefer keeping dev_dbg() then
> splitting the patch in two would make sense.

dev_dbg() seems the correct function here: these are user-triggerable
errors that aren't related to hardware conditions.

> 
> > >> 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;
> > >>   	}
> > >>   

-- 
Regards,

Sakari Ailus

Re: [PATCH] media: v4l: subdev: Use dev_err() to print errors and clarify

[Laurent Pinchart]

On Fri, Dec 13, 2024 at 08:33:09AM +0000, Sakari Ailus wrote:
> On Wed, Nov 27, 2024 at 09:20:33AM +0200, Laurent Pinchart wrote:
> > On Mon, Nov 25, 2024 at 10:34:40PM +0200, Cosmin Tanislav wrote:
> > > On 11/23/24 11:32 PM, Laurent Pinchart wrote:
> > > > 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.
> > 
> > I'm OK either way. If other people prefer keeping dev_dbg() then
> > splitting the patch in two would make sense.
> 
> dev_dbg() seems the correct function here: these are user-triggerable
> errors that aren't related to hardware conditions.

Are these user-triggerable in the absence of bugs in drivers ?

> > > >> 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;
> > > >>   	}
> > > >>   

-- 
Regards,

Laurent Pinchart