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

[Sakari Ailus <sakari.ailus@linux.intel.com>]

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