[erlang-questions] No backtrace on errors in cowboy

Fred Hebert mononcqc@REDACTED
Wed Jul 18 04:34:57 CEST 2012


First of all, you have to understand that when a request comes in 
cowboy, there goes a chain of command based on how you described your 
listener in a call to cowboy:start_listener. That chain does things like 
accepting requests, handling socket/port ownership, and dispatching stuff.

One of the steps in there is to start a process based on the protocol 
you picked. In this case, the protocol is handled by 
cowboy_http_protocol, and the function is request.

That's where your stack trace begins.

When a call is made in Erlang, and that call is the last thing to happen 
in a function's body (it's a tail call), the stack trace for the current 
one will be dropped. This is to say, if I have:

a() -> b(), ok.
b() -> hello, c().
c() -> ok.

and I'm in b(), the stack trace will be [a, b]. a() is there because b() 
isn't happening in last place. We thus need to store that we're part of 
'a' in order to return to it in the future and execute the 'ok' 
expression. Then b() calls c().

Because b() ends with a call to c(), and we know that b() returns to 
a(), we can replace b in [a,b] and change it to [a,c]. This is good, 
because when we do things like recursing forever in a server loop, it 
keeps us from growing the stack until it crashes (stack overflow, or 
OOM). We drop whatever stack trace information we can afford to drop.

So when your error happens, it's on line 172.

This goes through:

request -> parse_header -> wait_header

parse_header and wait_header both happen in a tail position. This 
explains why your stack trace shows *nothing* but request. They're each 
removed from the stack trace before. That explains why you get:

[{cowboy_http_protocol,request,2,
  [{file,"src/cowboy_http_protocol.erl"},{line,172}]}]

Consider yourself lucky we now have line numbers to help!

Now for the shell, when you get an error there, it looks like:

[{erl_eval,do_apply,6,[{file,"erl_eval.erl"},{line,576}]},
  {erl_eval,try_clauses,8,[{file,"erl_eval.erl"},{line,767}]},
  {shell,exprs,7,[{file,"shell.erl"},{line,668}]},
  {shell,eval_exprs,7,[{file,"shell.erl"},{line,623}]},
  {shell,eval_loop,3,[{file,"shell.erl"},{line,608}]}]

This is simply because shell evaluation and whatnot, for all these 
functions, is *not* making these calls in a tail position. This is part 
of how the shell works, and explains why you'll get a longer stack trace 
there than with compiled code.

You can see part of the variation there:

1> spawn(fun() -> try
1>         erlang:error(xxxxxREQ_error)
1>     catch
1>         error:_ ->
1>             io:format("~nxxxxxREQ_error stacktrace~n~p~n", 
[erlang:get_stacktrace()])
1>     end
1> end).

xxxxxREQ_error stacktrace
[{erl_eval,do_apply,6,[{file,"erl_eval.erl"},{line,576}]},
  {erl_eval,try_clauses,8,[{file,"erl_eval.erl"},{line,767}]}]
<0.71.0>

You'll see that for that one, part of the evaluation was done 
beforehand. When the new function is spawned and starts running, the 
'shell' module is no longer involved, and the stack trace changes. New 
processes do not carry old stack information as they need not to return 
anywhere.

So it's not surprising that you get barely nothing from cowboy when the 
function you get is pretty much the only one that can be allowed in the 
stack trace by these rules. It's brand new and the error happens after a 
chain of tail calls.

I hope this helps.

