Hi Sakari
On Thu, Mar 30, 2023 at 02:58:37PM +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@xxxxxxxxxxxxxxx>
> ---
> drivers/media/v4l2-core/v4l2-async.c | 59 ++++++++++++++++++++++++----
> 1 file changed, 52 insertions(+), 7 deletions(-)
>
> diff --git a/drivers/media/v4l2-core/v4l2-async.c b/drivers/media/v4l2-core/v4l2-async.c
> index 008a2a3e312e..6dd426c2ca68 100644
> --- a/drivers/media/v4l2-core/v4l2-async.c
> +++ b/drivers/media/v4l2-core/v4l2-async.c
> @@ -75,6 +75,12 @@ static bool match_i2c(struct v4l2_async_notifier *notifier,
> #endif
> }
>
> +static struct device *notifier_dev(struct v4l2_async_notifier *notifier)
> +{
> + return notifier->sd ? notifier->sd->dev : notifier->v4l2_dev ?
> + notifier->v4l2_dev->dev : NULL;
> +}
> +
> static bool
> match_fwnode_one(struct v4l2_async_notifier *notifier,
> struct v4l2_subdev *sd, struct fwnode_handle *sd_fwnode,
> @@ -86,13 +92,18 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
> bool sd_fwnode_is_ep;
> struct device *dev;
>
> + dev_dbg(sd->dev, "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(sd->dev, "async: direct match found\n");
> return true;
> + }
>
> /*
> * Otherwise, check if the sd fwnode and the asd fwnode refer to an
> @@ -105,8 +116,10 @@ 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(sd->dev, "async: matching node types\n");
"matching node type" is misleading as it suggests a match has been
found. As both sd and asd are of the same type, I would use a
message similar to the above
dev_dbg(sd->dev, "async: direct match failed\n");
> return false;
> + }
>
> /*
> * The sd and asd fwnodes are of different types. Get the device fwnode
> @@ -120,10 +133,15 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
> other_fwnode = sd_fwnode;
> }
>
> + dev_dbg(sd->dev, "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(sd->dev, "async: compat match not found\n");
and to be more consistent: "compat match failed"
> return false;
> + }
>
> /*
> * We have a heterogeneous match. Retrieve the struct device of the side
> @@ -143,12 +161,17 @@ match_fwnode_one(struct v4l2_async_notifier *notifier,
> dev->driver->name);
> }
>
> + dev_dbg(sd->dev, "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(sd->dev, "async: matching for notifier %pfw, sd %pfw\n",
> + dev_fwnode(notifier_dev(notifier)), sd->fwnode);
> +
> if (match_fwnode_one(notifier, sd, sd->fwnode, asd))
> return true;
>
> @@ -156,6 +179,8 @@ static bool match_fwnode(struct v4l2_async_notifier *notifier,
> if (IS_ERR_OR_NULL(sd->fwnode->secondary))
> return false;
>
> + dev_dbg(sd->dev, "async: trying secondary fwnode match\n");
> +
> return match_fwnode_one(notifier, sd, sd->fwnode->secondary, asd);
> }
>
> @@ -247,16 +272,21 @@ v4l2_async_nf_can_complete(struct v4l2_async_notifier *notifier)
> {
> struct v4l2_subdev *sd;
>
> - if (!list_empty(¬ifier->waiting))
> + if (!list_empty(¬ifier->waiting)) {
> + dev_dbg(notifier_dev(notifier), "async: waiting for subdevs\n");
> return false;
> + }
>
> list_for_each_entry(sd, ¬ifier->done, async_list) {
> struct v4l2_async_notifier *subdev_notifier =
> v4l2_async_find_subdev_notifier(sd);
>
> if (subdev_notifier &&
> - !v4l2_async_nf_can_complete(subdev_notifier))
> + !v4l2_async_nf_can_complete(subdev_notifier)) {
> + dev_dbg(notifier_dev(notifier),
> + "async: cannot complete\n");
These two will be printed out a lot of times, don't they ?
> return false;
> + }
> }
>
> return true;
> @@ -269,22 +299,32 @@ 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(¬ifier->waiting))
> return 0;
>
> + if (notifier->sd)
> + dev_dbg(notifier_dev(notifier), "async: trying to complete\n");
> +
> /* 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),
> + "async: V4L2 device not available\n");
is this a BUG() ?
> return 0;
> + }
>
> /* Is everything ready? */
> if (!v4l2_async_nf_can_complete(notifier))
> return 0;
>
> + dev_dbg(notifier_dev(__notifier), "async: complete\n");
> +
> return v4l2_async_nf_call_complete(notifier);
> }
>
> @@ -362,7 +402,12 @@ static int v4l2_async_match_notify(struct v4l2_async_notifier *notifier,
> */
> subdev_notifier->parent = notifier;
>
> - return v4l2_async_nf_try_all_subdevs(subdev_notifier);
> + ret = v4l2_async_nf_try_all_subdevs(subdev_notifier);
> +
> + dev_dbg(sd->dev, "async: bound to %s's notifier (ret %d)\n",
> + dev_name(notifier_dev(notifier)), ret);
> +
> + return ret;
This will only be print out if there's no subnotifier as a few lines
above we return early. Is this intentional ?
> }
>
> /* Test all async sub-devices in a notifier for a match. */
> --
> 2.30.2
>
