dtrace discuss - Mar 2007 - How to monitor and dump a dynamic buffer?

Hi experts,

I''d like to use dtrace to monitor a buffer and dump it. But the
buffer''s
length is variable. The word "for" is not supported yet, so that I
have
to use the following workaround. 

However, for multi-threads and large buffer, the output of data may be
out of order. that is, the data of two buffers will be printed with
overlap. I''ve ever tried to use a increasing buffer array(such as,
pdata[k++] = mblk for each entry) to record and print the buffers
sequentially. But it would eat up the dtrace buffer soon and it doesn''t
work for multi-core system since the callback entry is not protected.

Is there any way to lock the system when entering callback entry? Is it
possible to print the whole buffer in position (A)? Just like copyout,
it can copy a buffer to an address, can I write a similar function to
print the buffer to screen? Thanks.


::hid_interrupt_pipe_callback:entry
{
        req = (usb_intr_req_t *)arg1;
        mblk = req->intr_data;
        lens = req->intr_len;

        data = (uint8_t *)mblk->b_rptr;
        i = 0;
	
	/* what a pity that "for" is not supported.	<= (A)
	 for (i = 0 ; i < lens; i++)
		printf("%x ", mblk->b_rptr[i]);
	*/
}

::hid_interrupt_pipe_callback:return
{
        lens = 0;
        printf("\n");
}

entry,return
/lens > 0 && i < lens/
{
        printf("0x%02x  ", mblk->b_rptr[i]);
        i++;
}



-- 
Best Regards,
GaoPeng Chen
Call: +86-10-62673005
Ext: x82005
Sun Microsystem Inc. China

Since the trace record for a single probe clause is fixed length, here 
are the only ways that I know to record trace data that varies in length:

   1. Use multiple probe clauses for the same probe, and check for the
      presence of the variable portions with predicates.   Since all of
      the clauses for one probe execute in order, they should all be
      strung together in one trace buffer.  Multiple threads on
      different processors will be recorded in different trace buffers,
      and then displayed one at a time by the DTrace command.
   2. Record the maximum length every time, but also record something
      that tells you how much of the trace record is real data.  You
      could use tracemem to record the maximum.  If storage for original
      data is dynamic, and accessing the maximum could lead to access
      violations, then you could declare a thread-local scalar array to
      be the maximum length, and then copy your data to it using a bunch
      of conditional operators in a creative fashion.  This should be as
      "order safe" as the previous method.  BTW: you can change the
      string lengths from the default 256 at the start of your DTrace
      run, and then stuff a string with trace output one sub-string at a
      time with a whole bunch of conditional expressions, put a NULL
      character at the varying string-end, and then trace the string. 
      The whole string will get recorded in the buffer, but the DTrace
      command will only display up to the NULL character.
   3. Do something like what you are doing now and utilize other probe
      events to get the data recorded.  You''re still going to need to
      know the maximum length, because you need to copy the data to a
      DTrace variable, since the original data is vulnerable to being
      overwritten.  However, you might consider using a probe for which
      you have control over the firing so that you are not causing a lot
      of unnecessary probe events.  For example, you could write a short
      C program, one that is started with the -c option and receives
      piped data from the other which you call using "system" to pass
      the number of iterations of a subroutine to call.  In your DTrace
      script, you have a PID probe for that function which handles the
      extended part of the buffer.   This method is not the least bit
      order safe, so you may need to tag each trace record with order
      data, and then reconstruct it with a post-processing script.

I''m not sure what kind of lock you have in mind.  You obviously
can''t
stop the system, because then your probe clauses wouldn''t be executing 
any more to get things restarted.  "chill" will pause the system 
momentarily, but, again, nothing happens to get your data handling 
completed while the system is chilled.

Chip


