Broken pipe on request

[dedayoa]

Hello @all. This library has worked flawlessly so far, but then I started experiencing an issue. http request seem to freeze and then return nil after a few seconds. I was able to get the same request to work with postman. Also, this only happens for a particular request. My request function

function make_request(url, params, xml_request)
    local http_request = require "http.request"
    local req = http_request.new_from_uri(xml_handler_url)
    req.headers:upsert(":method", "POST")
    req.headers:upsert("content-type", "application/json")
    -- add hostname to header esp. for loading event_socket on startup
    req.headers:upsert('host-name', trim(api:execute("switchname")))

    for k,v in pairs(xml_request) do
        req.headers:upsert(string.gsub(k, "_", "-"), v)
    end    

    if (params:serialize() ~= nil) then
        req:set_body(params:serialize("json"))
    end

    if (debug["http_request"]) then
        freeswitch.consoleLog("notice", "[URL]: "..xml_handler_url.."\n[BODY]"..params:serialize().."\n");
    end

    local headers, stream = req:go()

    freeswitch.consoleLog("notice", "[STREAM]: "..stream.."\n");

    local body = assert(stream:get_body_as_string(5))

    freeswitch.consoleLog("notice", "[STATUS]: "..headers:get("status").."\n");

    if headers:get ":status" ~= "200" then
        error(body)
    end

    return body;
end

My request headers

Section:directory
Tag-Name:domain
Key-Name:name
Key-Value:tekart.dayo.com.ng
Content-Type:application/json

Request body

{"Event-Name":"REQUEST_PARAMS","Core-UUID":"fa82b0bd-f4af-4f89-b8c9-c7668acc9ff9","FreeSWITCH-Hostname":"test-fs-001","FreeSWITCH-Switchname":"test-fs-001","FreeSWITCH-IPv4":"139.162.188.90","FreeSWITCH-IPv6":"::1","Event-Date-Local":"2018-08-26 07:04:53","Event-Date-GMT":"Sun, 26 Aug 2018 07:04:53 GMT","Event-Date-Timestamp":"1535267093552210","Event-Calling-File":"sofia_reg.c","Event-Calling-Function":"sofia_reg_parse_auth","Event-Calling-Line-Number":"2820","Event-Sequence":"1266","action":"sip_auth","sip_profile":"internal","sip_user_agent":"Z 3.15.40006 rv2.8.20","sip_auth_username":"1001","sip_auth_realm":"tekart.dayo.com.ng","sip_auth_nonce":"2e899b8c-44bc-4b94-a610-39777e714408","sip_auth_uri":"sip:tekart.dayo.com.ng;transport=UDP","sip_contact_user":"1001","sip_contact_host":"192.168.43.205","sip_to_user":"1001","sip_to_host":"tekart.dayo.com.ng","sip_via_protocol":"udp","sip_from_user":"1001","sip_from_host":"tekart.dayo.com.ng","sip_call_id":"Mrvir4KlInsn7QsSbQJtqQ..","sip_request_host":"tekart.dayo.com.ng","sip_auth_qop":"auth","sip_auth_cnonce":"be4f06798446b872daee39cc7856329d","sip_auth_nc":"00000001","sip_auth_response":"d323a68857a84252282d0231b9ce9346","sip_auth_method":"REGISTER","client_port":"56316","key":"id","user":"1001","domain":"tekart.dayo.com.ng","ip":"197.210.47.195"}

A sample response - using postman

