New subject: Fwd: Async HTTP request is sent but response is incorrectly processed

29 Dec 2024


      Hi all!
still struggling with Async HTTP Client ...
My current configuration is very simple:
#!define HTTP_API_ROUTING_ENDPOINT_MAIN   "
http://MY_HTTP_REST_API:18085/Endpoint"
include_file "listen.cfg"
loadmodule "pv"
loadmodule "tm"
loadmodule "http_async_client"
loadmodule "xlog"
loadmodule "tmx"
loadmodule "sl"
loadmodule "textops"
loadmodule "cfgutils"
loadmodule "siputils"
loadmodule "rr"
loadmodule "ctl"
loadmodule "jsonrpcs.so"
loadmodule "jansson.so"
modparam("pv", "shvset", "http_async=i:8");
modparam("http_async_client", "workers", 1);
modparam("http_async_client", "connection_timeout", 500)
modparam("http_async_client", "curl_verbose", 1) # for debug purpose
#modparam("tm", "fr_timer", 750)
#modparam("tm", "fr_inv_timer", 20000)
#modparam("tm", "remap_503_500", 0)
modparam("tm", "failure_reply_mode", 3)
modparam("tm", "max_inv_lifetime",5000)
# ----- jsonrpcs params -----
modparam("jsonrpcs", "pretty_format", 1)
/* set the path to RPC fifo control file */
modparam("jsonrpcs", "fifo_name", "/tmp/kamailio_rpc.fifo")
/* set the path to RPC unix socket control file */
modparam("jsonrpcs", "dgram_socket", "/tmp/kamailio_rpc.sock")
debug=2
children=16
log_facility=LOG_LOCAL0
log_prefix="{$mt $hdr(CSeq) $ci} "
disable_sctp = yes
force_rport  = yes
rundir="/tmp"
request_route {
$avp(REQUEST_URL) = HTTP_API_ROUTING_ENDPOINT_MAIN;
if ( is_method("ACK") ) {
                if ( t_check_trans() ) {
                    t_relay();
                }
                exit;
        }
if(is_method("OPTIONS")){
                sl_reply("200", "OK");
                exit;
        }
if(is_method("CANCEL")){
                sl_reply("200","OK");
                sl_reply("487","Request Terminated");
                exit;
        }
jansson_set("string","from"    , $hdr(From)    , "$var(req)");
        jansson_set("string","to"      , $hdr(To)      , "$var(req)");
        jansson_set("string","r-uri"   , $ru           , "$var(req)");
        jansson_set("string","contact" , $hdr(Contact) , "$var(req)");
        jansson_set("string","call-id" , $ci           , "$var(req)");
xinfo("MAIN-ROUTE - Setting From=$hdr(From) To=$hdr(To)
Contact=$hdr(Contact) ci=$ci \n");
if ( is_present_hf("Identity") )
                jansson_set("string","identity"             ,
$hdr(Identity)            , "$var(req)");
if ( is_present_hf("P-Identity-Bypass") )
                jansson_set("string","p-identity-bypass"    ,
$hdr(P-Identity-Bypass)   , "$var(req)");
if ( is_present_hf("P-Asserted-Identity") )
                jansson_set("string","p-asserted-identity"  ,
$hdr(P-Asserted-Identity) , "$var(req)");
if ( is_present_hf("P-STSH-UC") )
                jansson_set("string","p-stsh-uc"            ,
$hdr(P-STSH-UC)           , "$var(req)");
        jansson_set("string", "request-time" , $avp(requestTime),
"$var(req)");
## Create transaction before http_async_query;
    if (is_method("INVITE")){
        t_newtran();
        xinfo("MAIN-ROUTE - Sending request [$var(req)]\n");
        route(HTTP_ASYNC_REQUEST);
    }
    exit;
}
route[HTTP_ASYNC_REQUEST] {
    xinfo("HTTP_ASYNC_REQUEST - Sending request [$var(req)]\n");
$http_req(all) = $null;
    $http_req(suspend) = 1;
    $http_req(timeout) = 1500; # 1 second timeout
    $http_req(method) = "POST";
    $http_req(hdr) = "Content-Type: application/json";
    $http_req(body) = $var(req);
if ( !http_async_query($avp(REQUEST_URL), "HTTP_REPLY") ) {
        xinfo("HTTP_ASYNC_REQUEST - http_async_query $ci FAILED. Return is
[$rc]\n");
    }else{
        send_reply("503", "Server Error");
        exit;
    }
}
route[HTTP_REPLY] {
    xinfo("HTTP_REPLY - Xphere Response Code $http_rs - $ci\n");
if ( $http_ok && $http_rs==200) {
        xinfo("HTTP_REPLY - $ci reply ok\n");
        jansson_xdecode($http_rb, "json");
        xinfo("HTTP_REPLY - HTTP JSON Response: $http_rb \n");
if ( $xavp(json=>sip-response-code) == 300 ){
                remove_hf("Contact");
                append_to_reply("Contact: $xavp(json=>contact)\r\n");
                ## "touch" the ruri to add the contact header for 3xx:
                $ru = $ru;
                send_reply("300", "Multiple Choice");
                exit;
        }else{
                xinfo("HTTP_REPLY - $ci Error Replied
$xavp(json=>sip-response-code) - $xavp(json=>sip-response-text) \n");
send_reply("$xavp(json=>sip-response-code)","$xavp(json=>sip-response-text)");
                exit;
        }
}
    else {
                xinfo("HTTP_REPLY - HTTP Response Code $ci - $http_rs and
error $http_err \n");
                if (!$http_ok){
                        sl_reply("503", "No Connection to HTTP");
                        exit;
                }else if ($http_rs>=500){
                        sl_reply("503", "HTTP Processing Error");
                        exit;
                }
                else{
                        sl_reply("503", "Cannot Connect to HTTP");
                        exit;
                }
    }
    exit;
}
The configuration is based on Ben Kaufman's kamailio_http_async
https://github.com/whosgonna/kamailio_http_async example, but I have
extended it a bit.
Currently all the requests are being sent to the HTTP REST API. I can't
find queue/buffering issues...
What I am experiencing is that , using SNGREP, I get this flow:
10.240.12.209:5060            10.242.17.146:5060
        ----------*----------         ----------*----------
17:33:46.689852   x        INVITE (SDP)         x
      +0.000530   x --------------------------> x
17:33:46.690382   x  100 trying -- your call is x
      +1.499822   x <-------------------------- x
17:33:48.190204   x  503 No Connection to HTTP  x
      +0.000029   x <-------------------------- x
17:33:48.190233   x  500 I'm terribly sorry, se x
      +0.002130   x <-------------------------- x
17:33:48.192363   x             ACK             x
      +0.485836   x --------------------------> x
17:33:48.678199   x  500 I'm terribly sorry, se x
      +0.004881   x <<<------------------------ x
17:33:48.683080   x             ACK             x
      +0.973295   x ------------------------>>> x
17:33:49.656375   x  500 I'm terribly sorry, se x
      +0.004105   x <<<------------------------ x
17:33:49.660480   x             ACK             x
      +1.995420   x ------------------------>>> x
17:33:51.655900   x  500 I'm terribly sorry, se x
      +0.005361   x <<<-------------------------x
17:33:51.661261   x             ACK             x
                  x ------------------------>>> x
I suspected issues with the HTTP REST service, but when using tcpdump, I
can find the Request from Kamailio and a reply back from the REST API
service, so doesn't seem to be a problem on the HTTP REST service
So my questions are:
- why is Kamailio sending a "SIP 500 I'm terribly sorry..." error after a
503 No Connection to HTTP is sent and an "exit" command is executed?
- how can I get rid of these messages?
- Why Kamailio keeps sending responses back to SBC after the ACK when it is
set to just "exit"?
- Why is Kamailio not processing the response from HTTP REST API when it is
correctly received?
Logs are also weird:
- I find a lot of these warnings:
"Dec 29 17:38:34 ire-nprod-sip1 /usr/local/sbin/kamailio[590864]: WARNING:
http_async_client [http_async_client_mod.c:529]: ah_get_status(): an async
variable was read after http error, use $http_ok to check the request's
status"
and
"Dec 29 17:38:34 ire-nprod-sip1 /usr/local/sbin/kamailio[590864]: ERROR:
http_async_client [http_multi.c:621]: check_multi_info(): handle
0x7f375f786b30 returned error 7:"
(I am still not using EVAPI module, that will be my next step, after the
holiday season)
(I suspect, however, that the REST API is not being able to handle the load
in this test environment (between 400 to 600 CAPS), but that is another
matter.)
In attach, TCPDUMP, if anyone wishes to analyse.
Atenciosamente / Kind Regards / Cordialement / Un saludo,
*Sérgio Charrua*