dtrace discuss - May 2009 - Anomaly in Dtrace copyin() observed through DTT's zvmstat

Hi all,


Not sure if this is an anomaly in dtrace''s copyin() or just
the way that the hacks in DTT''s zvmstat created this observation.


I am seeing this anomaly where copyin() from syscall::write:entry/return
probe is getting trailing data from the previous calls.


This can be observed from the zvmstat script bundled in DTT,
running on system where there are zones which the zonenames
are of various string length.


For example, on a system with the following zones configured:

bash-3.00# zoneadm list
global
bravo
alpha88
alps
apple
alibaba
allscp
cvsserv
lego1
situationroom
cookbook
fire99
pooh
prodapps
rdrv
redzone

bash-3.00# ./zvmstat
      ZONE   re    mf   fr    sr  epi  epo  epf  api  apo  apf  fpi fpo  fpf
    global   76   324    0     0    0    0    0    0    0    0    0 0    0
    bravol    0     0    0     0    0    0    0    0    0    0    0 0    0
   alpha88    0     0    0     0    0    0    0    0    0    0    0 0    0
   alpsa88    0     0    0     0    0    0    0    0    0    0    0 0    0
   apple88    0     0    0     0    0    0    0    0    0    0    0 0    0
   alibaba    0     0    0     0    0    0    0    0    0    0    0 0    0
   allscpa    0     0    0     0    0    0    0    0    0    0    0 0    0
   cvsserv    0     0    0     0    0    0    0    0    0    0    0 0    0
   lego1rv    0     0    0     0    0    0    0    0    0    0    0 0    0
situationroom    0     0    0     0    0    0    0    0    0    0    0   0    0
cookbooknroom    0     0    0     0    0    0    0    0    0    0    0   0    0
fire99oknroom    0     0    0     0    0    0    0    0    0    0    0   0    0
pooh99oknroom    0     0    0     0    0    0    0    0    0    0    0   0    0
prodappsnroom    0     0    0     0    0    0    0    0    0    0    0   0    0
rdrvappsnroom    0     0    0     0    0    0    0    0    0    0    0   0    0
redzonesnroom    0     0    0     0    0    0    0    0    0    0    0   0    0


Notice that any subsequent zonename string that is shorter
than it''s prev. neighbours will have it''s neighbour trailing
string.


Having suspecting arg2 (length) returned by the
syscall::write:entry, I stripped down zvmstat further,
to print the string length as well. Well, the string
lengths all appeared to be correct.


bash-3.00# ./zv.d
ZONE
----
arg2 - 1 = 6 [global]
arg2 - 1 = 5 [bravol]
arg2 - 1 = 7 [alpha88]
arg2 - 1 = 4 [alpsa88]
arg2 - 1 = 5 [apple88]
arg2 - 1 = 7 [alibaba]
arg2 - 1 = 6 [allscpa]
arg2 - 1 = 7 [cvsserv]
arg2 - 1 = 5 [lego1rv]
arg2 - 1 = 13 [situationroom]
arg2 - 1 = 8 [cookbooknroom]
arg2 - 1 = 6 [fire99oknroom]
arg2 - 1 = 4 [pooh99oknroom]
arg2 - 1 = 8 [prodappsnroom]
arg2 - 1 = 4 [rdrvappsnroom]
arg2 - 1 = 7 [redzonesnroom]


If I add in a print(" \b") as below to trigger additional
syscall::write: probes, I''ve got the correct values.
*BUT* this firing of probe triggered an neccessary cosmetic
issue with an additional printout, not an ideal workaround,
and the observation is still a puzzle to me.

   156   /*
   157    * Scrape zone listing
   158    */
   159   syscall::write:entry
   160   /listing && (execname == "zoneadm") &&
   161   (curthread->t_procp->p_parent->p_ppid == $pid)/
   162   {
   163          printf(" \b");      ### Triggers another probe.
   164          /* read zoneadm output */
   165          zonelist[zonemax] = stringof(copyin(arg1, arg2 - 1));
   166          zone_len[zonemax] = arg2 - 1;
   167          /* increment max number of zones */
   168          zonemax++;
   169   }

