[DTrace-devel] [PATCH] test: Allow duplicate usym/umod/uaddr if for different pids

[Eugene Loh]

On 2/25/25 16:09, Kris Van Hees wrote:

> Eugene,
>
> Can you re-check this against the current dev and ensure the changes are
> correct?

This is interesting.

I guess what happens is that if we hit something like usym(addr), the 
kernel only knows the addr;  it's the consumer's job to do the usym() 
translation.  E.g., when the usym(addr) is in an aggregation key, the 
kernel's copy of the aggregation is potentially very large (many 
distinct addr values) while the consumer's copy of that aggregation is 
much more compact (many addr values mapping to the same sym).

Anyhow, dtrace loops over dtrace_work(), which calls dt_consume(), which 
calls dtrace_aggregate_snap().  When we "snapshot" the aggregation, we 
first call dtrace_aggregate_clear() and then walk the aggregations in 
the BPF map.

The problem appears to be that the usym() mapping changes.  Why? First 
of all, we could imagine that the mapping might change.  E.g., a library 
is loaded and unloaded and then a different library is loaded.  But it's 
also possible (I don't know why) for the mapping to fail once (but not 
on subsequent attempts).  Incidentally, the rule is if the translation 
fails, we just keep the addr value (rather than replacing this addr with 
the addr of the associated symbol).

So what happens is we snapshot the aggregation, and a couple of usym() 
translations fail.  They produce aggregation records (in the consumer's 
copy of the aggregation) with the raw addr values.  A later snapshot 
will clear the consumer's aggregation (zeroing out the values but 
preserving the keys).  If the translation is now successful, the "raw" 
address will be orphaned.  It will be reported with a count of 0.  The 
tests in question might (likely) fail.

I'm thinking about some fixes, but don't mind some feedback.

*)  One possibility is that if the usym() translation fails, we omit the 
data from the aggregation.

*)  Another option is that, when we loop routinely over 
dtrace_work()=>dt_consume()=>dtrace_aggregate_snap() and snapshot the 
aggregations, instead of calling dtrace_aggregate_clear() each time we 
"truncate" the consumer's copy of the aggregations... that is, throw 
away old keys altogether. We're reading them back in anyhow.

*)  Come to think of it, why are we snapshotting aggregations so often 
anyhow?  It's not as though we are unloading data from the kernel.  Why 
not snapshot lazily...  if needed for a printa() or END?

There remain other problems -- like, what if a library is loaded, used, 
usym(addr) shows up in an aggregation, a different library is loaded in 
its place, and the aggregation is not printed until after the 
translation information has become stale?  But maybe we can settle for 
getting these tests passing for now.

