ferd / recon

Collection of functions and scripts to debug Erlang in production.

recon

Recon wants to be a set of tools usable in production to diagnose Erlang problems or inspect production environment safely.

To build the library:

rebar3 compile

Documentation for the library can be obtained at http://ferd.github.io/recon/

It is recommended that you use tags if you do not want bleeding edge and development content for this library.

Current Status

Versions supported: OTP-18 and up. Support of OTP-17 down to R15B02 is best effort. Builds with Rebar3 require OTP-18.3 and up because that's what the build tools support. Testing may eventually clamp up to OTP-supported releases (current and the two prior).

recon's Issues

Crash using `binary_memory` on a dead process

erlang:process_info/2 can return undefined — the docs don't explain why, but it's in the typespec and definitely happens when the queried process is dead. If using recon:info/2 with the binary_memory attribute, Recon doesn't handle this return value and crashes in an internal call to proc_fake (see here).

Additionally, the typespec for recon:info/2 doesn't include undefined as a possible return value, even though it can return this (e.g. if used on a dead process).

Example in Elixir, because I'm not very good at Erlang syntax, but hopefully it makes sense:

pid = spawn(fn -> true end) # spawn a process that immediately dies
Process.sleep(100) # give it a moment to finish
:recon.info(pid, [:binary_memory])

** (FunctionClauseError) no function clause matching in :recon.proc_fake/2

    The following arguments were given to :recon.proc_fake/2:

        # 1
        [:binary_memory]

        # 2
        :undefined

    (recon 2.5.2) src/recon.erl:247: :recon.proc_fake/2

difficulties installing recon

I added recon to the DEPS (dependencies).
I added it to app.src,

but when I try to use it on target server - it gives undefined function

New relase with records tracing

I noticed that since version 2.3.6 an interesting feature related to records tracing was merged into master. I'd like to know if or when new release is planned.

How to trace recursive calls ?

How this can be done with recon?
With dbg I can do something line:

:dbg.tracer(:process, {fn msg, n -> IO.inspect(msg); n+1 end, 0})
:dbg.tpl(Recursion, :sum, 2, [])
:dbg.p(:all, :c)
Recursion.sum([1, 3, 5, 6, 7, 8], 0)

This will allow me to debug all recursive calls:

23:48:16.912916 <0.146.0> 'Elixir.Recursion':sum([1,3,5,6,7,8], 0)

23:48:16.913188 <0.146.0> 'Elixir.Recursion':sum([3,5,6,7,8], 1)

23:48:16.913435 <0.146.0> 'Elixir.Recursion':sum([5,6,7,8], 4)

23:48:16.913563 <0.146.0> 'Elixir.Recursion':sum([6,7,8], 9)

23:48:16.913718 <0.146.0> 'Elixir.Recursion':sum([7,8], 15)

23:48:16.913874 <0.146.0> 'Elixir.Recursion':sum("\b", 22)

23:48:16.913972 <0.146.0> 'Elixir.Recursion':sum([], 30)

ipv6_v6only option is not available on R15B and results in {error,einval}

I happened to be investigating something and discovered this. Since you want to recon to work for R15B02 (at least according to the README), I figured you'd want to know. Most likely you can just move the ipv6_v6only to a different optional part to fix it. If I have a chance I'll submit a pull request with the change.

Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:2:2] [async-threads:0] [hipe] [kernel-poll:false]

