Received-SPF: pass (google.com: domain of linux-kernel+bounces-202899-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:40f1:3f00::1 as permitted sender) client-ip=2604:1380:40f1:3f00::1;
Message-ID: <25ff111f-039d-4280-b604-ad3d2b9933fb@linux.intel.com>
Date: Wed, 5 Jun 2024 18:15:58 +0200
Precedence: bulk
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Subject: Re: [PATCH v2 3/4] soundwire: bus: clean up probe warnings
To: Johan Hovold <johan@kernel.org>
Cc: Johan Hovold <johan+linaro@kernel.org>, Vinod Koul <vkoul@kernel.org>,
 Bard Liao <yung-chuan.liao@linux.intel.com>,
 Sanyog Kale <sanyog.r.kale@intel.com>, alsa-devel@alsa-project.org,
 linux-kernel@vger.kernel.org
References: <20240604075213.20815-1-johan+linaro@kernel.org>
 <20240604075213.20815-4-johan+linaro@kernel.org>
 <8dd7cadc-138c-4ef5-b06f-7177550b1215@linux.intel.com>
 <Zl7boEkMpQaELARP@hovoldconsulting.com>
 <970501b1-09ae-4f2c-a078-2b4f23fe460e@linux.intel.com>
 <Zl8iUmOfrjw3gWVX@hovoldconsulting.com>
 <0d15954f-0158-4a56-afef-f0d043135146@linux.intel.com>
 <ZmBWBrJDRjPn6TpA@hovoldconsulting.com>
Content-Language: en-US
From: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
In-Reply-To: <ZmBWBrJDRjPn6TpA@hovoldconsulting.com>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit


On 6/5/24 14:11, Johan Hovold wrote:
> On Tue, Jun 04, 2024 at 05:07:39PM +0200, Pierre-Louis Bossart wrote:
>> \
>>>>>>> @@ -123,7 +123,7 @@ static int sdw_drv_probe(struct device *dev)
>>>>>>>  	/* init the dynamic sysfs attributes we need */
>>>>>>>  	ret = sdw_slave_sysfs_dpn_init(slave);
>>>>>>>  	if (ret < 0)
>>>>>>> -		dev_warn(dev, "Slave sysfs init failed:%d\n", ret);
>>>>>>> +		dev_warn(dev, "failed to initialise sysfs: %d\n", ret);
>>>>>>>  
>>>>>>>  	/*
>>>>>>>  	 * Check for valid clk_stop_timeout, use DisCo worst case value of
>>>>>>> @@ -147,7 +147,7 @@ static int sdw_drv_probe(struct device *dev)
>>>>>>>  	if (drv->ops && drv->ops->update_status) {
>>>>>>>  		ret = drv->ops->update_status(slave, slave->status);
>>>>>>>  		if (ret < 0)
>>>>>>> -			dev_warn(dev, "%s: update_status failed with status %d\n", __func__, ret);
>>>>>>> +			dev_warn(dev, "failed to update status: %d\n", ret);
>>>>>>
>>>>>> the __func__ does help IMHO, 'failed to update status' is way too general...
>>>>>
>>>>> Error messages printed with dev_warn will include the device and driver
>>>>> names so this message will be quite specific still.
>>>>
>>>> The goal isn't to be 'quite specific' but rather 'completely
>>>> straightforward'. Everyone can lookup a function name in a xref tool and
>>>>  quickly find out what happened. Doing 'git grep' on message logs isn't
>>>> great really, and over time logs tend to be copy-pasted. Just look at
>>>> the number of patches where we had to revisit the dev_err logs to make
>>>> then really unique/useful.
>>>
>>> Error message should be self-contained and give user's some idea of what
>>> went wrong and not leak implementation details like function names (and
>>> be greppable, which "%s:" is not).
>>
>> "Failed to update status" doesn't sound terribly self-contained to me.
>>
>> It's actually a great example of making the logs less clear with good
>> intentions. How many people know that the SoundWire bus exposes an
>> 'update_status' callback, and that callback can be invoked from two
>> completely different places (probe or on device attachment)?
>>
>> /* Ensure driver knows that peripheral unattached */
>> ret = sdw_update_slave_status(slave, status[i]);
>> if (ret < 0)
>> 	dev_warn(&slave->dev, "Update Slave status failed:%d\n", ret);
>>
>> You absolutely want to know which of these two cases failed, but with
>> your changes they now look rather identical except for the order of
>> words. one would be 'failed to update status' and the other 'update
>> status failed'.
>>
>> What is much better is to know WHEN this failure happens, then folks
>> looking at logs to fix a problem don't need to worry about precise
>> wording or word order.
>>
>> It's a constant battle to get meaningful messages that are useful for
>> validation/integration folks, and my take is that it's a
>> windmill-fighting endeavor. The function name is actually more useful,
>> it's not an implementation detail, it's what you're looking for when
>> reverse-engineering problematic sequences from a series of CI logs.
> 
> Just add "at probe" to differentiate the two cases if you really think
> this is an issue:
> 
> 	dev_warn(dev, "failed to update status at probe: %d\n", ret);

__func__ would provide equivalent functionality, only more precise...
I guess it's time for Vinod and Bard to chime in.