Re: [PATCH v1] power: add wakeup log

["Burakov, Anatoly" <anatoly.burakov@intel.com>]

On 24-Feb-22 2:38 AM, Li, Miao wrote:
> Hi,
> 
>> -----Original Message-----
>> From: Hunt, David <david.hunt@intel.com>
>> Sent: Wednesday, February 23, 2022 12:32 AM
>> To: Li, Miao <miao.li@intel.com>; dev@dpdk.org
>> Cc: Wang, Yinan <yinan.wang@intel.com>; stephen@networkplumber.org
>> Subject: Re: [PATCH v1] power: add wakeup log
>>
>>
>> On 22/2/2022 1:52 PM, Miao Li wrote:
>>> This patch adds a log in rte_power_monitor to show the core has been
>>> waked up.
>>>
>>> Signed-off-by: Miao Li <miao.li@intel.com>
>>> ---
>>>    lib/eal/x86/rte_power_intrinsics.c | 8 ++++++++
>>>    1 file changed, 8 insertions(+)
>>>
>>> diff --git a/lib/eal/x86/rte_power_intrinsics.c
>> b/lib/eal/x86/rte_power_intrinsics.c
>>> index f749da9b85..dd63e2b6eb 100644
>>> --- a/lib/eal/x86/rte_power_intrinsics.c
>>> +++ b/lib/eal/x86/rte_power_intrinsics.c
>>> @@ -128,6 +128,14 @@ rte_power_monitor(const struct
>> rte_power_monitor_cond *pmc,
>>>    			: "D"(0), /* enter C0.2 */
>>>    			  "a"(tsc_l), "d"(tsc_h));
>>>
>>> +	cur_value = __get_umwait_val(pmc->addr, pmc->size);
>>> +
>>> +	/* check if core has been waked up by changing monitoring value */
>>> +	if (pmc->fn(cur_value, pmc->opaque) != 0)
>>> +		RTE_LOG(INFO, EAL,
>>> +			"lcore %u is waked up from value change\n",
>>> +			rte_lcore_id());
>>> +
>>>    end:
>>>    	/* erase sleep address */
>>>    	rte_spinlock_lock(&s->lock);
>>
>>
>> Hi Li,
>>
>> If I'm not mistaken, a similar patch was added to a previous DPDK
>> release and then removed because of the enormous performance impact.
>>
>> This looks to be something similar, and it's adding a log message to a
>> low-level function. Also, as mentioned before, the intention in the
>> future is to call this function much more agressively, so there would be
>> hundreds of thousands of messages every second.
>>
>> We cannot add an RTE_LOG here. Please rework and put the log in the test
>> case instead.
> 
> I add a judgment before the output. When no packet arriver, the log will not be printed. When a lot of packets arriver, the rte_power_monitor will not be called. So I think the performance impact is small.
> 
>>
>> Also, regarding the wording, I would suggest  "lcore %u awoke due to
>> monitor address value change\n"
> 
> I will change the log content in next version.
> 
>>
>> Rgds,
>>
>> Dave.
>>
> 
> Thanks,
> Miao
> 
> 

Hi Miao,

I have to agree with Dave here, I don't think this patch should be 
merged, as there are several problems with it.

First of all, the result might be inaccurate in practice, because there 
is a race condition between reading value first and second time - 
UMONITOR protects us from that before we sleep, but not after. So, the 
information we get with `__get_umwait_val()` and calling a callback 
might be out of date by the time we reach that code. So, this code is 
*provably* vulnerable to race conditions.

More importantly, I do not see how this is a useful addition to DPDK. I 
have to ask: what is the problem the patch is trying to solve? Because 
if the problem being solved is validating full path from l3fwd-power 
down to `rte_power_monitor`, then it could be solved in other ways that 
are more agreeable.

For example, I believe we have logging inside l3fwd-power, so we can 
validate that it wakes up correctly. We *don't* have logging inside 
rte_power for these particular code paths, but IMO it would be 
unnecessary because l3fwd-power already effectively does that anyway. We 
*don't* have logging inside `rte_power_monitor`, but we can still 
validate it with unit tests, if the concern here is validating that the 
functionality works correctly.

So, we can verify `rte_power_monitor` works with unit tests. We *could* 
introspect `rte_power` callback code with more logging if that's 
required (although IMO unnecessary, given that l3fwd-power already does 
that), and we can validate that l3fwd-power wakes up correctly with 
existing logging. So, with the addition of unit tests, the entire stack 
would be validated.

Thus, to me, it seems like the patch is adding a (conditional) log 
message to a low level function, supported by an unnecessary and racy 
read/callback call for the sole purpose of checking information that 
does not get used anywhere else in the function other than in a log 
message, to solve a problem that could be solved in another way (with 
unit tests).

Is there anything that I'm missing here?

-- 
Thanks,
Anatoly