bash-3.00# ./zv.d
arg2 - 1 = 6 [global]
arg2 - 1 = 5 [bravo]
arg2 - 1 = 7 [alpha88]
arg2 - 1 = 4 [alps]
arg2 - 1 = 5 [apple]
arg2 - 1 = 7 [alibaba]
arg2 - 1 = 6 [allscp]
arg2 - 1 = 7 [cvsserv]
arg2 - 1 = 5 [lego1]
arg2 - 1 = 13 [situationroom]
arg2 - 1 = 8 [cookbook]
arg2 - 1 = 6 [fire99]
arg2 - 1 = 4 [pooh]
arg2 - 1 = 8 [prodapps]
arg2 - 1 = 4 [rdrv]
arg2 - 1 = 7 [redzone]
ZONE
----
arg2 - 1 = 6 [global]
arg2 - 1 = 5 [bravo]
arg2 - 1 = 7 [alpha88]
arg2 - 1 = 4 [alps]
arg2 - 1 = 5 [apple]
arg2 - 1 = 7 [alibaba]
arg2 - 1 = 6 [allscp]
arg2 - 1 = 7 [cvsserv]
arg2 - 1 = 5 [lego1]
arg2 - 1 = 13 [situationroom]
arg2 - 1 = 8 [cookbook]
arg2 - 1 = 6 [fire99]
arg2 - 1 = 4 [pooh]
arg2 - 1 = 8 [prodapps]
arg2 - 1 = 4 [rdrv]
arg2 - 1 = 7 [redzone]


My ultimate question here is, is this a bug in
Dtrace copyin()/copyinstr() here, or I am missing
something here?

TIA

Regards
ST
-- 
This message posted from opensolaris.org

Ok. I have came up with a more simplified demonstration of the issue
at hand. Comments prefixed with "!!!".


!!! Using the following very simple "hello_print" program: 


# cat hello_print.c
/* hello_print.c */

#include <stdio.h>

main()
{
        printf("ss20\n");
	printf("sparcstation\n");
	printf("suni386\n");
	printf("itanium\n");
	printf("austinpower\n");
	printf("u27\n");
	printf("u24\n");
	printf("galaxy\n");
	printf("sunfire240\n");
        printf("v890\n");
	printf("sunfire15000\n");
	printf("x4120\n");
	printf("u\n");
	printf("deadman\n");
	printf("snooping\n");
	printf("0xdeadbeef\n");
	printf("null\n");
	printf("trap0x31\n");
	printf("u10\n");

}


!!! And running the following dtrace script, "c.d" in 
!!! one terminal, and then start up the "hello_print" 
!!! in another terminal.


# cat c.d
#!/usr/sbin/dtrace -qs


