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

[Mikael Pettersson]

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.