Mochiweb and Erlang OTP 17.3

177 views
Skip to first unread message

Bogdan Andu

unread,
Oct 30, 2014, 7:14:07 AM10/30/14
to moch...@googlegroups.com

Hi ,

Sorry for opening an old issue but I can not find a solution.

At every http request mochiweb yields the following crash:

=CRASH REPORT==== 30-Oct-2014::12:47:08 ===
  crasher:
    initial call: mochiweb_acceptor:init/3
    pid: <0.151.0>
    registered_name: []
    exception error: no match of right hand side value {error,einval}
      in function  mochiweb_http:request/2 (src/mochiweb_http.erl, line 63)
    ancestors: [mwagl_http_inet,<0.142.0>,<0.126.0>]
    messages: []
    links: [<0.143.0>]
    dictionary: []
    trap_exit: false
    status: running
    heap_size: 376
    stack_size: 27
    reductions: 2212
  neighbours:

I modified the file src/mochiweb_http.erl in order to print some values:
loop(Socket, Body) ->
    R1 = mochiweb_socket:setopts(Socket, [{packet, http}]),
    R2 = inet:getstat(Socket),
    R3 = inet:sockname(Socket),
    error_logger:info_msg("[LOOP]:~nSOCKET=~p~nSETOPTS=~p~nGETSTAT=~p~nSOCKNAME=~p~n", [Socket, R1, R2, R3]),
    request(Socket, Body).

request(Socket, Body) ->
    R1 = mochiweb_socket:setopts(Socket, [{active, once}]),
    R2 = inet:getstat(Socket),
    R3 = inet:sockname(Socket),
    error_logger:info_msg("[REQUEST]:~nSOCKET=~p~nSETOPTS=~p~nGETSTAT=~p~nSOCKNAME=~p~n", [Socket, R1, R2, R3]),
    receive
    ..........

[LOOP]:
SOCKET=#Port<0.5049>
SETOPTS=ok
GETSTAT={ok,[{recv_oct,0},
             {recv_cnt,0},
             {recv_max,0},
             {recv_avg,0},
             {recv_dvi,0},
             {send_oct,0},
             {send_cnt,0},
             {send_max,0},
             {send_avg,0},
             {send_pend,0}]}
SOCKNAME={ok,{{10,10,11,66},8010}}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[REQUEST]:
SOCKET=#Port<0.5049>
SETOPTS=ok
GETSTAT={ok,[{recv_oct,77},
             {recv_cnt,1},
             {recv_max,77},
             {recv_avg,77},
             {recv_dvi,0},
             {send_oct,0},
             {send_cnt,0},
             {send_max,0},
             {send_avg,0},
             {send_pend,0}]}
SOCKNAME={ok,{{10,10,11,66},8010}}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[<0.222.0>]:REQ={'GET',"/get_cookie_m?list=sfgdfgdfgdf"}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[LOOP]:
SOCKET=#Port<0.5701>
SETOPTS=ok
GETSTAT={ok,[{recv_oct,0},
             {recv_cnt,0},
             {recv_max,0},
             {recv_avg,0},
             {recv_dvi,0},
             {send_oct,0},
             {send_cnt,0},
             {send_max,0},
             {send_avg,0},
             {send_pend,0}]}
SOCKNAME={ok,{{10,10,11,66},8010}}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[REQUEST]:
SOCKET=#Port<0.5701>
SETOPTS=ok
GETSTAT={ok,[{recv_oct,86},
             {recv_cnt,1},
             {recv_max,86},
             {recv_avg,86},
             {recv_dvi,0},
             {send_oct,0},
             {send_cnt,0},
             {send_max,0},
             {send_avg,0},
             {send_pend,0}]}
SOCKNAME={ok,{{10,10,11,66},8010}}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[<0.227.0>]:REQ={'POST',"/update_session_cn?cookie_val=46d35f1fab2c8051c2a219c62c148be48a35f50e"}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[LOOP]:
SOCKET=#Port<0.5701>
SETOPTS={error,einval}
GETSTAT={error,einval}
SOCKNAME={error,einval}

=INFO REPORT==== 30-Oct-2014::12:55:45 ===
[REQUEST]:
SOCKET=#Port<0.5701>
SETOPTS={error,einval}
GETSTAT={error,einval}
SOCKNAME={error,einval}

The line number  63 may not be relevenat any more

I seems that the socket is valid - exists in the system and when a POST
is sent to the server einval appears.
It looks like it tries to use for POST request the same socket for the previous
GET request.

Don't know why this happens.

Please shed some light on this issue as I am stuck and I have to migrate my application servers on otp 17

Thank you,

Bogdan


 

Вадим Картавых

