[RESEND,v3,05/32] media: v4l: async: Add some debug prints

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@linux.intel.com>
---
 drivers/media/v4l2-core/v4l2-async.c | 71 ++++++++++++++++++++++++----
 1 file changed, 63 insertions(+), 8 deletions(-)

Hi Sakari,

Thank you for the patch.

On Thu, May 25, 2023 at 12:15:48PM +0300, 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@linux.intel.com>
> ---
>  drivers/media/v4l2-core/v4l2-async.c | 71 ++++++++++++++++++++++++----
>  1 file changed, 63 insertions(+), 8 deletions(-)
> 
> diff --git a/drivers/media/v4l2-core/v4l2-async.c b/drivers/media/v4l2-core/v4l2-async.c
> index 7831bc8792904..c5781124337af 100644
> --- a/drivers/media/v4l2-core/v4l2-async.c
> +++ b/drivers/media/v4l2-core/v4l2-async.c
> @@ -77,6 +77,17 @@ static bool match_i2c(struct v4l2_async_notifier *notifier,
>  #endif
>  }
>  
> +static struct device *notifier_dev(struct v4l2_async_notifier *notifier)
> +{
> +	if (notifier->sd)
> +		return notifier->sd->dev;
> +
> +	if (notifier->v4l2_dev)
> +		return notifier->v4l2_dev->dev;
> +
> +	return NULL;
> +}
> +
>  static bool
>  match_fwnode_one(struct v4l2_async_notifier *notifier,
>  		 struct v4l2_subdev *sd, struct fwnode_handle *sd_fwnode,
> @@ -88,13 +99,20 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  	bool sd_fwnode_is_ep;
>  	struct device *dev;
>  
> +	dev_dbg(notifier_dev(notifier),
> +		"v4l2-async: fwnode match: need %pfw, trying %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(notifier_dev(notifier),
> +			"v4l2-async: direct match found\n");
>  		return true;
> +	}
>  
>  	/*
>  	 * Otherwise, check if the sd fwnode and the asd fwnode refer to an
> @@ -107,8 +125,11 @@ 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)
> +	if (sd_fwnode_is_ep == asd_fwnode_is_ep) {
> +		dev_dbg(notifier_dev(notifier),
> +			"v4l2-async: direct match not found\n");
>  		return false;
> +	}
>  
>  	/*
>  	 * The sd and asd fwnodes are of different types. Get the device fwnode
> @@ -122,10 +143,17 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  		other_fwnode = sd_fwnode;
>  	}
>  
> +	dev_dbg(notifier_dev(notifier),
> +		"v4l2-async: fwnode compat match: need %pfw, trying %pfw\n",
> +		dev_fwnode, other_fwnode);
> +
>  	fwnode_handle_put(dev_fwnode);
>  
> -	if (dev_fwnode != other_fwnode)
> +	if (dev_fwnode != other_fwnode) {
> +		dev_dbg(notifier_dev(notifier),
> +			"v4l2-async: compat match not found\n");
>  		return false;
> +	}
>  
>  	/*
>  	 * We have a heterogeneous match. Retrieve the struct device of the side
> @@ -145,12 +173,18 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
>  			   dev->driver->name);
>  	}
>  
> +	dev_dbg(notifier_dev(notifier), "v4l2-async: compat match found\n");
> +
>  	return true;
>  }
>  
>  static bool match_fwnode(struct v4l2_async_notifier *notifier,
>  			 struct v4l2_subdev *sd, struct v4l2_async_subdev *asd)
>  {
> +	dev_dbg(notifier_dev(notifier),
> +		"v4l2-async: matching for notifier %pfw, sd fwnode %pfw\n",
> +		dev_fwnode(notifier_dev(notifier)), sd->fwnode);
> +
>  	if (match_fwnode_one(notifier, sd, sd->fwnode, asd))
>  		return true;
>  
> @@ -158,6 +192,9 @@ static bool match_fwnode(struct v4l2_async_notifier *notifier,
>  	if (IS_ERR_OR_NULL(sd->fwnode->secondary))
>  		return false;
>  
> +	dev_dbg(notifier_dev(notifier),
> +		"v4l2-async: trying secondary fwnode match\n");
> +
>  	return match_fwnode_one(notifier, sd, sd->fwnode->secondary, asd);
>  }
>  
> @@ -271,22 +308,33 @@ v4l2_async_nf_can_complete(struct v4l2_async_notifier *notifier)
>  static int
>  v4l2_async_nf_try_complete(struct v4l2_async_notifier *notifier)
>  {
> +	struct v4l2_async_notifier *__notifier = notifier;
> +
>  	/* Quick check whether there are still more sub-devices here. */
>  	if (!list_empty(&notifier->waiting))
>  		return 0;
>  
> +	if (notifier->sd)
> +		dev_dbg(notifier_dev(notifier),
> +			"v4l2-async: trying to complete\n");