> On Mon, Jan 06, 2025 at 06:44:37PM -0500, Kris Van Hees wrote:
>> Withdrawing R-b for now after seeing these tests fail after this patch was
>> merged.  Needs further investigation.
>>
>> On Mon, Jan 06, 2025 at 04:04:25PM -0500, Kris Van Hees wrote:
>>> On Thu, Dec 05, 2024 at 02:13:18PM -0500, eugene.loh at oracle.com wrote:
>>>> From: Eugene Loh <eugene.loh at oracle.com>
>>>>
>>>> In 83da884cbdc5 ("Preface usym/umod/uaddr with pid"), a bug was fixed
>>>> in which addresses in the same module (or function) might be mapped to
>>>> multiple agg entries.  This fix helped the associated tests run much
>>>> more successfully.  Nonetheless, tests would sometimes still fail.
>>>>
>>>> Another problem is that the tests themselves were overly narrow.  It
>>>> is fine for a module (or function) to appear multiple times in the
>>>> aggregation output... if those entries correspond to different pids.
>>>>
>>>> Further, odd behaviors can result for some of the processes running on
>>>> a system.
>>>>
>>>> Change the tests to add a "pid" agg key.  Filter on only a few, select
>>>> pids.  Distinguish agg entries by pid.
>>>>
>>>> There are still occasional time outs observed with these tests,
>>>> presumably because the tick-2s probe is not firing (when profile-1234hz
>>>> is running).
>>>>
>>>> Signed-off-by: Eugene Loh <eugene.loh at oracle.com>
>>> Reviewed-by: Kris Van Hees <kris.van.hees at oracle.com>
>>>
>>>> ---
>>>>   test/unittest/profile-n/tst.ufunc.sh | 12 ++++++++----
>>>>   test/unittest/profile-n/tst.umod.sh  | 11 ++++++++---
>>>>   test/unittest/profile-n/tst.usym.sh  | 11 ++++++++---
>>>>   3 files changed, 24 insertions(+), 10 deletions(-)
>>>>
>>>> diff --git a/test/unittest/profile-n/tst.ufunc.sh b/test/unittest/profile-n/tst.ufunc.sh
>>>> index 243822407..f5174a1e2 100755
>>>> --- a/test/unittest/profile-n/tst.ufunc.sh
>>>> +++ b/test/unittest/profile-n/tst.ufunc.sh
>>>> @@ -11,10 +11,14 @@ tmpfile=$tmpdir/tst.profile_ufunc.$$
>>>>   script()
>>>>   {
>>>>   	$dtrace $dt_flags -qs /dev/stdin <<EOF
>>>> +	BEGIN
>>>> +	{
>>>> +		printf("dtrace is %d\n", \$pid);
>>>> +	}
>>>>   	profile-1234hz
>>>>   	/arg1 != 0/
>>>>   	{
>>>> -		@[ufunc(arg1)] = count();
>>>> +		@[ufunc(arg1), pid] = count();
>>>>   	}
>>>>   
>>>>   	tick-2s
>>>> @@ -52,9 +56,9 @@ if ! grep -q 'bash`[a-zA-Z_]' $tmpfile; then
>>>>   	status=1
>>>>   fi
>>>>   
>>>> -# Check that functions are unique.  (Exclude shared libraries and unresolved addresses.)
>>>> -if gawk '!/^ *(ld-linux-|lib|([^`]*`)?0x)/ {print $1}' $tmpfile | \
>>>> -     sort | uniq -c | grep -qv " 1 "; then
>>>> +# Check that functions are unique for each pid that interests us.
>>>> +dtpid=`awk '/^dtrace is [0-9]*$/ { print $3 }' $tmpfile`
>>>> +if gawk '$2 == '$child' || $2 == '$dtpid' {print $1, $2}' $tmpfile | sort | uniq -c | grep -qv " 1 "; then
>>>>   	echo ERROR: duplicate ufunc
>>>>   	status=1
>>>>   fi
>>>> diff --git a/test/unittest/profile-n/tst.umod.sh b/test/unittest/profile-n/tst.umod.sh
>>>> index 45d2b1e9b..7cfe2a073 100755
>>>> --- a/test/unittest/profile-n/tst.umod.sh
>>>> +++ b/test/unittest/profile-n/tst.umod.sh
>>>> @@ -11,10 +11,14 @@ tmpfile=$tmpdir/tst.profile_umod.$$
>>>>   script()
>>>>   {
>>>>   	$dtrace $dt_flags -qs /dev/stdin <<EOF
>>>> +	BEGIN
>>>> +	{
>>>> +		printf("dtrace is %d\n", \$pid);
>>>> +	}
>>>>   	profile-1234hz
>>>>   	/arg1 != 0/
>>>>   	{
>>>> -		@[umod(arg1)] = count();
>>>> +		@[umod(arg1), pid] = count();
>>>>   	}
>>>>   
>>>>   	tick-2s
>>>> @@ -52,8 +56,9 @@ if ! grep -wq 'bash' $tmpfile; then
>>>>   	status=1
>>>>   fi
>>>>   
>>>> -# Check that modules are unique.  (Exclude shared libraries and unresolved addresses.)
>>>> -if gawk '!/^ *lib/ && !/^ *ld-.*\.so / && !/^ *0x/ {print $1}' $tmpfile | sort | uniq -c | grep -qv " 1 "; then
>>>> +# Check that modules are unique for each pid that interests us.
>>>> +dtpid=`awk '/^dtrace is [0-9]*$/ { print $3 }' $tmpfile`
>>>> +if gawk '$2 == '$child' || $2 == '$dtpid' {print $1, $2}' $tmpfile | sort | uniq -c | grep -qv " 1 "; then
>>>>   	echo ERROR: duplicate umod
>>>>   	status=1
>>>>   fi
>>>> diff --git a/test/unittest/profile-n/tst.usym.sh b/test/unittest/profile-n/tst.usym.sh
>>>> index 634e633b3..8e373b976 100755
>>>> --- a/test/unittest/profile-n/tst.usym.sh
>>>> +++ b/test/unittest/profile-n/tst.usym.sh
>>>> @@ -11,10 +11,14 @@ tmpfile=$tmpdir/tst.profile_usym.$$
>>>>   script()
>>>>   {
>>>>   	$dtrace $dt_flags -qs /dev/stdin <<EOF
>>>> +	BEGIN
>>>> +	{
>>>> +		printf("dtrace is %d\n", \$pid);
>>>> +	}
>>>>   	profile-1234hz
>>>>   	/arg1 != 0/
>>>>   	{
>>>> -		@[usym(arg1)] = count();
>>>> +		@[usym(arg1), pid] = count();
>>>>   	}
>>>>   
>>>>   	tick-2s
>>>> @@ -52,8 +56,9 @@ if ! grep -q 'bash`[a-zA-Z_]' $tmpfile; then
>>>>   	status=1
>>>>   fi
>>>>   
>>>> -# Check that symbols are unique.  (Exclude shared libraries and unresolved addresses.)
>>>> -if gawk '!/^ *lib/ && !/^ *0x/ {print $1}' $tmpfile | sort | uniq -c | grep -qv " 1 "; then
>>>> +# Check that symbols are unique for each pid that interests us.
>>>> +dtpid=`awk '/^dtrace is [0-9]*$/ { print $3 }' $tmpfile`
>>>> +if gawk '$2 == '$child' || $2 == '$dtpid' {print $1, $2}' $tmpfile | sort | uniq -c | grep -qv " 1 "; then
>>>>   	echo ERROR: duplicate usym
>>>>   	status=1
>>>>   fi
>>>> -- 
>>>> 2.43.5
>>>>