[RFC 1/1] v4l: async: Add some debug prints

[Frieder Schrempf]

Hi Sakari,

On 09.02.23 23:16, Sakari Ailus wrote:
> Just add some debug prints for V4L2 async sub-device matching process. These
> might come useful in figuring out why things don't work as expected.
> 
> Signed-off-by: Sakari Ailus <sakari.ailus at linux.intel.com>
> ---
> Frieder,
> 
> Can you try this? It prints what is being matched with what. Perhaps this
> could be merged in a bit more refined form if it proves useful.
> 
> Not tested in any way.
> 

Thanks for the patch!

I fixed a few issues (see below) and gave this patch a try. Though in my
case it doesn't seem to help much as the problem is somewhere before the
matching actually happens. The only output from this patch I get is:

[    1.536479] imx219 1-0010: trying to complete
[    1.540856] imx219 1-0010: V4L2 device not available

Thanks
Frieder

>  drivers/media/v4l2-core/v4l2-async.c | 41 ++++++++++++++++++++++++----
>  1 file changed, 36 insertions(+), 5 deletions(-)
> 
> diff --git a/drivers/media/v4l2-core/v4l2-async.c b/drivers/media/v4l2-core/v4l2-async.c
> index 2f1b718a9189..6c13a9488415 100644
> --- a/drivers/media/v4l2-core/v4l2-async.c
> +++ b/drivers/media/v4l2-core/v4l2-async.c
> @@ -86,13 +86,18 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  	bool sd_fwnode_is_ep;
>  	struct device *dev;
>  
> +	dev_dbg(sd->dev, "async fwnode match %pfw vs. %pfw\n", sd_fwnode,
> +		asd->match.fwnode);
> +
>  	/*
>  	 * Both the subdev and the async subdev can provide either an endpoint
>  	 * fwnode or a device fwnode. Start with the simple case of direct
>  	 * fwnode matching.
>  	 */
> -	if (sd_fwnode == asd->match.fwnode)
> +	if (sd_fwnode == asd->match.fwnode) {
> +		dev_dbg(sd->dev, "true\n");
>  		return true;
> +	}
>  
>  	/*
>  	 * Otherwise, check if the sd fwnode and the asd fwnode refer to an
> @@ -105,8 +110,12 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  	sd_fwnode_is_ep = fwnode_graph_is_endpoint(sd_fwnode);
>  	asd_fwnode_is_ep = fwnode_graph_is_endpoint(asd->match.fwnode);
>  
> -	if (sd_fwnode_is_ep == asd_fwnode_is_ep)
> +	dev_dbg(sd->dev, "async fwnode match %pfw vs. %pfw\n", sd_fwnode,
> +		asd->match.fwnode);
> +	if (sd_fwnode_is_ep == asd_fwnode_is_ep) {
> +		dev_dbg(sd->dev, "unmatching node types (false)\n");
>  		return false;
> +	}
>  
>  	/*
>  	 * The sd and asd fwnodes are of different types. Get the device fwnode
> @@ -120,10 +129,15 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  		other_fwnode = sd_fwnode;
>  	}
>  
> +	dev_dbg(sd->dev, "async fwnode (compat) match %pfw vs. %pfw\n",
> +		dev_fwnode, other_fwnode);
> +
>  	fwnode_handle_put(dev_fwnode);
>  
> -	if (dev_fwnode != other_fwnode)
> +	if (dev_fwnode != other_fwnode) {
> +		dev_dbg(sd->dev, "false\n");
>  		return false;
> +	}
>  
>  	/*
>  	 * We have a heterogeneous match. Retrieve the struct device of the side
> @@ -143,6 +157,8 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  			   dev->driver->name);
>  	}
>  
> +	dev_dbg(sd->dev, "true\n");
> +
>  	return true;
>  }
>  
> @@ -255,7 +271,10 @@ v4l2_async_nf_can_complete(struct v4l2_async_notifier *notifier)
>  			v4l2_async_find_subdev_notifier(sd);
>  
>  		if (subdev_notifier &&
> -		    !v4l2_async_nf_can_complete(subdev_notifier))
> +		    !v4l2_async_nf_can_complete(subdev_notifier)) {
> +			if (subdev_notifier->sd)
> +				deb_dbg(subdev_notifier->sd->dev,

dev_dbg()

> +					"cannot complete\n");
>  			return false;

missing }

>  	}
>  
> @@ -273,18 +292,27 @@ v4l2_async_nf_try_complete(struct v4l2_async_notifier *notifier)
>  	if (!list_empty(&notifier->waiting))
>  		return 0;
>  
> +	if (notifier->sd)
> +		deb_dbg(notifier->sd->dev, "trying to complete\n");

dev_dbg()

> +
>  	/* Check the entire notifier tree; find the root notifier first. */
>  	while (notifier->parent)
>  		notifier = notifier->parent;
>  
>  	/* This is root if it has v4l2_dev. */
> -	if (!notifier->v4l2_dev)
> +	if (!notifier->v4l2_dev) {
> +		if (notifier->sd)
> +			deb_dbg(notifier->sd->dev,

dev_dbg()

> +				"V4L2 device not available\n");
>  		return 0;
> +	}
>  
>  	/* Is everything ready? */
>  	if (!v4l2_async_nf_can_complete(notifier))
>  		return 0;
>  
> +	deb_dbg(notifier->sd->dev, "complete\n");

missing guard "if (notifier->sd)"
dev_dbg()

> +
>  	return v4l2_async_nf_call_complete(notifier);
>  }
>  
> @@ -386,6 +414,9 @@ v4l2_async_nf_try_all_subdevs(struct v4l2_async_notifier *notifier)
>  			continue;
>  
>  		ret = v4l2_async_match_notify(notifier, v4l2_dev, sd, asd);
> +		deb_dbg(sd->dev, "bound to %s's notifier (ret %d)\n",

dev_dbg()

> +			notifier->sd ? dev_name(notifier->sd->dev) : "no-dev",
> +			ret);
>  		if (ret < 0)
>  			return ret;
>