Gaopeng Chen - Sun China wrote:
> Hi experts,
>
> I''d like to use dtrace to monitor a buffer and dump it. But the
buffer''s
> length is variable. The word "for" is not supported yet, so that
I have
> to use the following workaround. 
>
> However, for multi-threads and large buffer, the output of data may be
> out of order. that is, the data of two buffers will be printed with
> overlap. I''ve ever tried to use a increasing buffer array(such as,
> pdata[k++] = mblk for each entry) to record and print the buffers
> sequentially. But it would eat up the dtrace buffer soon and it
doesn''t
> work for multi-core system since the callback entry is not protected.
>
> Is there any way to lock the system when entering callback entry? Is it
> possible to print the whole buffer in position (A)? Just like copyout,
> it can copy a buffer to an address, can I write a similar function to
> print the buffer to screen? Thanks.
>
>
> ::hid_interrupt_pipe_callback:entry
> {
>         req = (usb_intr_req_t *)arg1;
>         mblk = req->intr_data;
>         lens = req->intr_len;
>
>         data = (uint8_t *)mblk->b_rptr;
>         i = 0;
> 	
> 	/* what a pity that "for" is not supported.	<= (A)
> 	 for (i = 0 ; i < lens; i++)
> 		printf("%x ", mblk->b_rptr[i]);
> 	*/
> }
>
> ::hid_interrupt_pipe_callback:return
> {
>         lens = 0;
>         printf("\n");
> }
>
> entry,return
> /lens > 0 && i < lens/
> {
>         printf("0x%02x  ", mblk->b_rptr[i]);
>         i++;
> }
>
>
>
>

Firstly, thanks for great help. I still have some questions.

On Sat, 2007-03-31 at 01:10, Chip Bennett wrote:
> Since the trace record for a single probe clause is fixed length, here 
> are the only ways that I know to record trace data that varies in length:
> 
>    1. Use multiple probe clauses for the same probe, and check for the
I don''t understand well about this. Since the buffer length is variable
and the address is from args, how many probe clauses should be defined? 
>       presence of the variable portions with predicates.   Since all of
>       the clauses for one probe execute in order, they should all be
>       strung together in one trace buffer.  Multiple threads on
>       different processors will be recorded in different trace buffers,
>       and then displayed one at a time by the DTrace command.
>    2. Record the maximum length every time, but also record something
>       that tells you how much of the trace record is real data.  You
>       could use tracemem to record the maximum.  If storage for original
>       data is dynamic, and accessing the maximum could lead to access
>       violations, then you could declare a thread-local scalar array to
>       be the maximum length, and then copy your data to it using a bunch
>       of conditional operators in a creative fashion.  This should be as
That may work. But the buffer I want to dump has a big range, from 0 to
several KB. So it''s not convenient to use tracemem here. BTW, What I
monitor is not a string buffer, it may includes many
zeroes.
>       "order safe" as the previous method.  BTW: you can change
the
>       string lengths from the default 256 at the start of your DTrace
>       run, and then stuff a string with trace output one sub-string at a
>       time with a whole bunch of conditional expressions, put a NULL
>       character at the varying string-end, and then trace the string. 
>       The whole string will get recorded in the buffer, but the DTrace
>       command will only display up to the NULL character.
>    3. Do something like what you are doing now and utilize other probe
>       events to get the data recorded.  You''re still going to need
to
>       know the maximum length, because you need to copy the data to a
>       DTrace variable, since the original data is vulnerable to being
>       overwritten.  However, you might consider using a probe for which
>       you have control over the firing so that you are not causing a lot
>       of unnecessary probe events.  For example, you could write a short
>       C program, one that is started with the -c option and receives
>       piped data from the other which you call using "system" to
pass
>       the number of iterations of a subroutine to call.  In your DTrace
>       script, you have a PID probe for that function which handles the
>       extended part of the buffer.   This method is not the least bit
>       order safe, so you may need to tag each trace record with order
>       data, and then reconstruct it with a post-processing script.
Yes, this may be a good idea if dtrace copyout() can copy the buffer to
user space. Thus the data can be processed in the application. I''ll
have
a try.
> 
> I''m not sure what kind of lock you have in mind.  You obviously
can''t
> stop the system, because then your probe clauses wouldn''t be
executing
> any more to get things restarted.  "chill" will pause the system 
> momentarily, but, again, nothing happens to get your data handling 
> completed while the system is chilled.
What I want is not lock the whole system , it''s just to make the probe
called serially like the following. So that I have enough time to
process the data buffer sequentially when there are multiple processors.