On 12-07-17 2:09 PM, Aleksandr Vinokurov wrote:
>
>
> Hello all,
>
> I need to see a backtrace of a cowboy_http_protocol:request/2 and to 
> get it I've added some code in the function (marked strong):
>
> request(_Any, State) ->
> %%%%%%%%%
> *io:format("~n~p~n", [{xxxxx161, State, _Any}]),*
> *    try*
> *        erlang:error(xxxxx161_error)*
> *    catch*
> *        error:X ->*
> *            io:format("~nxxxxx161_error stacktrace~n~p~n", 
> [erlang:get_stacktrace()]),*
> *            erlang:error(X)*
> *    end,*
> *%%%%%%%%%%%*
> error_terminate(400, State).
>
>
> After recompilation and reloading I see only one line in backtrace list:
>
> (web@REDACTED)1>
> {xxxxx161,
> {state,<0.85.0>,#Port<0.3809>,cowboy_tcp_transport,
>         [{'_',
>              [{[<<"token">>],
>                ps_oauth_2_api_external_token_endpoint,
>                [{config,off,off,
>                     {{127,0,0,1},8080},
>                     {{127,0,0,1},8180},
>                     {{127,0,0,1},8443},
>                     {{127,0,0,1},8543},
>                     [{"jay","123"},"bob",{"matt","321"}],
>                     "http://127.0.0.1:8881/client-storage",
> [{<<"apt1">>,{seconds,600,"600"}},
>  {<<"apt2">>,{seconds,6000,"6000"}}],
>                     {seconds,3600,"3600"},
>                     {seconds,600,"600"},
>                     undefined,
>                     {bytes,64},
>                     {bytes,256},
>                     {bytes,1024}},
> {external_api_applications,ps_oauth_2_ext_api_applications}]},
> {'_',ps_oauth_2_index,[external,#Fun<ps_oauth_2.2.99090327>]}]}],
>         {ps_oauth_2_api_external_token_endpoint,
>             [{config,off,off,
>                  {{127,0,0,1},8080},
>                  {{127,0,0,1},8180},
>                  {{127,0,0,1},8443},
>                  {{127,0,0,1},8543},
>                  [{"jay","123"},"bob",{"matt","321"}],
>                  "http://127.0.0.1:8881/client-storage",
>  [{<<"apt1">>,{seconds,600,"600"}},
> {<<"apt2">>,{seconds,6000,"6000"}}],
>                  {seconds,3600,"3600"},
>                  {seconds,600,"600"},
>                  undefined,
>                  {bytes,64},
>                  {bytes,256},
>                  {bytes,1024}},
>  {external_api_applications,ps_oauth_2_ext_api_applications}]},
>         undefined,undefined,
>         {#Fun<cowboy_http.urldecode.2>,crash},
>         0,5,213,infinity,4096,5000,
>         <<"authorization: Basic YXBwMToxMjM=\r\nconnection: 
> keep-alive\r\n\r\ngrant_type=authorization_code&code=1pD8tsKZTFXw3sbbOPbLtCU0oSg5CWx%2FohR8AC%2BAuTROzsx1DQC6LLm4h6iaOvupV5cOs3cAqBqsWB%2BtzfxVtg%3D%3D">>,
>         false,infinity,undefined},
>     {http_error,<<"7.0.0.1:8080 <http://7.0.0.1:8080>\r\n">>}}
>
> (web@REDACTED)1>
> xxxxx161_error stacktrace
> [{cowboy_http_protocol,request,2,
>  [{file,"src/cowboy_http_protocol.erl"},{line,172}]}]
> (web@REDACTED)1>
>
> =ERROR REPORT==== 17-Jul-2012::21:51:26 ===
> Error in process <0.1373.0> on node 'web@REDACTED' with exit value: 
> {xxxxx161_error,[{cowboy_http_protocol,request,2,[{file,"src/cowboy_http_protocol.erl"},{line,176}]}]}
>
> =SUPERVISOR REPORT==== 17-Jul-2012::21:51:26 ===
>      Supervisor: {<0.86.0>,cowboy_requests_sup}
>      Context:    child_terminated
>      Reason:     {xxxxx161_error,
>                      [{cowboy_http_protocol,request,2,
> [{file,"src/cowboy_http_protocol.erl"},
>                            {line,176}]}]}
>      Offender:   [{pid,<0.1373.0>},
>                   {name,cowboy_requests_sup},
> {mfargs,{cowboy_requests_sup,start_request,undefined}},
>                   {restart_type,temporary},
>                   {shutdown,brutal_kill},
>                   {child_type,worker}]
>
> If I call that code in shell I see a full backtrace like that:
>
> (web@REDACTED)4> try
>         erlang:error(xxxxxREQ_error)
>     catch
>         error:_ ->
>             io:format("~nxxxxxREQ_error stacktrace~n~p~n", 
> [erlang:get_stacktrace()])
>     end.
>
> xxxxxREQ_error stacktrace
> [{erl_eval,do_apply,6,[{file,"erl_eval.erl"},{line,576}]},
>  {erl_eval,try_clauses,8,[{file,"erl_eval.erl"},{line,767}]},
>  {shell,exprs,7,[{file,"shell.erl"},{line,668}]},
>  {shell,eval_exprs,7,[{file,"shell.erl"},{line,623}]},
>  {shell,eval_loop,3,[{file,"shell.erl"},{line,608}]}]
> ok
> (web@REDACTED)5>
>
> I don't understand what am I doing wrong.
>
> -- 
> ????????? ?????????
> +7 (921) 982-21-43
> @aleksandrvin
>
>
>
> _______________________________________________
> erlang-questions mailing list
> erlang-questions@REDACTED
> http://erlang.org/mailman/listinfo/erlang-questions

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://erlang.org/pipermail/erlang-questions/attachments/20120717/85d5c4f1/attachment.htm>


More information about the erlang-questions mailing list