[DTrace-devel] [PATCH v2 02/17] cg: add dt_cg_trace

[Eugene Loh]

Maybe the main point is that this patch isn't actually needed by the 
patch series.  It's to support a certain kind of debugging and can be 
added separately or modified or discussed independently of the alloca 
patch series.

On 3/24/22 3:57 PM, Nick Alcock wrote:

> On 23 Mar 2022, Eugene Loh via DTrace-devel spake thusly:
>
>> Reviewed-by: Eugene Loh <eugene.loh at oracle.com>
>> assuming the following prove insignificant...
>>
>> I did try to build this.  I got:
>>      % make clean
>>      [...]
>>      % make
>>      [...]
>>      CC: test/utils/badioctl.c
>>      LINK: badioctl
>>      CC: test/utils/showUSDT.c
>>      LINK: showUSDT
>>      CC: test/utils/print-stack-layout.c
>>      LINK: print-stack-layout
>>      % make clean
>>      [...]
>>      % make debugging=yes
>>      [...]
>>      GENDOF: test/triggers/usdt-tst-forker-prov.d
>>      LINK: usdt-tst-forker
>>      GENHDR: test/triggers/usdt-tst-special-prov.d
>>      CC: test/triggers/usdt-tst-special.c
>>      GENDOF: test/triggers/usdt-tst-special-prov.d
>>      dtrace: failed to link script test/triggers/usdt-tst-special-prov.d:
>>          an error was encountered while processing dtrace-user/build/test-triggers--usdt-tst-special.o
>>      make: *** [Makerules:31: dtrace-user/build/test-triggers--usdt-tst-special-prov.o] Error 1
>> I have not tried to troubleshoot this.
> It's unrelated, something wrong in dt_link I think.
>
>> Incidentally, I tried running this (ignoring the test make error), but then operations on trace_pipe hung when I went to look at the
>> output.  Any idea what I'm doing wrong?
> You have to cat the trace_pipe before you start dtrace -- it doesn't
> buffer anything, so start it in another terminal.

Still no luck.  And I don't see anything show up in /sys/.../trace either.