Eshell V5.9.3.1  (abort with ^G)
1>  {ok, P} = gen_udp:open (12111, [ { reuseaddr, true }, {ip, {0,0,0,0}}]).
{ok,#Port<0.824>}
2>  inet:getopts(P,[active, broadcast,buffer,delay_send, dontroute,exit_on_close,header,high_watermark,keepalive,linger, low_watermark, mode, nodelay,packet, packet_size, priority,read_packets, recbuf, reuseaddr,send_timeout, sndbuf]).
{ok,[{active,true},
     {broadcast,false},
     {buffer,8192},
     {dontroute,false},
     {exit_on_close,true},
     {header,0},
     {keepalive,false},
     {linger,{false,0}},
     {mode,list},
     {packet,0},
     {packet_size,0},
     {priority,0},
     {read_packets,5},
     {recbuf,16384},
     {reuseaddr,true},
     {sndbuf,212992}]}
3> inet:getopts(P,[active, broadcast,buffer,delay_send, dontroute,exit_on_close,header,high_watermark,keepalive,linger, low_watermark, mode, nodelay,packet, packet_size, priority,read_packets, recbuf, reuseaddr,send_timeout, sndbuf,ipv6_v6only]).
{error,einval}
4>

`recon:node_stats` - Issue in number of reductions

The function node_stats(N, Interval, FoldFun, Init) has an issue with the returned number of reductions. This is because erlang:statistics(reductions) returns a tuple with {Total, Count_since_last_call} but those calls are global.

recon relies on calling this function twice and using the count, but if any other process in the same VM calls erlang:statistics(reductions), then the returned number is much lower than the real number.

You can see it for instance calling recon:node_stats_list(1, 1000) in a task and, just before one second has passed, call erlang:statistics(reductions) manually. Alternatively, call recon:node_stats_list(1, 1000) twice, concurrently: one of the two stats will have a very very low number of reductions.

Probably reductions should instead be computed as delta between the Total (first element).

Hex.pm package not usable

The Hex.pm package for Recon is not usable as a dependency (at least not in Elixir). Using the suggested dependency {:recon, "~> 2.3"} yields the following error when building:

Could not compile :recon, no "mix.exs", "rebar.config" or "Makefile" (pass :compile as an option to customize compilation, set it to "false" to do nothing)

Dialyzer warning for overlapping domains

dialyzer'ing master with OTP 18+ I get:

src/recon.erl
 200: Overloaded contract for recon:info/2 has overlapping domains; such contracts are currently unsupported and are simply ignored
 610: Overloaded contract for recon:port_info/2 has overlapping domains; such contracts are currently unsupported and are simply ignored

@ferd, would you be interested in a fix for this? Or do you consider it OK to leave as-is?

Note: I found no other dialyzer -related issues for OTP 18.3 through 21.2

problem with R15B, badarg when register recon_trace_tracer

$ erl -pa ebin
Erlang R15B (erts-5.9) [source] [smp:4:4] [async-threads:0] [kernel-poll:false]

Eshell V5.9 (abort with ^G)
1> recon_trace:calls({queue, '', ''}, 100).
0
2> recon_trace:calls({queue, '', ''}, 100).
** exception error: bad argument
in function register/2
called as register(recon_trace_tracer,<0.37.0>)
in call from recon_trace:setup/2 (src/recon_trace.erl, line 366)
in call from recon_trace:calls/3 (src/recon_trace.erl, line 300)
3>

I tried to add unregister before register and problem is solved,
but I wonder why didn't the clear() in function setup/2 take effect.

I tried r17.3 and no problem.

Any Idea will be appreciated.

recon:proc_count does not take self() into account

I faced with strange behaviour on one of the servers, when one of the metrics, which reported max message queue length started to report rather big increasing value. After some digging I found that somebody subscribed to the producer from the shell (console was attached to the process) and recon did not show it after calling recon:proc_count(message_queue_len,5) which confused a lot. While I don't think that attach is a good method to investigate on what is going on(in case remsh is used we can find out the violator with recon:proc_count/2), maybe it's better to include self() it in the search?

2.3.0 tag/release

In the README.md file I can see version 2.3.0 but there is no such tag. When can we expect it?

2.3.2 tag not found in the git repo.

Test snapshots in recon_alloc_SUITE failed

On R15B03:

{failed,
    {function_clause,
        [{recon_alloc,'-snapshot_load/1-lc$^1/1-2-',
             [false,
              [{temp_alloc,
              ...
              sbmbc_alloc],
             [{file,"src/recon_alloc.erl"},{line,471}]},
         {recon_alloc,snapshot_load,1,
             [{file,"src/recon_alloc.erl"},{line,471}]},
         {recon_alloc_SUITE,snapshots,1,
             [{file,"recon_alloc_SUITE.erl"},{line,136}]},
         {test_server,ts_tc,3,[{file,"test_server.erl"},{line,1874}]},
         {test_server,run_test_case_eval1,6,
             [{file,"test_server.erl"},{line,1404}]},
         {test_server,run_test_case_eval,9,
             [{file,"test_server.erl"},{line,1342}]}]}}

Sending you the complete stacktrace via mail.

Map filtering breaks some output

I don't have some precise example here because they happened while recording my advent of code videos, but it looks like some maps I filter make tuple printing turn into {X, Y,}, and there's some trailing condition in the map printer that probably needs fixing.

recon_alloc:memory(usage) > 1 ?

In 38 of 4258 cases, the result of this call is greater than 1. What can be the cause? The maximum value is 32.13506572.

app_deps.erl enhancements

@ferd would it be possible to add ebin directories under _checkouts to script/app_deps.erl?

main(_) ->
    AppFiles = filelib:wildcard("deps/*/ebin/*.app")
               ++
               filelib:wildcard("apps/*/ebin/*.app")
               ++
               filelib:wildcard("ebin/*.app")
               ++
               filelib:wildcard("_build/default/lib/*/ebin/*.app")
               ++
               filelib:wildcard("_checkouts/*/ebin/*.app"), %% _checkouts
    to_graphviz(read_deps(AppFiles)).

Does script/app_deps.erl works with rebar3? especially when compiled under different profile?

recon_alloc memory function returns memory used more than physical memory of the VM

recon_alloc:set_unit(gigabyte).
recon_alloc:memory(used, max).
397.1961054801941
recon_alloc:memory(allocated, max).
411.4017143249512

free -h
               total        used        free      shared  buff/cache   available
Mem:            98Gi        71Gi        14Gi       419Mi        11Gi        24Gi
Swap:             0B          0B          0B

Request to release 2.5.5

👋

In order to benefit from fab61ce, would it be possible to tag, release (GitHub) and publish (Hex) 2.5.5, maybe?

Thanks.

recon_trace:calls for remote node

add function like this
([email protected]) > recon_trace:remote_calls(['[email protected]','[email protected]'],{lists,seq,'_'},10).
([email protected]) > lists:seq(1).
([email protected]) > lists:seq(1).
all stdout will redirect to [email protected]

[email protected] 18:38:01.195994 <0.88.0>  lists:seq(1)  
[email protected] 18:38:01.195994 <0.89.0>  lists:seq(1)

It will work when debugging code in production consumer mode.
If you accept this issue,I will pull requests.

recon_trace:calls - no output on OTP26

When using recon_trace:calls, I don't get any (meaningful) output on OTP26. Empty lines are printed for every function call, but I can't see the actual trace output:

$ rebar3 shell
===> Verifying dependencies...
===> Analyzing applications...
===> Compiling recon
Erlang/OTP 26 [erts-14.0] [source] [64-bit] [smp:10:10] [ds:10:10:10] [async-threads:1] [jit] [dtrace]

Eshell V14.0 (press Ctrl+G to abort, type help(). for help)
1> recon_trace:calls({lists, seq, return_trace}, 10).
2
2> [lists:seq(1, X) || X <- [1, 2, 3]].
[[1],[1,2],[1,2,3]]






3>

On OTP25, everything works as expected:

1> recon_trace:calls({lists, seq, return_trace}, 10).
2
2> [lists:seq(1, X) || X <- [1, 2, 3]].

11:9:45.591208 <0.94.0> lists:seq(1, 1)
[[1],[1,2],[1,2,3]]

11:9:45.591826 <0.94.0> lists:seq/2 --> [1]

11:9:45.592098 <0.94.0> lists:seq(1, 2)

11:9:45.592347 <0.94.0> lists:seq/2 --> [1,2]

11:9:45.592612 <0.94.0> lists:seq(1, 3)

11:9:45.592785 <0.94.0> lists:seq/2 --> [1,2,3]

Custom formatters for tracer

It would be nice to support custom formatter callback function. Custom formatters are useful for log/replay testing. For example if you have an http server you would be able to trace calls to it and format trace records as curl or httpie commands. Then you can just copy paste wget commands to create simple test case. Custom formatters also would benefit elixir/LFE/... users.

Newbie question

How do I incorporate it with my app? I have an existing app, which I connect to with remsh, and i want to make use of recon to introspect it. I've tried copying the beam files to my lib, but cannot execute any recon functions from the remote shell... would be great if we can add some docs to explain how to incorporate it to any generic app.

Is recon:proc_count(memory, 10) an expensive command?

All,
In my system, I have seen the max simultaneous process number is around 100K. Will executing recon:proc_count(memory, 10) in every 4 minutes have significant performance impact on the system?
Any suggestion regarding this will be highly appreciated.
Thanks.

Find top n items in unordered list function.

https://github.com/ferd/recon/blob/master/src/recon.erl#L263

 lists:sublist(lists:usort(
        fun({_,A,_},{_,B,_}) -> A > B end,
        recon_lib:sliding_window(First, Last)
    ), Num).

Don't need to sort all items.
I run some benchmarks base on gb_tree and order_list, please have a look.
https://gist.github.com/zhongwencool/d7d4db85b094f74f5edf876e413dca0d

Which method is better?
:)

typo example

https://github.com/ferd/recon/blob/master/src/recon_trace.erl#L252
recon_trace:calls([{dict,filter,2},{lists,filter,2}], 10, [{pid, new]})

recon:port_info/1 errors with OTP 23.0 and later when Creation > 3

My guess is that this is related to the DFLAG_BIG_CREATION that Erlang/OTP 23 required. Transcript:

• Erlang 22.3:

  C:\Users\bakkenl\development\ferd\recon [(2.5.2) +0 ~1 -0 !]
  > git clean -xffd; C:\tools\erl-22.3\bin\escript.exe C:\Users\bakkenl\bin\rebar3 shell
  Removing _build/
  ===> Verifying dependencies...
  ===> Analyzing applications...
  ===> Compiling recon
  Eshell V10.7  (abort with ^G)
  1> node().
  nonode@nohost
  2> recon:port_info("#Port<0.28>").
  [{meta,[undefined,undefined,undefined,undefined]},
   {signals,[undefined,undefined,undefined]},
   {io,[undefined,undefined]},
   {memory_used,[undefined,undefined]},
   {type,[]}]
  3>
  
  C:\Users\bakkenl\development\ferd\recon [(2.5.2) +0 ~1 -0 !]
  > git clean -xffd; C:\tools\erl-22.3\bin\escript.exe C:\Users\bakkenl\bin\rebar3 shell --sname recon@localhost
  Removing _build/
  ===> Verifying dependencies...
  ===> Analyzing applications...
  ===> Compiling recon
  Eshell V10.7  (abort with ^G)
  (recon@localhost)1> node().
  recon@localhost
  (recon@localhost)2> recon:port_info("#Port<0.28>").
  [{meta,[undefined,undefined,undefined,undefined]},
   {signals,[undefined,undefined,undefined]},
   {io,[undefined,undefined]},
   {memory_used,[undefined,undefined]},
   {type,[]}]
  (recon@localhost)3>
  

• Erlang 23.0 (and beyond):

  C:\Users\bakkenl\development\ferd\recon [(2.5.2) +0 ~1 -0 !]
  > git clean -xffd; C:\tools\erl-23.0\bin\escript.exe C:\Users\bakkenl\bin\rebar3 shell
  Removing _build/
  ===> Verifying dependencies...
  ===> Analyzing applications...
  ===> Compiling recon
  Eshell V11.0  (abort with ^G)
  1> node().
  nonode@nohost
  2> recon:port_info("#Port<0.28>").
  [{meta,[undefined,undefined,undefined,undefined]},
  {signals,[undefined,undefined,undefined]},
  {io,[undefined,undefined]},
  {memory_used,[undefined,undefined]},
  {type,[]}]
  3>
  
  C:\Users\bakkenl\development\ferd\recon [(2.5.2) +0 ~1 -0 !]
  > git clean -xffd; C:\tools\erl-23.0\bin\escript.exe C:\Users\bakkenl\bin\rebar3 shell --sname recon@localhost
  Removing _build/
  ===> Verifying dependencies...
  ===> Analyzing applications...
  ===> Compiling recon
  Eshell V11.0  (abort with ^G)
  (recon@localhost)1> node().
  recon@localhost
  (recon@localhost)2> recon:port_info("#Port<0.28>").
  ** exception error: bad argument
      in function  binary_to_term/1
          called as binary_to_term(<<131,102,100,0,15,114,101,99,111,110,64,108,
                                  111,99,97,108,104,111,115,116,0,0,0,28,86>>)
      in call from recon_lib:term_to_port/1 (c:/Users/bakkenl/development/ferd/recon/src/recon_lib.erl, line 182)
      in call from recon:port_info/1 (c:/Users/bakkenl/development/ferd/recon/src/recon.erl, line 597)
  (recon@localhost)3>
  

Elixir Kernel function cannot be traced but erlang kernel

Hi, I'd like to use the recon_trace in the elixir application. It works well most of the time but has some problems with the elixir kernel function.
When I try to trace a kernel function in elixir, it seems can't be traced but only from the erlang one. below is an example of Kernel.+/2
this also happens to all the other Kernal methods that I tested so far. I wonder if there is some syntax error about the matching here or it's some other issues.

iex(1)> :recon_trace.calls({Kernel, :+, 2}, 1)
1
iex(2)> Kernel.+(1,2)
3
iex(3)> :recon_trace.calls({:erlang, :+, 2}, 1)
1
iex(4)> Kernel.+(1,2)
3

5:54:07.460259 <0.190.0> erlang:'+'(1, 2)
Recon tracer rate limit tripped.

Problem using recon_trace in Elixir

In IEx I can trace using the following expression:

:recon_trace.calls({Server, :json_encode, 1}, 10)

When I attempt to get return values, I try (among many variants!):

:recon_trace.calls({Server, :json_encode, fn x -> return_trace end}, 10)

... and I get this fun message:

Error: Unknown error code {122,'Elixir.IEx.Helpers',return_trace}
** (CaseClauseError) no case clause matching: {:error, :transform_error}
(recon) src/recon_trace.erl:435: :recon_trace.validate_tspec/3
(recon) src/recon_trace.erl:379: :recon_trace."-trace_calls/3-lc$^0/1-0-"/2
(recon) src/recon_trace.erl:378: :recon_trace.trace_calls/3

Am I doing something wrong? Or is this a problem in recon? Or Elixir?

Thanks for this great package!

Best,

Mike

Crash on recon_alloc:memory(used) on OTP 23.0

On requesting the used memory on OTP 23.0:

(zotonic@PoToi)2> recon_alloc:memory(used).
** exception error: bad argument
     in function  element/2
        called as element(2,false)
     in call from recon_alloc:container_value/4 (/Users/marc/Sites/zotonic-master/_build/default/lib/recon/src/recon_alloc.erl, line 696)
     in call from recon_alloc:container_size/3 (/Users/marc/Sites/zotonic-master/_build/default/lib/recon/src/recon_alloc.erl, line 668)
     in call from lists:map/2 (lists.erl, line 1239)
     in call from recon_alloc:memory/2 (/Users/marc/Sites/zotonic-master/_build/default/lib/recon/src/recon_alloc.erl, line 208)

This is on macOS 10.14.6, OTP 23.0, build with kerl:

Erlang/OTP 23 [erts-11.0] [source] [64-bit] [smp:12:12] [ds:12:12:10] [async-threads:1] [hipe]

初始化参数中的SchedWall和erlang:statistics(scheduler_wall_time)的结果可能相同

** exception error: an error occurred when evaluating an arithmetic expression
in function recon_lib:'-scheduler_usage_diff/2-fun-0-'/1 (e:/mywork/recon/src/recon_lib.erl, line 221)
in call from lists:map/2 (lists.erl, line 1237)
in call from recon:'-node_stats/4-fun-0-'/1 (e:/mywork/recon/src/recon.erl, line 430)
in call from recon_lib:time_fold/6 (e:/mywork/recon/src/recon_lib.erl, line 206)
in call from recon:node_stats/4 (e:/mywork/recon/src/recon.erl, line 445)

Please create a new release

If you have time, would you mind creating a new release? I'm doing some RabbitMQ debugging and am running into the issue fixed by #100. We're pinned to version 2.5.2 in the RabbitMQ codebase. Thank you!

Add binary dump to process info

https://github.com/erlyvideo/flussonic-old/blob/e52617d21b7de9524ab64df6f8aa518ecd9527f3/apps/flussonic/src/ems_debug.erl#L54

Maybe add something like this?

Would atom table dumping be useful for recon?

See the second answer here
http://stackoverflow.com/questions/13480462/erlang-can-i-get-a-list-of-all-currently-registered-atoms
It's a neat trick which could of course break an any point, but I could imagine something which captured the current count, paused, then captured again helping out in the cases where you are programmatically creating atoms (or something is), and you don't know what.

Assumably, the system might first crash with full atom tables or something like that, they you start up with recon and see what's growing the table? At least that's a use-case I could imagine.

What do you think?

Move from Travis CI to GitHub Actions?

Would you be interested in a pull request that moves CI from Travis CI to GitHub Actions, or at least adds GitHub Actions alongside Travis CI? It seems travis-ci.org will stop being useful from Dec 31 2020. I can do it, except that I think you need to create the workflow yml, first, in master, after which I can branch off of.

Two failing tests in recon_alloc_SUITE.erl

1. recon_alloc_SUITE:snapshots/1 fails on R16B03 (same issue as the one fixed in c009363 )
2. recon_alloc_SUITE:memory/1 fails during:

   true = Usage =< recon_alloc:memory(usage, max)

which is IMHO plain wrong.

recon_alloc fails on OTP 23

$ rebar3 shell
===> Verifying dependencies...
===> Compiling recon
Erlang/OTP 23 [erts-11.0] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1]

Eshell V11.0  (abort with ^G)
1> recon_alloc:memory(used).
** exception error: bad argument
     in function  element/2
        called as element(2,false)
     in call from recon_alloc:container_value/4 (/Users/aboroska/github/recon/src/recon_alloc.erl, line 699)
     in call from recon_alloc:container_size/3 (/Users/aboroska/github/recon/src/recon_alloc.erl, line 671)
     in call from lists:map/2 (lists.erl, line 1239)
     in call from recon_alloc:memory/2 (/Users/aboroska/github/recon/src/recon_alloc.erl, line 208)

Erlang 23 changed the system_info allocators format. Notably blocks and blocks_size.

For example TypeProps in OTP 22:

{mbcs,[{blocks,0,0,1},
             {blocks_size,0,0,56}, ...

In OTP 23:

    {mbcs, [{blocks, [{temp_alloc,[{count,0,0,1},{size,0,0,56}]}]},
                  {carriers,1,1,1}, ...

and

{mbcs, [{blocks, [{sl_alloc, [{count,0,1,1332},{size,0,64,209480}]}]},
              {carriers,1,1,2}, ...

also

{sbcs,  [{blocks,[]}, 
              {carriers,0,0,0}, ...

recon:rpc/3 badfun

hi fred,

1. NodeA, NodeB are connected;
2. In NodeA I can do

rpc:call(NodeB, make, all, [[load]]).
update_to_date

the problem is ：

rpc:call(NodeB, erlang, apply, [fun() -> make:all([load]) end,[]]).

{badrpc,{'EXIT',{{badfun,#Fun<shell.5.68187095>},
[{erl_eval,do_apply,6,[{file,"erl_eval.erl"},{line,659}]},
{rpc,'-handle_call_call/6-fun-0-',5,
[{file,"rpc.erl"},{line,205}]}]}}}

they both compile their code from the same source ,but the machine system setting is different.

So:

Maybe change recon:rpc(Node, Fun, Timeout) to recon:rpc(Node, M, F, A, Timeout) will be better?