<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
    <section name="directory">
        <domain name="tekart.dayo.com.ng" alias="true">
            <params>
                <param name="jsonrpc-allowed-methods" value="verto"/>
                <param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
            </params>
            <groups>
                <group name="default">
                    <users>
                        <user id="1001">
                            <params>
                                <param name="password" value=""/>
                                <param name="vm-enabled" value="false"/>
                                <param name="dial-string" value="{sip_invite_domain=&quot;tekart.dayo.com.ng&quot;,presence_id=&quot;1001@tekart.dayo.com.ng&quot;}${sofia_contact(&quot;1001@tekart.dayo.com.ng&quot;)}"/>
                                <param name="verto-context" value="tekart.dayo.com.ng"/>
                                <param name="verto-dialplan" value="XML"/>
                                <param name="jsonrpc-allowed-methods" value="verto"/>
                                <param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
                            </params>
                            <variables>
                                <variable name="domain_uuid" value="None"/>
                                <varibale name="domain_name" value="tekart.dayo.com.ng"/>
                                <variable name="user_id" value="4"/>
                                <variable name="extension_uuid" value="ca301077-645a-4740-a33a-e5989c8b4ab4"/>
                                <variable name="call_timeout" value="30"/>
                                <variable name="caller_id_name" value="1001"/>
                                <variable name="caller_id_number" value="1001"/>
                                <variable name="prescene_id" value="1001@tekart.dayo.com.ng"/>
                                <variable name="user_context" value="tekart.dayo.com.ng"/>
                                <variable name="bypass_media" value="false"/>
                                <variable name="export_vars" value="domain_name"/>
                            </variables>
                        </user>
                    </users>
                </group>
            </groups>
        </domain>
    </section>
</document>

Error from CLI

2018-08-26 09:22:08.832556 [NOTICE] switch_cpp.cpp:1365 [STREAM]: Broken pipe
2018-08-26 09:22:08.832556 [ERR] mod_lua.cpp:203 /usr/share/freeswitch/scripts/app/xml_handler/index.lua:59: attempt to call method 'get_body_as_string' (a nil value)
stack traceback:
        /usr/share/freeswitch/scripts/app/xml_handler/index.lua:59: in function 'make_request'
        /usr/share/freeswitch/scripts/app/xml_handler/index.lua:73: in main chunk
        /usr/share/freeswitch/scripts/app.lua:15: in main chunk
2018-08-26 09:22:08.832556 [ERR] mod_lua.cpp:271 LUA script parse/execute error!

Thanks in advance

[daurnimator]

local headers, stream = req:go()

Make sure you assert this to get the actual error message.

[dedayoa]

So five minutes after posting this, I ended up solving a problem I'd been on for a whole day...maybe more! ARRGH! Turns out that my development server (django devserver) was not dealing with the expect:100-continue header semantics. req.headers:delete("expect") did the trick.

Question/Suggestion I don't know the reasoning for the expect header being quietly set on the request, but it does pose a problem for the untrained eye/mind. Why not leave setting this option up to the developer?

[dedayoa]

@daurnimator issue resolved See https://github.com/daurnimator/lua-http/issues/126#issuecomment-416027069. Thanks for the edit. Now I know about ```[lang] :)

[daurnimator]

Turns out that my development server (django devserver) was not dealing with the expect:100-continue header semantics.

What did it do wrong? Have you filed a bug with them?

I don't know the reasoning for the expect header being quietly set on the request, but it does pose a problem for the untrained eye/mind.

Sending a large request body without it is considered bad behaviour by servers. Even curl sets it! Since curl is so widely used for testing/debugging I'm suprised you were able to find a server that doesn't like it.

Why not leave setting this option up to the developer?

Because they're likely to forget/not know that they're meant to set it. they can opt out by deleting the header as you did.

[dedayoa]

Well, its a development server built into django and not a production server like nginx or apache. The core team will not consider a case such as this to be a "bug"

Sending a large request body without it is considered bad behaviour by servers. Even curl sets it! Since curl is so widely used for testing/debugging I'm suprised you were able to find a server that doesn't like it.

Now, I understand. Thanks for the help. Much appreciated.

[daurnimator]

Well, its a development server built into django and not a production server like nginx or apache. The core team will not consider a case such as this to be a "bug"

I'd still file it anyway. Even if it's just to have a closed "wontfix" bug as something point to at in a comment next to your :delete("expect") line.