[DTrace-devel] [PATCH] Provide a more consistent implementation of the trace() action
Eugene Loh
eugene.loh at oracle.com
Wed May 20 22:10:57 PDT 2020
On 05/18/2020 10:44 AM, Kris Van Hees wrote:
> The trace(n) action in DTrace v1 does not provide a consistent way
> for displaying numeric data. Due to the fact that information about
> the value is lost (whether it is a signed value), the consumer was
> always interpreting the value as a signed value. However, due to
> what seems like a bug, values with an integer datatype of less than
> 64 bits were being interpreted as 32-bit values. Therefore;
>
> (quiet) (non-quiet)
> (int8_t)-1 prints as 255 " 255"
> (int16_t)-1 prints as 65535 " 65535"
> (int32_t)-1 prints as -1 " -1"
> (int64_t)-1 prints as -1 " -1"
>
> (uint8_t)0xff prints as 255 " 255"
> (uint16_t)0xffff
> prints as 65535 " 65535"
> (uint32_t)0xffffffff
> prints as -1 " -1"
> (uint32_t)0x7fffffff
> prints as 2147483647
> " 2147483647"
> (uint64_t)0xffffffffffffffff
> prints as -1 " -1"
> (uint64_t)0x7fffffffffffffff
> prints as 9223372036854775807
> " 9223372036854775807"
>
> The output statements fail to specify the correct number of decimal
> characters in the output for 32-bit and 64-bit values.
>
> This patch provides a consistent implementation by passing a flag
> into the record to indicate whether the value is signed. The output
> uses a custom formatting string based on the datatype width and sign
> of the value.
>
> With the new implementation:
> (quiet) (non-quiet)
> (int8_t)-1 prints as -1 " -1"
> (int16_t)-1 prints as -1 " -1"
> (int32_t)-1 prints as -1 " -1"
> (int64_t)-1 prints as -1 " -1"
>
> (uint8_t)0xff prints as 255 " 255"
> (uint16_t)0xffff
> prints as 65535 " 65535"
> (uint32_t)0xffffffff
> prints as 4294967295
> " 4294967295"
> (uint64_t)0xffffffffffffffff
> prints as 18446744073709551615
> " 18446744073709551615"
Regarding those tables:
*) In place of those "0xffff", just say -1. It saves on horizontal
space and it's truer to what is actually in the tests.
*) You have an extra space before 4294967295.
*) The "before" table includes
(uint32_t)0x7fffffff
(uint64_t)0x7fffffffffffffff
but these are besides the point: they are not the point of the bug and
there is no comparison in the "after" table.
*) There is inconsistent use of tabs for white space.
IMHO, the "before" table would look better so:
prints as
value --------------------------------------------
(quiet) (non-quiet)
(int8_t)-1 255 " 255"
(int16_t)-1 65535 " 65535"
(int32_t)-1 -1 " -1"
(int64_t)-1 -1 " -1"
(uint8_t)-1 255 " 255"
(uint16_t)-1 65535 " 65535"
(uint32_t)-1 -1 " -1"
(uint64_t)-1 -1 " -1"
and the "after" table so:
prints as
value --------------------------------------------
(quiet) (non-quiet)
(int8_t)-1 -1 " -1"
(int16_t)-1 -1 " -1"
(int32_t)-1 -1 " -1"
(int64_t)-1 -1 " -1"
(uint8_t)-1 255 " 255"
(uint16_t)-1 65535 " 65535"
(uint32_t)-1 4294967295 " 4294967295"
(uint64_t)-1 18446744073709551615 " 18446744073709551615"
IMHO, this would make the tables more compact and readable... fewer of
continuation lines and overlapping columns.
> This patch also adds unit tests for the various numeric value sizes,
> and a variety of error conditions.
>
> Signed-off-by: Kris Van Hees <kris.van.hees at oracle.com>
> ---
> libdtrace/dt_cg.c | 123 ++++++++++++------
> libdtrace/dt_consume.c | 64 ++++++++-
> .../trace/err.D_PROTO_LEN.missing_arg.d | 20 +++
> .../trace/err.D_PROTO_LEN.missing_arg.r | 2 +
> .../trace/err.D_PROTO_LEN.too_many_args.d | 20 +++
> .../trace/err.D_PROTO_LEN.too_many_args.r | 2 +
> test/unittest/actions/trace/err.D_TRACE_DYN.d | 22 ++++
> test/unittest/actions/trace/err.D_TRACE_DYN.r | 2 +
> .../unittest/actions/trace/err.D_TRACE_VOID.d | 20 +++
> .../unittest/actions/trace/err.D_TRACE_VOID.r | 2 +
> test/unittest/actions/trace/tst.expr.d | 21 +++
> test/unittest/actions/trace/tst.expr.r | 1 +
> .../actions/trace/tst.int16_t-quiet.d | 21 +++
> .../actions/trace/tst.int16_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.int16_t.d | 19 +++
> test/unittest/actions/trace/tst.int16_t.r | 5 +
> .../actions/trace/tst.int32_t-quiet.d | 21 +++
> .../actions/trace/tst.int32_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.int32_t.d | 19 +++
> test/unittest/actions/trace/tst.int32_t.r | 5 +
> .../actions/trace/tst.int64_t-quiet.d | 21 +++
> .../actions/trace/tst.int64_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.int64_t.d | 19 +++
> test/unittest/actions/trace/tst.int64_t.r | 5 +
> .../unittest/actions/trace/tst.int8_t-quiet.d | 21 +++
> .../unittest/actions/trace/tst.int8_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.int8_t.d | 19 +++
> test/unittest/actions/trace/tst.int8_t.r | 5 +
> test/unittest/actions/trace/tst.str.d | 21 +++
> test/unittest/actions/trace/tst.str.r | 1 +
> .../actions/trace/tst.uint16_t-quiet.d | 21 +++
> .../actions/trace/tst.uint16_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.uint16_t.d | 19 +++
> test/unittest/actions/trace/tst.uint16_t.r | 5 +
> .../actions/trace/tst.uint32_t-quiet.d | 21 +++
> .../actions/trace/tst.uint32_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.uint32_t.d | 19 +++
> test/unittest/actions/trace/tst.uint32_t.r | 5 +
> .../actions/trace/tst.uint64_t-quiet.d | 21 +++
> .../actions/trace/tst.uint64_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.uint64_t.d | 19 +++
> test/unittest/actions/trace/tst.uint64_t.r | 5 +
> .../actions/trace/tst.uint8_t-quiet.d | 21 +++
> .../actions/trace/tst.uint8_t-quiet.r | 1 +
> test/unittest/actions/trace/tst.uint8_t.d | 19 +++
> test/unittest/actions/trace/tst.uint8_t.r | 5 +
> test/unittest/codegen/tst.post_inc_gvar_val.r | 2 +-
> test/unittest/codegen/tst.post_inc_lvar_val.r | 2 +-
> test/unittest/codegen/tst.post_inc_tvar_val.r | 2 +-
> test/unittest/codegen/tst.pre_inc_gvar_val.r | 2 +-
> test/unittest/codegen/tst.pre_inc_lvar_val.r | 2 +-
> test/unittest/codegen/tst.pre_inc_tvar_val.r | 2 +-
> .../codegen/tst.reg_spilling.bug31187562-2.r | 2 +-
> .../codegen/tst.reg_spilling.bug31187562.r | 2 +-
> 54 files changed, 652 insertions(+), 53 deletions(-)
> create mode 100644 test/unittest/actions/trace/err.D_PROTO_LEN.missing_arg.d
> create mode 100644 test/unittest/actions/trace/err.D_PROTO_LEN.missing_arg.r
> create mode 100644 test/unittest/actions/trace/err.D_PROTO_LEN.too_many_args.d
> create mode 100644 test/unittest/actions/trace/err.D_PROTO_LEN.too_many_args.r
> create mode 100644 test/unittest/actions/trace/err.D_TRACE_DYN.d
> create mode 100644 test/unittest/actions/trace/err.D_TRACE_DYN.r
> create mode 100644 test/unittest/actions/trace/err.D_TRACE_VOID.d
> create mode 100644 test/unittest/actions/trace/err.D_TRACE_VOID.r
> create mode 100644 test/unittest/actions/trace/tst.expr.d
> create mode 100644 test/unittest/actions/trace/tst.expr.r
> create mode 100644 test/unittest/actions/trace/tst.int16_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.int16_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.int16_t.d
> create mode 100644 test/unittest/actions/trace/tst.int16_t.r
> create mode 100644 test/unittest/actions/trace/tst.int32_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.int32_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.int32_t.d
> create mode 100644 test/unittest/actions/trace/tst.int32_t.r
> create mode 100644 test/unittest/actions/trace/tst.int64_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.int64_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.int64_t.d
> create mode 100644 test/unittest/actions/trace/tst.int64_t.r
> create mode 100644 test/unittest/actions/trace/tst.int8_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.int8_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.int8_t.d
> create mode 100644 test/unittest/actions/trace/tst.int8_t.r
> create mode 100644 test/unittest/actions/trace/tst.str.d
> create mode 100644 test/unittest/actions/trace/tst.str.r
> create mode 100644 test/unittest/actions/trace/tst.uint16_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.uint16_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.uint16_t.d
> create mode 100644 test/unittest/actions/trace/tst.uint16_t.r
> create mode 100644 test/unittest/actions/trace/tst.uint32_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.uint32_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.uint32_t.d
> create mode 100644 test/unittest/actions/trace/tst.uint32_t.r
> create mode 100644 test/unittest/actions/trace/tst.uint64_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.uint64_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.uint64_t.d
> create mode 100644 test/unittest/actions/trace/tst.uint64_t.r
> create mode 100644 test/unittest/actions/trace/tst.uint8_t-quiet.d
> create mode 100644 test/unittest/actions/trace/tst.uint8_t-quiet.r
> create mode 100644 test/unittest/actions/trace/tst.uint8_t.d
> create mode 100644 test/unittest/actions/trace/tst.uint8_t.r
>
> diff --git a/libdtrace/dt_cg.c b/libdtrace/dt_cg.c
> index 1fe79e97..3e8adf86 100644
> --- a/libdtrace/dt_cg.c
> +++ b/libdtrace/dt_cg.c
> @@ -242,6 +242,73 @@ dt_cg_spill_load(int reg)
> dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> }
>
> +static int
> +dt_cg_store_val(dt_pcb_t *pcb, dt_node_t *dnp, dtrace_actkind_t kind, int act)
> +{
Out of curiosity, you outline this code into this new function
dt_cg_store_val(), which is called from only one site. Do you
anticipate calling it from more sites in the future?
Also, I don't understand the whole dtrace_actkind_t mechanism. We
define a "struct dt_cg_actdesc _dt_cg_actions[]", but the "kind" field
is usually not used. And if you wanted to have an action kind, you
could just specify it inside the function -- ah, and we already do so
for dt_cg_act_[commit|discard|exit|...], using
DTRACEACT_[COMMIT|DISCARD|EXIT|...]. And now you do the same with
dt_cg_act_trace(), specifying DTRACEACT_DIFEXPR in the function's code
and never using dt_cg_act_trace()'s (undefined) "kind" argument. Maybe
that's all a little confusing; my point is why don't we get rid of
"struct dg_cg_actdesc" since the "kind" member isn't needed. [To answer
my own question, maybe it's so that dt_cg_act_symmod can be used for MOD
SYM UMOD USYM and UADDR, but that seems like a weak answer.]
The last argument to dt_cg_store_val() is called "type" in the caller,
"act" in the function, and "arg" in the callee. Ugh. How about
changing "type" to "arg" in dt_cg_act_trace() and changing "act" to
"arg" in dt_cg_store_val()? Now, you might object that "arg" is already
the name you use for dnp->dn_args. True, but we use the name "anp" for
that in dt_cg_act_clear() and then again in dt_cg_act_denormalize(). (I
have no idea what anp stands for.) Anyhow, it'd be nice to have more
consistent names, whether for an argument that's passed from function to
function or for a common expression like dnp->dn_args that appears in
multiple functions.
> + dtrace_diftype_t vtype;
> + struct bpf_insn instr;
> + dt_irlist_t *dlp = &pcb->pcb_ir;
> + uint_t off;
> +
> + dt_cg_node(dnp, &pcb->pcb_ir, pcb->pcb_regs);
> + dt_node_diftype(pcb->pcb_hdl, dnp, &vtype);
> +
> + if (dt_node_is_scalar(dnp)) {
> + int sz = 8;
> +
> + off = dt_rec_add(pcb->pcb_hdl, dt_cg_fill_gap, kind,
> + vtype.dtdt_size, vtype.dtdt_size, NULL,
> + act);
> +
> + switch (vtype.dtdt_size) {
> + case sizeof(uint64_t):
> + sz = BPF_DW;
> + break;
> + case sizeof(uint32_t):
> + sz = BPF_W;
> + break;
> + case sizeof(uint16_t):
> + sz = BPF_H;
> + break;
> + case sizeof(uint8_t):
> + sz = BPF_B;
> + break;
> + }
> +
> + instr = BPF_STORE(sz, BPF_REG_9, off, dnp->dn_reg);
> + dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> + dt_regset_free(pcb->pcb_regs, dnp->dn_reg);
> +
> + return 0;
> +#if 0
> + } else if (dt_node_is_string(dnp->dn_args)) {
> + size_t sz = dt_node_type_size(dnp->dn_args);
> +
> + /*
> + * Strings are stored as a 64-bit size followed by a character
> + * array. Given that all entries in the output buffer are
> + * aligned at 64-bit boundaries, this guarantees that the
> + * character array is also aligned at a 64-bit boundary.
> + * We will pad the string to a multiple of 8 bytes as well.
> + *
> + * We store the size as two 32-bit values, lower 4 bytes first,
> + * then the higher 4 bytes.
> + */
> + sz = P2ROUNDUP(sz, sizeof(uint64_t));
> + instr = BPF_STORE_IMM(BPF_W, BPF_REG_9, off,
> + sz & ((1UL << 32)-1));
> + dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> + instr = BPF_STORE_IMM(BPF_W, BPF_REG_9, off + 4, sz >> 32);
> + dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> + dt_regset_free(pcb->pcb_regs, dnp->dn_args->dn_reg);
> +
> + return sz + sizeof(uint64_t);
> +#endif
> + }
> +
> + return -1;
> +}
> +
> static void
> dt_cg_act_breakpoint(dt_pcb_t *pcb, dt_node_t *dnp, dtrace_actkind_t kind)
> {
> @@ -506,61 +573,31 @@ dt_cg_act_system(dt_pcb_t *pcb, dt_node_t *dnp, dtrace_actkind_t kind)
> static void
> dt_cg_act_trace(dt_pcb_t *pcb, dt_node_t *dnp, dtrace_actkind_t kind)
> {
> - struct bpf_insn instr;
> - dt_irlist_t *dlp = &pcb->pcb_ir;
> char n[DT_TYPE_NAMELEN];
> - uint_t off;
> + dt_node_t *arg = dnp->dn_args;
> + int type = 0;
>
> - if (dt_node_is_void(dnp->dn_args)) {
> - dnerror(dnp->dn_args, D_TRACE_VOID,
> + if (dt_node_is_void(arg)) {
> + dnerror(arg, D_TRACE_VOID,
> "trace( ) may not be applied to a void expression\n");
> }
>
> - if (dt_node_is_dynamic(dnp->dn_args)) {
> - dnerror(dnp->dn_args, D_TRACE_DYN,
> + if (dt_node_is_dynamic(arg)) {
> + dnerror(arg, D_TRACE_DYN,
> "trace( ) may not be applied to a dynamic "
> "expression\n");
> }
Since you're touching those two "if" statements anyhow, if we're
conforming to that "no braces for single-statement code blocks" rule,
might as well remove the braces around the dnerror() statements.
> - dt_cg_node(dnp->dn_args, &pcb->pcb_ir, pcb->pcb_regs);
> -
> - if (dt_node_is_scalar(dnp->dn_args)) {
> - off = dt_rec_add(pcb->pcb_hdl, dt_cg_fill_gap,
> - DTRACEACT_DIFEXPR, sizeof(uint64_t),
> - sizeof(uint64_t), NULL, DT_ACT_TRACE);
> + if (arg->dn_flags & DT_NF_REF)
> + type = DT_NF_REF;
> + else if (arg->dn_flags & DT_NF_SIGNED)
> + type = DT_NF_SIGNED;
>
> - instr = BPF_STORE(BPF_DW, BPF_REG_9, off, dnp->dn_args->dn_reg);
> - dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> - dt_regset_free(pcb->pcb_regs, dnp->dn_args->dn_reg);
> -#if 0
> - } else if (dt_node_is_string(dnp->dn_args)) {
> - size_t sz = dt_node_type_size(dnp->dn_args);
> -
> - /*
> - * Strings are stored as a 64-bit size followed by a character
> - * array. Given that all entries in the output buffer are
> - * aligned at 64-bit boundaries, this guarantees that the
> - * character array is also aligned at a 64-bit boundary.
> - * We will pad the string to a multiple of 8 bytes as well.
> - *
> - * We store the size as two 32-bit values, lower 4 bytes first,
> - * then the higher 4 bytes.
> - */
> - sz = P2ROUNDUP(sz, sizeof(uint64_t));
> - instr = BPF_STORE_IMM(BPF_W, BPF_REG_9, off,
> - sz & ((1UL << 32)-1));
> - dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> - instr = BPF_STORE_IMM(BPF_W, BPF_REG_9, off + 4, sz >> 32);
> - dt_irlist_append(dlp, dt_cg_node_alloc(DT_LBL_NONE, instr));
> - dt_regset_free(pcb->pcb_regs, dnp->dn_args->dn_reg);
> -
> - return sz + sizeof(uint64_t);
> -#endif
> - } else
> - dnerror(dnp->dn_args, D_PROTO_ARG,
> + if (dt_cg_store_val(pcb, arg, DTRACEACT_DIFEXPR, type) == -1)
> + dnerror(arg, D_PROTO_ARG,
> "trace( ) argument #1 is incompatible with prototype:\n"
> "\tprototype: scalar or string\n\t argument: %s\n",
> - dt_node_type_name(dnp->dn_args, n, sizeof (n)));
> + dt_node_type_name(arg, n, sizeof(n)));
> }
>
> static void
> diff --git a/libdtrace/dt_consume.c b/libdtrace/dt_consume.c
> index cabef503..6c15b4a5 100644
> --- a/libdtrace/dt_consume.c
> +++ b/libdtrace/dt_consume.c
> @@ -2254,6 +2254,66 @@ nextepid:
> return (dt_handle_cpudrop(dtp, cpu, DTRACEDROP_PRINCIPAL, drops));
> }
> #else
> +static int
> +dt_print_trace(dtrace_hdl_t *dtp, FILE *fp, dtrace_recdesc_t *rec,
> + caddr_t data, int quiet)
> +{
> + /*
> + * String or any other non-numeric data items are printed as a byte
> + * stream.
> + */
> + if (rec->dtrd_arg == DT_NF_REF)
> + return dt_print_bytes(dtp, fp, data, rec->dtrd_size, 33,
> + quiet);
> +
> + /*
> + * Differentiate between signed and unsigned numeric values.
> + *
> + * Note:
> + * This is an enhancement of the functionality present in DTrace v1,
> + * where values were anything smaller than a 64-bit value was used as a
> + * 32-bit value. As such, (int8_t)-1 and (int16_t)-1 would be printed
> + * as 255 and 65535, but (int32_t)-1 and (int64_t) would be printed as
(int64_t)
->
(int64_t)-1
> + * -1.
> + */
> + if (rec->dtrd_arg == DT_NF_SIGNED) {
> + switch (rec->dtrd_size) {
> + case sizeof(int64_t):
> + return dt_printf(dtp, fp, quiet ? "%ld" : " %19ld",
> + *(int64_t *)data);
> + case sizeof(int32_t):
> + return dt_printf(dtp, fp, quiet ? "%d" : " %10d",
> + *(int32_t *)data);
> + case sizeof(int16_t):
> + return dt_printf(dtp, fp, quiet ? "%hd" : " %5hd",
> + *(int16_t *)data);
> + case sizeof(int8_t):
> + return dt_printf(dtp, fp, quiet ? "%hhd" : " %3hhd",
> + *(int8_t *)data);
> + }
> + } else {
> + switch (rec->dtrd_size) {
> + case sizeof(uint64_t):
> + return dt_printf(dtp, fp, quiet ? "%lu" : " %20lu",
> + *(uint64_t *)data);
> + case sizeof(uint32_t):
> + return dt_printf(dtp, fp, quiet ? "%u" : " %10u",
> + *(uint32_t *)data);
> + case sizeof(uint16_t):
> + return dt_printf(dtp, fp, quiet ? "%hu" : " %5hu",
> + *(uint16_t *)data);
> + case sizeof(uint8_t):
> + return dt_printf(dtp, fp, quiet ? "%hhu" : " %3hhu",
> + *(uint8_t *)data);
> + }
> + }
> +
> + /*
> + * We should never get here, but if we do... print bytes.
> + */
> + return dt_print_bytes(dtp, fp, data, rec->dtrd_size, 33, quiet);
> +}
> +
> static dtrace_workstatus_t
> dt_consume_one(dtrace_hdl_t *dtp, FILE *fp, int cpu, char *buf,
> dtrace_probedata_t *pdat, dtrace_consume_probe_f *efunc,
> @@ -2354,8 +2414,8 @@ dt_consume_one(dtrace_hdl_t *dtp, FILE *fp, int cpu, char *buf,
> if (rval != DTRACE_CONSUME_THIS)
> return dt_set_errno(dtp, EDT_BADRVAL);
>
> - n = dt_printf(dtp, fp, quiet ? "%lld" : " %16lld",
> - *(int64_t *)pdat->dtpda_data);
> + n = dt_print_trace(dtp, fp, rec, pdat->dtpda_data,
> + quiet);
>
> if (n < 0)
> return -1;
I cut the tests out of this email, but regarding the tests:
1) Typo "THe":
$ git grep THe
test/unittest/actions/trace/err.D_PROTO_LEN.missing_arg.d: * ASSERTION:
THe trace() action takes exactly one argument.
test/unittest/actions/trace/err.D_PROTO_LEN.too_many_args.d: *
ASSERTION: THe trace() action takes exactly one argument.
2) There is the usual, old, fruitless debate we have about the
proliferation of tests. You like breaking these little tests out into
separate tests. I think this makes the code harder to write, review,
and maintain. Oh well.
More information about the DTrace-devel
mailing list