[erlang-bugs] Type assertion failure when tracing with process_dump message

[Sverker Eriksson]

On 07/29/2015 08:55 PM, Mikael Pettersson wrote:
> James Fish writes:
>   > When using {message, {process_dump}} in a trace the VM can abort on OTP
>   > R16B03 to 18.0.2 (not R16B02 and earlier) on a linux 3.19.0-21-generic
>   > x86_64:
>   >
>   > TYPE ASSERTION FAILED, file beam/erl_term.c, line 115: tag_val_def:
>   > 0x7f9c183ee6d2
>   > Aborted (core dumped)
>   >
>   > #0  0x00007f9c1c56f267 in __GI_raise (sig=sig@REDACTED=6) at
>   > ../sysdeps/unix/sysv/linux/raise.c:55
>   > #1  0x00007f9c1c570eca in __GI_abort () at abort.c:89
>   > #2  0x000000000056dfd1 in et_abort (expr=0x9081e0 <msg> "tag_val_def:
>   > 0x7f9c183ee6d2", file=0x64fe45 "beam/erl_term.c", line=115) at
>   > beam/erl_term.c:48
>   > #3  tag_val_def (x=x@REDACTED=140308398401234) at beam/erl_term.c:115
>   > #4  0x00000000004cf12e in print_term (obj_base=<optimised out>,
>   > dcount=<synthetic pointer>, obj=140308398401234, arg=0x7f9c1d780078,
>   > fn=0x630a10 <write_ds>) at beam/erl_printf_term.c:352
>   > #5  erts_printf_term (fn=0x630a10 <write_ds>, arg=0x7f9c1d780078,
>   > term=<optimised out>, precision=99999, term_base=<optimised out>) at
>   > beam/erl_printf_term.c:657
>   > #6  0x000000000062ed17 in erts_printf_format (fn=fn@REDACTED=0x630a10
>   > <write_ds>, arg=arg@REDACTED=0x7f9c1d780078, fmt=fmt@REDACTED=0x64830b "%T\n",
>   > ap=ap@REDACTED=0x7f9c198fc640) at common/erl_printf_format.c:847
>   > #7  0x0000000000631750 in erts_vdsprintf (dsbufp=dsbufp@REDACTED=0x7f9c1d780078,
>   > format=format@REDACTED=0x64830b "%T\n", arglist=arglist@REDACTED=0x7f9c198fc640)
>   > at common/erl_printf.c:459
>   > #8  0x00000000004a9696 in erts_print (to=to@REDACTED=-4,
>   > arg=arg@REDACTED=0x7f9c1d780078,
>   > format=format@REDACTED=0x64830b "%T\n") at beam/utils.c:400
>   > #9  0x00000000004ea8cf in stack_element_dump (yreg=2, sp=0x7f9c183ef258,
>   > to_arg=0x7f9c1d780078, to=-4) at beam/erl_process.c:12546
>   > #10 erts_stack_dump (to=to@REDACTED=-4, to_arg=to_arg@REDACTED=0x7f9c1d780078,
>   > p=p@REDACTED=0x7f9c1bb003d8) at beam/erl_process.c:12466
>   > #11 0x000000000055b56d in print_process_info (to=to@REDACTED=-4,
>   > to_arg=to_arg@REDACTED=0x7f9c1d780078, p=p@REDACTED=0x7f9c1bb003d8) at
>   > beam/break.c:339
>   > #12 0x000000000052cc20 in db_prog_match (c_p=c_p@REDACTED=0x7f9c1bb003d8,
>   > bprog=0x7f9c1bdc0b78, term=term@REDACTED=18446744073709551611,
>   > base=base@REDACTED=0x0,
>   > termp=termp@REDACTED=0x7f9c198fca70, arity=arity@REDACTED=1,
>   >     in_flags=ERTS_PAM_TMP_RESULT, return_flags=0x7f9c198fca14) at
>   > beam/erl_db_util.c:2404
>   > #13 0x000000000052e5ec in erts_match_set_run (p=p@REDACTED=0x7f9c1bb003d8,
>   > mpsp=<optimised out>, args=args@REDACTED=0x7f9c198fca70,
>   > num_args=num_args@REDACTED=1, in_flags=in_flags@REDACTED=ERTS_PAM_TMP_RESULT,
>   >     return_flags=return_flags@REDACTED=0x7f9c198fca14) at
>   > beam/erl_db_util.c:1243
>   > #14 0x00000000004a0c55 in erts_call_trace (p=p@REDACTED=0x7f9c1bb003d8,
>   > mfa=mfa@REDACTED=0x7f9c1822f058, match_spec=<optimised out>,
>   > args=0x7f9c198fca70, args@REDACTED=0x7f9c1bfc4180, local=local@REDACTED=1,
>   >     tracer_pid=0x7f9c1bb003e8, tracer_pid@REDACTED=0x7f9c198fdcc8) at
>   > beam/erl_trace.c:1873
>   > #15 0x0000000000455654 in do_call_trace (c_p=0x7f9c1bb003d8,
>   > I=0x7f9c1822f070, reg=0x7f9c1bfc4180, local=local@REDACTED=1, ms=<optimised
>   > out>, tracer_pid=tracer_pid@REDACTED=75) at beam/beam_bp.c:900
>   > #16 0x0000000000459524 in erts_generic_breakpoint (c_p=0x7f9c1bb003d8,
>   > I=0x7f9c1822f070, reg=0x7f9c1bfc4180) at beam/beam_bp.c:626
>   > #17 0x0000000000443f23 in process_main () at beam/beam_emu.c:4921
>   > #18 0x00000000004d6415 in sched_thread_func (vesdp=0x7f9c1ae4bc40) at
>   > beam/erl_process.c:8021
>   > #19 0x000000000062d0e3 in thr_wrapper (vtwd=0x7fff8a43d010) at
>   > pthread/ethread.c:114
>   > #20 0x00007f9c1cb136aa in start_thread (arg=0x7f9c198fe700) at
>   > pthread_create.c:333
>   > #21 0x00007f9c1c640eed in clone () at
>   > ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
>   >
>   > A minimal example:
>   >
>   > c("test.erl"),
>   > dbg:tracer(),
>   > dbg:p(self(), [call]),
>   > dbg:tpl(test, identity, [{'_',[],[{message,{process_dump}}]}]),
>   > test:sum(<<0>>, 0).
>   >
>   > test.erl:
>   >
>   > -module(test).
>   >
>   > -export([sum/2]).
>   >
>   > sum(<<Int, Rest/binary>>, Acc) ->
>   >     sum(Rest, Acc + identity(Int));
>   > sum(<<>>, Acc) -> Acc.
>   >
>   > identity(Int) ->
>   >     Int.
>
> I can reproduce, with otp 18.0.2 on Linux x86_64 w/ gcc-4.9.3.
>
> Inspecting the term at the final et_abort() in tag_val_def() gave me nonsense data
> (it looked like a perfectly fine 2-tuple), but adding an et_abort() at the end of the
> TAG_PRIMARY_BOXED case showed me a boxed term with header 0x144, a BIN_MATCHSTATE_SUBTAG,
> which isn't allowed here (it's not a user-visible term type).
>
> Running with erl -smp disable didn't prevent the error, so it's hopefully
> not a concurrency problem.
>

This bug will be fixed in OTP 18.1 planned for 23 September.

The fix based on 17.5.6.1 can be found here:

https://github.com/sverker/otp/commit/a22b5ba19193e3f39129fadd20d375f6cc3f8529

/Sverker, Erlang/OTP Ericsson