>> Also, the "(counter, value)" interface strikes me as odd.  Since bpf_trace_printfk() allows three arguments (if you count  the right
>> way), how about dt_cg_trace(dlp, drp, isreg_flags, val0, val1, val2) where
>>      if (isreg_flags & 1) val0 is a reg; else it's an IMM
>>      if (isreg_flags & 2) val1 is a reg; else it's an IMM
>>      if (isreg_flags & 4) val2 is a reg; else it's an IMM
>> For someone who is interested in fewer values, it's easy enough to feed a 0 value and not set the corresponding isreg bit.
> Sure, but I don't see any way to make this *readable*. I mean
> do you really think this:
>
> dt_cg_trace(dlp, drp, (1 >> 1) & (1 >> 2), 1, b, c);
>
> (to print the values of regs b and c with the immediate value 1 used as
> a call-site counter) or even worse this:
>
> dt_cg_trace(dlp, drp, 6, 1, b, c);
>
> (which I got wrong twice, yes, I'm that bad at bit-shifting in my head)
> is actually better than
>
> dt_cg_trace(dlp, drp, 1, 1, b);
> dt_cg_trace(dlp, drp, 1, 2, c);
>
> ... hm. Of course that's still pretty nasty!

I don't know.  It's readable to me.  I wouldn't want to have anyone just 
guess what the interface is, but I think I'm coming from this from a 
different point of view.  That is, it might be nice to use 
bpf_trace_printk() from dt_cg.c in some niche debugging cases. That's a 
tricky corner to be in, but if you're there it's nice to have a "simple" 
(relatively speaking) interface.  That's where I see dt_cg_trace() come 
in.  We're not going to let people mess with the format string but we 
would let them provide three args.

Most of all, this patch does not need to be part of the patch set. It's 
novel debugging capability that the patch series does not use.

> How about fusing ISREG and COUNTER?
I do not understand the point.  Plus, again, iiuc, the patch simply 
simply is not needed for this patch series.
> The real problem with this interface
> is that it's got two numeric args next to each other and they frankly
> are easy to mix up. But if you have an ISREG which can be any value but
> in which the lower bit is used as the ISREG check, you can say:
>
> dt_cg_trace(dlp, drp, 0, b);
> dt_cg_trace(dlp, drp, 1, c);
> dt_cg_trace(dlp, drp, 3, d);
>
> In the above, b is an immediate value: c and d are registers whose
> values should be printed. Odd values of ISREG mean the arg is a
> register. Even values mean it's an immediate. ISREG is also used as a
> counter (which is fine, the counter value is literally arbitrary, it's
> just used to distinguish call sites from each other).
>
> Bingo, no bit twiddling, just "is it odd or even" which even I can do in
> my head :P you don't get to emit three values at once but frankly for
> debugging this is pretty pointless, and it does add a lot of complexity
> trying to specify whether each of those values is a reg or not
> independently. If you can think of a nice syntax to specify it (not
> manual bit twiddling!) I'm happy, but right now I can't.
It is nice to have some things printed atomically (same line).  In the 
case you imagine, the values are counter + something else.  In another 
case, being able to print three things would be nice.
>> On 3/14/22 5:30 PM, Nick Alcock wrote:
>>> +override CFLAGS += -O0 -g -DDEBUGGING
>>> +override BPFCFLAGS += -DDEBUGGING
>>>    endif
>>>      ifneq ($(coverage),no)
>> The "DEBUGGING" name strikes me as awfully generic, especially when
>> there are already DEBUG and YYDEBUG in the source code and there are
>> multiple debugging features I could imagine we'll ultimately want to
>> turn on individually.
> It is intentionally generic. It doesn't mean 'dt_cg_trace is active', it
> means 'we ran make with debugging=yes'. It just so happens that we only
> turn on tracing if you do that. There could be other things hanging off
> it too.
Differences in opinions I guess.  This struck me as a particular kind of 
debugging that I would want to decide on independently of whatever 
future debugging hooks would also be added, even though we don't know 
what those future hooks would be.
>>> diff --git a/libdtrace/dt_cg.c b/libdtrace/dt_cg.c
>>> +	emit(dlp,  BPF_MOV_IMM(BPF_REG_1, counter));
>>> +	if (isreg)
>>> +		emit(dlp,  BPF_MOV_REG(BPF_REG_2, val));
>>> +	else
>>> +		emit(dlp,  BPF_MOV_IMM(BPF_REG_2, val));
>> One weird case is where val is %r1.  (Not so weird, actually, if one
>> is debugging function args.)  In that case, we would first overwrite
>> %r1 with "counter" and then put that copy in %r2.  I think this
>> problem is fixed if you first write %r2 and then write %r1.
> Adjusted.
>
> There is a bigger problem with this stuff later in the series. The
> bounds checkers have args like
>
> static void
> dt_cg_check_bounds(dt_irlist_t *dlp, dt_regset_t *drp, int regptr, int basereg,
> 		   int reg, int size, int lenreg, int sizemax, int lenmax)
>
> where REG and LENREG are registers, and SIZE may be (iff SIZEMAX is <
> 0).  The common case of calling this (from dt_cg_check_scratch_bounds)
> allocates two regs before calling this function, and inside this
> function we allocate more on some code paths.  But... nothing stops
> these allocations spilling REG or LENREG! Spilling LENREG is survivable,
> with extra code (which I'm not sure how to write), but if we spill REG
> we a) don't detect it and b) are in serious trouble, because the whole
> point of this function is to assign bounds to REG!
>
> I'm tempted to add some sort of guarding mechanism to the dt_regset so
> you can say "We are citing this register by number, do not spill it".
> Something like dt_regset_protect(dlp, reg); and then
> dt_regset_unprotect(dlp, reg) later on, and this flips a bit in a
> bitfield and bits which are on are not spilled.
>
> Does this seem sensible to anyone else?
Kris has been alluding to some spill/fill rework.  I don't know what he 
has in mind, but these sorts of problems must surely be among them.  For 
now, it appears we do things inconsistently and in some brittle way.  We 
fix problems only where it is easy to do so.