unread,
Oct 30, 2014, 1:30:21 PM10/30/14
to moch...@googlegroups.com
Sorry friend, but i didn`t programming on erlang about 5 years

--
You received this message because you are subscribed to the Google Groups "MochiWeb" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mochiweb+u...@googlegroups.com.
To post to this group, send email to moch...@googlegroups.com.
Visit this group at http://groups.google.com/group/mochiweb.
For more options, visit https://groups.google.com/d/optout.

Bob Ippolito

unread,
Oct 30, 2014, 6:24:12 PM10/30/14
to moch...@googlegroups.com
Do you have a minimal example that can reproduce this issue? Other users are not reporting problems with 17. Since you haven't posted the code that you use to set up the server or handle the request it's unclear how to reproduce the issue. Please also specify the operating system and version of mochiweb that you are testing with.

Ideally a (potential) bug report would be an issue on GitHub, rather than a mailing list post.

--

Bogdan Andu

unread,
Oct 31, 2014, 4:43:21 AM10/31/14
to moch...@googlegroups.com

Hi,

This is an example of how the application is structured:


Every http response is a json structure.


%% HTTP Module
-module(mod_httpd).

%% The Arg Options0 is read from .app file passed via app supervisor
%% to this worker, in the form:
%% {mod_http_loop, Options}
start(Options0) ->
    [Module, Options] = Options0,
   
    {DocRoot, Options1} = get_option(docroot, Options),
   
    Loop = fun (Req) ->
        Module:loop(Req)
    end,
    mochiweb_http:start([{loop, Loop} | Options1]).

......
%% HTTP LOOP Module:
module(mod_http_loop).

-export([loop/1]).

%% External API
loop(Req) ->
    "/" ++ Path = Req:get(path),
   
    case Req:get(method) of
        Method when Method =:= 'GET' ->
            case Path of

                "check_value" ->
                    DataIn = Req:parse_qs(),
                    Val = proplists:get_value("val", DataIn),
                    NewValue = Val * 10,
                    Rez = mochijson:encode({struct,  [{"valid", "true"}, {"value", NewValue}].}),
                    Req:respond({200, [{"Content-Type", "text/xml; charset=UTF-8"}], [iolist_to_binary(Rez)]});


.....................................

The crash appears after the request-response cycle is completed.

I also observed the fact that in examples the loop i defined as loop(Req),
but in templates/ as loop (Req, DocRoot).

Also the loop option has two forms:
1) {loop, {Module, loop_function}}

2) {loop, Fun}, where :
Fun = fun (Req) ->
        Module:loop(Req)
end,

which idiom is recommended for use in practice?

I also observed that if the http client issues a header : "Connection:close" to MochiWeb server, the crash dissapear

It seems that the server closes the socket on its side but the client would insists to send data on that socket, which being closed
the error einval appears which I think it means to set a socket option to an invalid socket.

On Fedora 20 x86_64 I had to programmatically issue the header "Connection:close" from the curl http client.

On OpenBSD 5.4 amd64 it seems that is no need to setup such header in client (may be is treated automatically tru some compile flag or something - I cannot tell).

Bogdan

Bob Ippolito

unread,
Nov 1, 2014, 3:20:36 PM11/1/14
to moch...@googlegroups.com
It looks like there's at least one typo in your code sample, there's a `.` in the `Rez = …` line that should not be there. It's also not valid to multiply a string by a number, so this code doesn't have any chance of working as-is.

Using the form `fun Module:loop/1` or `{Module, loop}` would be best, as it will not hold a reference to the current version of that module. There are actually three supported forms:

    call_body({M, F, A}, Req) ->
        erlang:apply(M, F, [Req | A]);
    call_body({M, F}, Req) ->
        M:F(Req);
    call_body(Body, Req) ->
        Body(Req).

The call to iolist_to_binary/1 isn't necessary, mochiweb will already do that. You can just write:

    Req:respond({200, [{"Content-Type", "text/xml; charset=UTF-8"}], Rez});

Or even better, use the convenience function:

    Req:ok({"text/xml; charset=UTF-8", Rez});

After fixing your example to work correctly, I am unable to reproduce your issue using `curl 'http://127.0.0.1:8080/check_value?val=1'` nor using telnet to manually issue multiple requests over the same connection. I have tested on Mac OS X 10.9 and Fedora 20. I'm sorry but you have not provided enough information to reproduce this issue. 

If you would like further assistance, please provide a fully reproducible example with instructions for how to reproduce (such as the curl command line).

-bob


Bogdan Andu

unread,
Nov 3, 2014, 5:40:22 AM11/3/14
to moch...@googlegroups.com

Hi ,

Thank you for insights.

Yes, indeed, there was a typo.. This was meant more as a pseudo-code. The important thing was the return value from server, which is a json structure as:

Req:respond({200, [{"Content-Type", "text/xml; charset=UTF-8"}], [iolist_to_binary(Rez)]})
and not a Req:respond({200, [], "200 OK\r\n"}) like in the example.

That made me to believe that client not seeing the 'OK' keeps its  socket open even though the server closed the socket on its side.

If a specify to the Perl curl client : WWW:Curl::Easy a header "Connection:close", the crash with einval, on the server side disappears 
which, I think , it means that the socket is no more accessed by the acceptor process.

Basically is a client issue, but I think that the socket behavior should not depend on a headers sent by clients.

Bogdan

Bogdan Andu

unread,
Nov 5, 2014, 8:56:17 AM11/5/14
to moch...@googlegroups.com

with command line curl was able to reproduce the einval crash,

but with curl -H"Connection:close" the crash dissapeared

Bob Ippolito

unread,
Nov 5, 2014, 10:25:51 AM11/5/14
to moch...@googlegroups.com
Sorry but I was using curl and was unable to reproduce. You have not provided sufficient information for me to help you. I need a complete example. Pseudo-code is no good. Nobody else is reporting a problem, so the issue is likely triggered by something your code is doing differently than everyone else. 
Reply all
Reply to author
Forward
0 new messages