::hid_interrupt_pip_callback:entry
{
	mutex_enter(...);

	...

	mutex_exit(...);
}
> 
> Chip
> 
> 
> Gaopeng Chen - Sun China wrote:
> > Hi experts,
> >
> > I''d like to use dtrace to monitor a buffer and dump it. But
the buffer''s
> > length is variable. The word "for" is not supported yet, so
that I have
> > to use the following workaround. 
> >
> > However, for multi-threads and large buffer, the output of data may be
> > out of order. that is, the data of two buffers will be printed with
> > overlap. I''ve ever tried to use a increasing buffer
array(such as,
> > pdata[k++] = mblk for each entry) to record and print the buffers
> > sequentially. But it would eat up the dtrace buffer soon and it
doesn''t
> > work for multi-core system since the callback entry is not protected.
> >
> > Is there any way to lock the system when entering callback entry? Is
it
> > possible to print the whole buffer in position (A)? Just like copyout,
> > it can copy a buffer to an address, can I write a similar function to
> > print the buffer to screen? Thanks.
> >
> >
> > ::hid_interrupt_pipe_callback:entry
> > {
> >         req = (usb_intr_req_t *)arg1;
> >         mblk = req->intr_data;
> >         lens = req->intr_len;
> >
> >         data = (uint8_t *)mblk->b_rptr;
> >         i = 0;
> > 	
> > 	/* what a pity that "for" is not supported.	<= (A)
> > 	 for (i = 0 ; i < lens; i++)
> > 		printf("%x ", mblk->b_rptr[i]);
> > 	*/
> > }
> >
> > ::hid_interrupt_pipe_callback:return
> > {
> >         lens = 0;
> >         printf("\n");
> > }
> >
> > entry,return
> > /lens > 0 && i < lens/
> > {
> >         printf("0x%02x  ", mblk->b_rptr[i]);
> >         i++;
> > }
> >
> >
> >
> >   
-- 
Best Regards,
GaoPeng Chen
Call: +86-10-62673005
Ext: x82005
Sun Microsystem Inc. China

Gaopeng Chen - Sun China wrote:
>
>   
> I don''t understand well about this. Since the buffer length is
variable
> and the address is from args, how many probe clauses should be defined? 
>   
If you want to control the length down to the byte, you''d need a probe
clause for every byte: probably not a good choice for
you.
>
> That may work. But the buffer I want to dump has a big range, from 0 to
> several KB. So it''s not convenient to use tracemem here. BTW, What
I
> monitor is not a string buffer, it may includes many zeroes.
>   
How about a compromise between multiple clauses and tracemem. If you
traced 128 bytes per probe clause, you could get by with around 16
clauses, right? Also, with regard to using printf, I was thinking you
might convert the binary value to displayable hex, when you put it in
the string. There''s no function to do that (I don''t think),
but you
could do it with a little base 16 math and a string constant with hex
digits.
>
> What I want is not lock the whole system , it''s just to make the
probe
> called serially like the following. So that I have enough time to
> process the data buffer sequentially when there are multiple processors.
>
> ::hid_interrupt_pip_callback:entry
> {
> 	mutex_enter(...);
>
> 	...
>
> 	mutex_exit(...);
> }
>   
Probe clauses run in kernel mode with interrupts disabled. They run in
the context of the probe that fired, so if the caller of
"hid_interrupt_pip_callback" were allowed to block on a mutex, the
results could be disastrous to the system. This is why probe clauses
have no flow control, and I think the reason they have fixed length
trace records: make it simple and fast.


Chip

I just tried to using copyout() to copy the buffer to an external
application, but it failed because there''s a big latency between kernel
and user space. The buffer has been invalid when the probe falls into
the user space. Multiple tracemem() is not what I prefer, for I must
analyze and re-organize the data and display them. tracemem() will give
much extra workload. I''m considering to record the buffer in dtrace and
then copyout to the user process, but it doesn''t work.

char pdata[100];

::hid_interrupt_pipe_callback:entry
{
        req = (usb_intr_req_t *)arg1;         mblk = req->intr_data;
        lens = req->intr_len;

        bcopy((uintptr_t)req->intr_data->b_rptr, pdata, size);
}

the error message is,

dtrace: error on enabled probe ID 2 (ID 38953:
fbt:hid:hid_interrupt_pipe_callback:entry): invalid address (0x4) in
action #6 at DIF offset 7

The guide says, src should lie outside of scratch memory, and dst should
lie inside of it. I don''t understand why it fails here?  

Oops.., does libdtrace help? Seems it provides private interfaces and
lack of manuals.


-- 
Best Regards,
GaoPeng Chen
Call: +86-10-62673005
Ext: x82005
Sun Microsystem Inc. China