I don't understand how the check and the message relate to each other.

Apart from that,

Reviewed-by: Laurent Pinchart <laurent.pinchart+renesas@ideasonboard.com>

> +
>  	/* 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) {
> +		dev_dbg(notifier_dev(__notifier),
> +			"v4l2-async: V4L2 device not available\n");
>  		return 0;
> +	}
>  
>  	/* Is everything ready? */
>  	if (!v4l2_async_nf_can_complete(notifier))
>  		return 0;
>  
> +	dev_dbg(notifier_dev(__notifier), "v4l2-async: complete\n");
> +
>  	return v4l2_async_nf_call_complete(notifier);
>  }
>  
> @@ -350,6 +398,9 @@ static int v4l2_async_match_notify(struct v4l2_async_notifier *notifier,
>  	/* Move from the global subdevice list to notifier's done */
>  	list_move(&sd->async_list, &notifier->done);
>  
> +	dev_dbg(notifier_dev(notifier), "v4l2-async: %s bound (ret %d)\n",
> +		dev_name(sd->dev), ret);
> +
>  	/*
>  	 * See if the sub-device has a notifier. If not, return here.
>  	 */
> @@ -378,6 +429,8 @@ v4l2_async_nf_try_all_subdevs(struct v4l2_async_notifier *notifier)
>  	if (!v4l2_dev)
>  		return 0;
>  
> +	dev_dbg(notifier_dev(notifier), "v4l2-async: trying all sub-devices\n");
> +
>  again:
>  	list_for_each_entry(sd, &subdev_list, async_list) {
>  		struct v4l2_async_subdev *asd;
> @@ -387,6 +440,9 @@ v4l2_async_nf_try_all_subdevs(struct v4l2_async_notifier *notifier)
>  		if (!asd)
>  			continue;
>  
> +		dev_dbg(notifier_dev(notifier),
> +			"v4l2-async: match found, subdev %s\n", sd->name);
> +
>  		ret = v4l2_async_match_notify(notifier, v4l2_dev, sd, asd);
>  		if (ret < 0)
>  			return ret;
> @@ -496,8 +552,7 @@ static int v4l2_async_nf_asd_valid(struct v4l2_async_notifier *notifier,
>  				   struct v4l2_async_subdev *asd,
>  				   int this_index)
>  {
> -	struct device *dev =
> -		notifier->v4l2_dev ? notifier->v4l2_dev->dev : NULL;
> +	struct device *dev = notifier_dev(notifier);
>  
>  	if (!asd)
>  		return -EINVAL;
> @@ -506,12 +561,12 @@ static int v4l2_async_nf_asd_valid(struct v4l2_async_notifier *notifier,
>  	case V4L2_ASYNC_MATCH_I2C:
>  	case V4L2_ASYNC_MATCH_FWNODE:
>  		if (v4l2_async_nf_has_async_subdev(notifier, asd, this_index)) {
> -			dev_dbg(dev, "subdev descriptor already listed in this or other notifiers\n");
> +			dev_dbg(dev, "v4l2-async: subdev descriptor already listed in a notifier\n");
>  			return -EEXIST;
>  		}
>  		break;
>  	default:
> -		dev_err(dev, "Invalid match type %u on %p\n",
> +		dev_err(dev, "v4l2-async: Invalid match type %u on %p\n",
>  			asd->match_type, asd);
>  		return -EINVAL;
>  	}