new issues w/ dtrace aborting...

[Mark Johnston]

On Thu, Oct 17, 2013 at 01:06:58PM -0700, John-Mark Gurney wrote:
> I'm see this failure which is reproducable:
> # dtrace -s ./disklatencycmd.d -x evaltime=postinit -c ./catall
> Tracing... Hit Ctrl-C to end.
> 
> Now, I have spent some time trying to debug this error and have
> gotten a stack trace:
> #0  dt_divide_128 (dividend=0x7fffffffd240, divisor=0, quotient=0x7fffffffd240)
>     at /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_consume.c:221
> #1  0x0000000800a8d343 in dt_stddev (data=0x802bb3e48, normal=1)
>     at /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_consume.c:372
> #2  0x0000000800a9549a in dt_aggregate_valcmp (lhs=<value optimized out>, 
>     rhs=<value optimized out>)
>     at /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_aggregate.c:120
> #3  0x0000000800a93821 in dt_aggregate_varvalcmp (lhs=0x804679240, 
>     rhs=0x804679260)
>     at /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_aggregate.c:950
> #4  0x0000000801a3d6aa in qsort () from /lib/libc.so.7
> #5  0x0000000800a93c88 in dt_aggregate_walk_sorted (dtp=0x80281d000, 
>     func=0x800a8f7d0 <dt_print_agg>, arg=0x7fffffffd498, 
>     sfunc=<value optimized out>)
>     at /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_aggregate.c:1275
> #6  0x0000000800a951c6 in dtrace_aggregate_print (dtp=0x80281d000, 
>     fp=<value optimized out>, func=<value optimized out>)
>     at /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_aggregate.c:1880
> #7  0x000000000040387f in main (argc=<value optimized out>, 
>     argv=0x7fffffffd700)
>     at /usr/src/cddl/usr.sbin/dtrace/../../../cddl/contrib/opensolaris/cmd/dtrace/dtrace.c:1921
> 
> Now the weird part is that between frame 3 and frame 0, the address of
> lhs/data changes, yet if you look at the code, it is passing the pointer
> straight through w/o modification...  The value pointed to by lhs is
> valid and non-zero, but in frame 0 the different pointer is now zero..
> 
> The script catall:
> #!/bin/sh -
> 
> #since dtrace has issues:
> find /mnt -type f -exec cat {} + > /dev/null
> 
> The directory /mnt has a FS that only contains a recent export of HEAD..
> I also umount/mount before each run to make sure the disk cache is clear,
> otherwise it's possible that all the data will be cached in memory, and
> not perform any io...

I can reproduce this by just running it on my laptop and killing it with
ctrl-C. I'll work on figuring it out this week. Thanks for reporting it.

> 
> It looks like it's an issue w/ clear(@stddev) as this is the script I've
> reduced it to reproduce the failiure:
> #pragma D option quiet
> #pragma D option dynvarsize=16m
>         
> io:::start  
> {
>         start_time[arg0] = timestamp;
> }
>         
> io:::done
> /this->start = start_time[arg0]/
> {
>         this->delta = (timestamp - this->start) / 1000;
>         @stddev[args[1]->device_name, args[1]->unit_number] = stddev(this->delta
> );
>         start_time[arg0] = 0;
> }
> 
> dtrace:::END
> {
>         clear(@stddev);
> }
> 
> Obviously for this to be useful, you'd print out the stddev, but the
> abort happens either way...
> 
> Thanks.
> 
> -- 
>   John-Mark Gurney				Voice: +1 415 225 5579
> 
>      "All that I will do, has been done, All that I have, has not."
> _______________________________________________
> freebsd-dtrace at freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-dtrace
> To unsubscribe, send any mail to "freebsd-dtrace-unsubscribe at freebsd.org"