BEGIN
{
	namemax = 0;
	namei = 0;
	rolling = 0;
	printf("\n");
	printf("Please run ''hello_print'' in another
terminal.\n");
	printf("-----------------------------------------------\n");
}


syscall::write:entry
/(execname == "hello_print")/
{
	namelist[namemax] = stringof(copyin(arg1, arg2 - 1));
	namelen[namemax] = arg2 - 1;  /* not including terminal NUL */
	namemax++;
}

/* When hello_print exit(), let''s get printing going by
   triggering the write probe */
fbt::exit:entry
/(execname == "hello_print")/
{
	rolling = 1;
	printf(" \b");
}

syscall::write:return
/(execname == "dtrace") && (pid == $pid) &&
 (namei < namemax) /
{
	printf("len = %2.2d [%s]\n", namelen[namei], namelist[namei]);
	namei++;
}

syscall::write:return
/(execname == "dtrace") && (pid == $pid) && (namei
>= namemax) && rolling/
{
	exit(0);
}

END
{
	printf("---------------\n");
}


!!! Below is what I got. Notice that any string that
!!! is 3 characters in length ( well, 4 chars counting
!!! the terminating null) will have the copyin() done
!!! correctly. Anything longer, will inherit it''s neighbour
!!! trailing strings.


# ./hello_print     
ss20
sparcstation
suni386
itanium
austinpower
u27
u24
galaxy
sunfire240
v890
sunfire15000
x4120
u
deadman
snooping
0xdeadbeef
null
trap0x31
u10


# ./c.d             

Please run ''hello_print'' in another terminal.
-----------------------------------------------
len = 04 [ss20]
len = 12 [sparcstation]
len = 07 [suni386ation]
len = 07 [itaniumation]
len = 11 [austinpowern]
len = 03 [u27]
len = 03 [u24]
len = 06 [galaxypowern]
len = 10 [sunfire240rn]
len = 04 [v890ire240rn]
len = 12 [sunfire15000]
len = 05 [x4120re15000]
len = 01 [u]
len = 07 [deadman15000]
len = 08 [snooping5000]
len = 10 [0xdeadbeef00]
len = 04 [nulladbeef00]
len = 08 [trap0x31ef00]
len = 03 [u10]
---------------


!!! I am sure this is not the right(or consistent) behaviour 
!!! here. Or I really have gone off tangent on this?
!!! Appreciate if anyone can shed some light on the 
!!! observation here.

TIA

Regards
S.T.
-- 
This message posted from opensolaris.org

Hi S.T.

The memory that''s used to store the string is reused from the previous
iteration. If you either null-terminal the string yourself or change  
the copyin() to include the trailing null your script should work as  
predicted.

Adam

On May 23, 2009, at 11:01 AM, S.T.Chang wrote:
> Ok. I have came up with a more simplified demonstration of the issue
> at hand. Comments prefixed with "!!!".
>
>
> !!! Using the following very simple "hello_print" program:
>
>
> # cat hello_print.c
> /* hello_print.c */
>
> #include <stdio.h>
>
> main()
> {
>        printf("ss20\n");
> 	printf("sparcstation\n");
> 	printf("suni386\n");
> 	printf("itanium\n");
> 	printf("austinpower\n");
> 	printf("u27\n");
> 	printf("u24\n");
> 	printf("galaxy\n");
> 	printf("sunfire240\n");
>        printf("v890\n");
> 	printf("sunfire15000\n");
> 	printf("x4120\n");
> 	printf("u\n");
> 	printf("deadman\n");
> 	printf("snooping\n");
> 	printf("0xdeadbeef\n");
> 	printf("null\n");
> 	printf("trap0x31\n");
> 	printf("u10\n");
>
> }
>
>
> !!! And running the following dtrace script, "c.d" in
> !!! one terminal, and then start up the "hello_print"
> !!! in another terminal.
>
>
> # cat c.d
> #!/usr/sbin/dtrace -qs
>
>
> BEGIN
> {
> 	namemax = 0;
> 	namei = 0;
> 	rolling = 0;
> 	printf("\n");
> 	printf("Please run ''hello_print'' in another
terminal.\n");
> 	printf("-----------------------------------------------\n");
> }
>
>
> syscall::write:entry
> /(execname == "hello_print")/
> {
> 	namelist[namemax] = stringof(copyin(arg1, arg2 - 1));
> 	namelen[namemax] = arg2 - 1;  /* not including terminal NUL */
> 	namemax++;
> }
>
> /* When hello_print exit(), let''s get printing going by
>   triggering the write probe */
> fbt::exit:entry
> /(execname == "hello_print")/
> {
> 	rolling = 1;
> 	printf(" \b");
> }
>
> syscall::write:return
> /(execname == "dtrace") && (pid == $pid) &&
> (namei < namemax) /
> {
> 	printf("len = %2.2d [%s]\n", namelen[namei], namelist[namei]);
> 	namei++;
> }
>
> syscall::write:return
> /(execname == "dtrace") && (pid == $pid) &&
(namei >= namemax) &&
> rolling/
> {
> 	exit(0);
> }
>
> END
> {
> 	printf("---------------\n");
> }
>
>
> !!! Below is what I got. Notice that any string that
> !!! is 3 characters in length ( well, 4 chars counting
> !!! the terminating null) will have the copyin() done
> !!! correctly. Anything longer, will inherit it''s neighbour
> !!! trailing strings.
>
>
> # ./hello_print
> ss20
> sparcstation
> suni386
> itanium
> austinpower
> u27
> u24
> galaxy
> sunfire240
> v890
> sunfire15000
> x4120
> u
> deadman
> snooping
> 0xdeadbeef
> null
> trap0x31
> u10
>
>
> # ./c.d
>
> Please run ''hello_print'' in another terminal.
> -----------------------------------------------
> len = 04 [ss20]
> len = 12 [sparcstation]
> len = 07 [suni386ation]
> len = 07 [itaniumation]
> len = 11 [austinpowern]
> len = 03 [u27]
> len = 03 [u24]
> len = 06 [galaxypowern]
> len = 10 [sunfire240rn]
> len = 04 [v890ire240rn]
> len = 12 [sunfire15000]
> len = 05 [x4120re15000]
> len = 01 [u]
> len = 07 [deadman15000]
> len = 08 [snooping5000]
> len = 10 [0xdeadbeef00]
> len = 04 [nulladbeef00]
> len = 08 [trap0x31ef00]
> len = 03 [u10]
> ---------------
>
>
> !!! I am sure this is not the right(or consistent) behaviour
> !!! here. Or I really have gone off tangent on this?
> !!! Appreciate if anyone can shed some light on the
> !!! observation here.
>
> TIA
>
> Regards
> S.T.
> -- 
> This message posted from opensolaris.org
> _______________________________________________
> dtrace-discuss mailing list
> dtrace-discuss at opensolaris.org

--
Adam Leventhal, Fishworks                        http://blogs.sun.com/ahl

Hi Adam, 

Thanks for the reply.
> If you either null-terminal the string yourself
Yes, inserting a trailing null works.
> or change the copyin() to include the trailing 
> null your script should work as predicted.
Using copyin(arg1, arg2) or copyinstr(arg1)
shown that there is no terminating null in
arg1 :-) My fault... I should have thought of
this.


I will advise the CU to modify their script to
insert a trailing NULL.


Thanks.

Regards
S.T.
-- 
This message posted from opensolaris.org