<!-- Kamailio Project uses GitHub Issues only for bugs in the code or feature requests.
If you have questions about using Kamailio or related to its configuration file, ask on sr-users mailing list:
* http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
If you have questions about developing extensions to Kamailio or its existing C code, ask on sr-dev mailing list
* http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
Please try to fill this template as much as possible for any issue. It helps the developers to troubleshoot the issue.
If you submit a feature request (or enhancement), you can delete the text of the template and only add the description of what you would like to be added.
If there is no content to be filled in a section, the entire section can be removed.
You can delete the comments from the template sections when filling.
You can delete next line and everything above before submitting (it is a comment). -->
### Description When using http_async_client, I'm getting the following error:
Nov 28 08:18:49 tm-kamailio-ingress kamailio[24612]: 3(24635) : <core> [core/mem/q_malloc.c:483]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f62e75130c0), called from http_async_client: async_http.c: set_query_params(616), first free http_async_client: async_http.h: free_async_query(142) - aborting
<!-- Explain what you did, what you expected to happen, and what actually happened. -->
### Troubleshooting
#### Reproduction
route[REQUEST_PERMISSIONS] { $var(body) = 0; jansson_set("string", "from", "$fU", "$var(body)"); jansson_set("string", "to", "$tU", "$var(body)"); $http_req(all) = $null;
$http_req(method) = "POST";
$http_req(hdr) = "Content-Type: application/json"; $http_req(hdr) = "Accept: application/json"; $http_req(hdr) = "Connection: keep-alive";
$http_req(body) = $var(body);
$var(re_url)= "localhost:3000/v1/mock/makeCall";
if (http_async_query("$var(re_url)", "REQUEST_PERMISSIONS_REPLY") < 0) { t_reply("500", "Server Internal Error"); exit; } }
<!-- If the issue can be reproduced, describe how it can be done. -->
#### Debugging Data
<!-- If you got a core dump, use gdb to extract troubleshooting data - full backtrace, local variables and the list of the code at the issue location.
gdb /path/to/kamailio /path/to/corefile bt full info locals list
If you are familiar with gdb, feel free to attach more of what you consider to be relevant. -->
``` (paste your debugging data here) ```
#### Log Messages
<!-- Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` (paste your log messages here) ```
#### SIP Traffic
<!-- If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` (paste your sip traffic here) ```
### Possible Solutions
<!-- If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix. -->
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
``` (paste your output here) ```
* **Operating System**:
<!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `uname -a`) -->
``` (paste your output here) ```
Could please provide more logs (possible at debug level) and a description of when this happens? Always? upon a failure? In the http reply route? Also, not related, I see that in $var(re_url) you are missing "http://".
Attached
From: Federico Cabiddu notifications@github.com Reply-To: kamailio/kamailio reply@reply.github.com Date: Tuesday, 28 November 2017 at 10:42 To: kamailio/kamailio kamailio@noreply.github.com Cc: arik arik.halperin@gmail.com, Author author@noreply.github.com Subject: Re: [kamailio/kamailio] http_async_client frees pointer twice(Kamailio 5.0.4) (#1340)
Could please provide more logs (possible at debug level) and a description of when this happens? Always? upon a failure? In the http reply route? Also, not related, I see that in $var(re_url) you are missing "http://".
— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or mute the thread.
Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 46, 4, 0x7fe0ddbbc708), fd_no=15 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 50, 4, 0x7fe0ddbbc794), fd_no=16 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 54, 4, 0x7fe0ddbbc820), fd_no=17 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 58, 4, 0x7fe0ddbbc8ac), fd_no=18 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 62, 4, 0x7fe0ddbbc938), fd_no=19 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 66, 4, 0x7fe0ddbbc9c4), fd_no=20 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 70, 4, 0x7fe0ddbbca50), fd_no=21 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 71, 4, 0x7fe0ddbbcadc), fd_no=22 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 72, 4, 0x7fe0ddbbcb68), fd_no=23 Nov 28 08:46:19 tm-kamailio-ingress kamailio[875]: 26(940) DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa4eb40, 73, 4, 0x7fe0ddbbcbf4), fd_no=24 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:600]: parse_msg(): SIP Request: Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:602]: parse_msg(): method: <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): uri: sip:138.197.183.92:5099 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): version: <SIP/2.0> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjAwS7kvUGVJxZEzvLNzmwJf4AN43bYSnn>; state=16 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:491]: parse_headers(): Via found, flags=2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:493]: parse_headers(): this is the first via Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [27]; uri=[sip:1004@138.197.183.92] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [sip:1004@138.197.183.92 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: ] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <28636> <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/receive.c:186]: receive_msg(): --- received sip message - request - call-id: [Tur2OzFG4u2Gmf.9TTWPx5hjyv6YbDoq] - cseq: [28636 REGISTER] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/receive.c:234]: receive_msg(): preparing to run routing scripts... Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=485 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=619 a=25 n=mf_process_maxfwd_header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: maxfwd [mf_funcs.c:76]: is_maxfwd_present(): value = 70 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=633 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=26 n=sanity_check Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=G.Lmpz.KMTY-9-Tp7YDRBTxzKBuqxKZZ Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=487 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ALERT: <script>: PSTN Destination is :<null> Walla!!! Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=489 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=492 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=815 a=55 n=force_rport Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=816 a=25 n=nat_uac_test Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (82.80.164.63, 10.0.0.28, 0) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=823 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=817 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=818 a=24 n=fix_nated_register Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=824 a=39 n=setflag Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=494 a=25 n=is_present_hf Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=509 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=504 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ERROR: <script>: 1111 Routing to register 1(895) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=505 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1030 a=25 n=save Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-37f-1] (1 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-37f-1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-37f-2] (2 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-37f-2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: registrar [reply.c:377]: build_contact(): created Contact HF: Contact: sip:1004@82.80.164.63:44927;ob;expires=163;received="sip:82.80.164.63:44927", sip:1004@10.0.0.28:44927;ob;expires=300;received="sip:82.80.164.63:44927" Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1039 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ERROR: <script>: 1111 PUSHJOIN 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1040 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1041 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ERROR: <script>: 1111 locking 1004 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1042 a=25 n=lock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 0 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1043 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ERROR: <script>: 1111 Getting vars 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1044 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1045 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1046 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ERROR: <script>: 1111 tU=1004 0 0 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1047 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: htable [ht_var.c:89]: pv_set_ht_cell(): set value for $sht(vtp=>join::1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1048 a=25 n=unlock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 1 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1056 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1051 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) ERROR: <script>: 1111 ts_append location 1004 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1033 a=2 n=exit Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/receive.c:275]: receive_msg(): request-route executed in: 1003 usec Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list 0x7fe0ddbf8330 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: message repeated 4 times: [ 1(895) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil)] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 1(895) DEBUG: <core> [core/receive.c:364]: receive_msg(): cleaning up Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:600]: parse_msg(): SIP Request: Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:602]: parse_msg(): method: <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): uri: sip:138.197.183.92:5099 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): version: <SIP/2.0> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjy.9YUHv9K0zq6Qz8AKdFk-r01iE4pNMC>; state=16 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:491]: parse_headers(): Via found, flags=2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:493]: parse_headers(): this is the first via Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [27]; uri=[sip:1004@138.197.183.92] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [sip:1004@138.197.183.92 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: ] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <28637> <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/receive.c:186]: receive_msg(): --- received sip message - request - call-id: [Tur2OzFG4u2Gmf.9TTWPx5hjyv6YbDoq] - cseq: [28637 REGISTER] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/receive.c:234]: receive_msg(): preparing to run routing scripts... Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=485 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=619 a=25 n=mf_process_maxfwd_header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: maxfwd [mf_funcs.c:76]: is_maxfwd_present(): value = 70 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=633 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=26 n=sanity_check Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=XgTDfqhjtcTotD3jDPFxsO2ppY7S-m8E Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=487 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ALERT: <script>: PSTN Destination is :<null> Walla!!! Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=489 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=492 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=815 a=55 n=force_rport Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=816 a=25 n=nat_uac_test Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (82.80.164.63, 10.0.0.28, 0) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=823 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=817 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=818 a=24 n=fix_nated_register Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=824 a=39 n=setflag Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=494 a=25 n=is_present_hf Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=509 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=504 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ERROR: <script>: 1111 Routing to register 2(896) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=505 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1030 a=25 n=save Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-380-1] (1 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-380-1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-380-2] (2 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-380-2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-380-3] (3 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-380-3 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: registrar [reply.c:377]: build_contact(): created Contact HF: Contact: sip:1004@82.80.164.63:44927;ob;expires=300;received="sip:82.80.164.63:44927" Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1039 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ERROR: <script>: 1111 PUSHJOIN 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1040 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1041 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ERROR: <script>: 1111 locking 1004 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1042 a=25 n=lock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 0 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1043 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ERROR: <script>: 1111 Getting vars 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1044 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1045 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1046 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ERROR: <script>: 1111 tU=1004 0 0 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1047 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: htable [ht_var.c:89]: pv_set_ht_cell(): set value for $sht(vtp=>join::1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1048 a=25 n=unlock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 1 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1056 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1051 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) ERROR: <script>: 1111 ts_append location 1004 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1033 a=2 n=exit Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/receive.c:275]: receive_msg(): request-route executed in: 916 usec Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list 0x7fe0ddbf8330 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: message repeated 4 times: [ 2(896) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil)] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 2(896) DEBUG: <core> [core/receive.c:364]: receive_msg(): cleaning up Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:600]: parse_msg(): SIP Request: Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:602]: parse_msg(): method: <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): uri: sip:138.197.183.92:5099 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): version: <SIP/2.0> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjxhu8S1NJyydfxy.gwPrfe.Vr10wihm5q>; state=16 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:491]: parse_headers(): Via found, flags=2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:493]: parse_headers(): this is the first via Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [27]; uri=[sip:1004@138.197.183.92] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [sip:1004@138.197.183.92 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: ] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <28638> <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/receive.c:186]: receive_msg(): --- received sip message - request - call-id: [Tur2OzFG4u2Gmf.9TTWPx5hjyv6YbDoq] - cseq: [28638 REGISTER] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/receive.c:234]: receive_msg(): preparing to run routing scripts... Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=485 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=619 a=25 n=mf_process_maxfwd_header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: maxfwd [mf_funcs.c:76]: is_maxfwd_present(): value = 70 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=633 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=26 n=sanity_check Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=5.O8JiVt-kHYaFKlgIlmNXnLKirX8K1X Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=487 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ALERT: <script>: PSTN Destination is :<null> Walla!!! Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=489 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=492 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=815 a=55 n=force_rport Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=816 a=25 n=nat_uac_test Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (82.80.164.63, 10.0.0.28, 0) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=823 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=817 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=818 a=24 n=fix_nated_register Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=824 a=39 n=setflag Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=494 a=25 n=is_present_hf Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=509 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=504 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ERROR: <script>: 1111 Routing to register 4(898) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=505 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1030 a=25 n=save Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-382-1] (1 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-382-1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-382-2] (2 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-382-2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1039 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ERROR: <script>: 1111 PUSHJOIN 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1040 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1041 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ERROR: <script>: 1111 locking 1004 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1042 a=25 n=lock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 0 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1043 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ERROR: <script>: 1111 Getting vars 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1044 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1045 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1046 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ERROR: <script>: 1111 tU=1004 0 0 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1047 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: htable [ht_var.c:89]: pv_set_ht_cell(): set value for $sht(vtp=>join::1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1048 a=25 n=unlock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 1 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1056 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1051 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) ERROR: <script>: 1111 ts_append location 1004 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1033 a=2 n=exit Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/receive.c:275]: receive_msg(): request-route executed in: 699 usec Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list 0x7fe0ddbf8330 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: message repeated 4 times: [ 4(898) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil)] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 4(898) DEBUG: <core> [core/receive.c:364]: receive_msg(): cleaning up Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:600]: parse_msg(): SIP Request: Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:602]: parse_msg(): method: <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): uri: sip:138.197.183.92:5099 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): version: <SIP/2.0> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjDWS8IcXcvUNOnJUhXXMw-KGgm2hzFpx6>; state=16 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:491]: parse_headers(): Via found, flags=2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:493]: parse_headers(): this is the first via Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [27]; uri=[sip:1004@138.197.183.92] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [sip:1004@138.197.183.92 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: ] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <64607> <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/receive.c:186]: receive_msg(): --- received sip message - request - call-id: [Cjbi-NxKv7jmg8-AUJMnectUWIUgz7i4] - cseq: [64607 REGISTER] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/receive.c:234]: receive_msg(): preparing to run routing scripts... Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=485 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=619 a=25 n=mf_process_maxfwd_header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: maxfwd [mf_funcs.c:76]: is_maxfwd_present(): value = 70 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=633 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=26 n=sanity_check Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=I9AB-K-2W1QbfB9xq1AFnCUo2v0TAuEW Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=487 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ALERT: <script>: PSTN Destination is :<null> Walla!!! Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=489 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=492 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=815 a=55 n=force_rport Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=816 a=25 n=nat_uac_test Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (82.80.164.63, 10.0.0.28, 0) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=823 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=817 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=818 a=24 n=fix_nated_register Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=824 a=39 n=setflag Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=494 a=25 n=is_present_hf Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=509 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=504 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ERROR: <script>: 1111 Routing to register 3(897) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=505 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1030 a=25 n=save Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-381-1] (1 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-381-1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-381-2] (2 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-381-2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: registrar [reply.c:377]: build_contact(): created Contact HF: Contact: sip:1004@10.0.0.28:44927;ob;expires=300;received="sip:82.80.164.63:44927" Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1039 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ERROR: <script>: 1111 PUSHJOIN 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1040 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1041 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ERROR: <script>: 1111 locking 1004 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1042 a=25 n=lock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 0 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1043 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ERROR: <script>: 1111 Getting vars 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1044 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1045 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1046 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ERROR: <script>: 1111 tU=1004 0 0 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1047 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: htable [ht_var.c:89]: pv_set_ht_cell(): set value for $sht(vtp=>join::1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1048 a=25 n=unlock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 1 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1056 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1051 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) ERROR: <script>: 1111 ts_append location 1004 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1054 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1033 a=2 n=exit Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/receive.c:275]: receive_msg(): request-route executed in: 871 usec Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list 0x7fe0ddbf8330 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: message repeated 4 times: [ 3(897) DEBUG: <core> [core/usr_avp.c:631]: destroy_avp_list(): destroying list (nil)] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 3(897) DEBUG: <core> [core/receive.c:364]: receive_msg(): cleaning up Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:600]: parse_msg(): SIP Request: Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:602]: parse_msg(): method: <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): uri: sip:138.197.183.92:5099 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): version: <SIP/2.0> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjdYeHjHbPlejp7Tx7ZNXGoyerlhQ3Jmqg>; state=16 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:491]: parse_headers(): Via found, flags=2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:493]: parse_headers(): this is the first via Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [27]; uri=[sip:1004@138.197.183.92] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [sip:1004@138.197.183.92 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: ] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <64608> <REGISTER> Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/receive.c:186]: receive_msg(): --- received sip message - request - call-id: [Cjbi-NxKv7jmg8-AUJMnectUWIUgz7i4] - cseq: [64608 REGISTER] Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/receive.c:234]: receive_msg(): preparing to run routing scripts... Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=485 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=619 a=25 n=mf_process_maxfwd_header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: maxfwd [mf_funcs.c:76]: is_maxfwd_present(): value = 70 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=624 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=633 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REQINIT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=629 a=26 n=sanity_check Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=Mxea3NowuFKGt5aiXRFWbC-jZgnJcqDR Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=487 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) ALERT: <script>: PSTN Destination is :<null> Walla!!! Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=489 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=492 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=815 a=55 n=force_rport Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=816 a=25 n=nat_uac_test Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (82.80.164.63, 10.0.0.28, 0) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=823 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=817 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=818 a=24 n=fix_nated_register Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=824 a=39 n=setflag Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[NATDETECT] c=[/usr/local/etc/kamailio/kamailio.cfg] l=827 a=2 n=return Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=494 a=25 n=is_present_hf Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=509 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=503 a=25 n=is_method Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=504 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) ERROR: <script>: 1111 Routing to register 5(899) exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio/kamailio.cfg] l=505 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=16 n=if Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1030 a=25 n=save Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-383-1] (1 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-383-1 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-383-2] (2 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-383-2 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5a1d225b-383-3] (3 / 19) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5a1d225b-383-3 Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: registrar [reply.c:377]: build_contact(): created Contact HF: Contact: sip:1004@82.80.164.63:44927;ob;expires=300;received="sip:82.80.164.63:44927" Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[REGISTER] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1032 a=5 n=route Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1039 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) ERROR: <script>: 1111 PUSHJOIN 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1040 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1041 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) ERROR: <script>: 1111 locking 1004 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1042 a=25 n=lock Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) DEBUG: cfgutils [cfgutils.c:661]: cfg_lock_helper(): cfg_lock mode 0 on 535 (1004) Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1043 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) ERROR: <script>: 1111 Getting vars 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1044 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1045 a=63 n=assign Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) exec: *** cfgtrace:request_route=[PUSHJOIN] c=[/usr/local/etc/kamailio/kamailio.cfg] l=1046 a=26 n=xlog Nov 28 08:46:43 tm-kamailio-ingress kamailio[875]: 5(899) ERROR: <script>: 1111 tU=1004 0 0 5(899) exec: *** cfgtrace:request_route=[PUSH
This only happens with 8 workers and above. So I tried to increase the amount of memory from 64M to 128M (-m 128 instead of -m 64). Now I can use 10 workers and it doesn't crash. So there is a high probability this issue is due to lack of memory and that somewhere an allocation fails and it's not reported.
We're having the same issue with only one worker ``` kamcmd> core.info { version: kamailio 5.0.5 id: unknown compiler: gcc 4.8.2 compiled: flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES } ``` ``` Dec 21 05:20:31 kamailio-1889-0 kamailio[4096]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foerdc.query.consul:8088/' - ci='33bac93114af7fba0dc7e57382a1e9f4' Dec 21 05:20:31 kamailio-1889-0 kamailio[4096]: : <core> [core/mem/q_malloc.c:483]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f01641853a0), called from http_async_client: async_http.c: set_query_params(633), first free http_async_client: http_multi.c: curl_shm_free (334) - aborting Dec 21 05:20:31 kamailio-1889-0 kamailio[4142]: CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 58 ``` I've enabled debug log will try to add more info later
@grumvalski will this fix this issue? ``` --- a/src/modules/http_async_client/http_multi.c +++ b/src/modules/http_async_client/http_multi.c @@ -330,8 +330,10 @@ static void *curl_shm_malloc(size_t size) } static void curl_shm_free(void *ptr) { - if (ptr) + if (ptr) { shm_free(ptr); + ptr = NULL; + } }
static void *curl_shm_realloc(void *ptr, size_t size) ```
@linuxmaniac - that is not solving it, setting ptr to NULL is effective only inside the curl_shm_free().
To me it looks like some pointers that are given to a CURL function, which is going to free them at some point, are also freed inside http_async_client module. Not that familiar with the code, but I think some of the `shm_free(`) inside `set_query_params()` should not be done. I guess that the fix is in the direction of: when a field from `struct query_params` is given to a CURL function, it should be set to `NULL` so `set_query_params()` doesn't free it again. Now, identifying when the field is given to a CURL function requires to look deeper a the code of the module, not being familiar with, I couldn't do it quickly and no much spare time here at this moment.
Daniel, Hello,
Thanks for the insight. I’ll look into it sometime next week. Hopefully I can resolve.
Arik
From: Daniel-Constantin Mierla notifications@github.com Reply-To: kamailio/kamailio reply@reply.github.com Date: Thursday, 21 December 2017 at 17:37 To: kamailio/kamailio kamailio@noreply.github.com Cc: arik arik.halperin@gmail.com, Author author@noreply.github.com Subject: Re: [kamailio/kamailio] http_async_client frees pointer twice(Kamailio 5.0.4) (#1340)
@linuxmaniac - that is not solving it, setting ptr to NULL is effective only inside the curl_shm_free().
To me it looks like some pointers that are given to a CURL function, which is going to free them at some point, are also freed inside http_async_client module. Not that familiar with the code, but I think some of the shm_free() inside set_query_params() should not be done. I guess that the fix is in the direction of: when a field from struct query_params is given to a CURL function, it should be set to NULL so set_query_params() doesn't free it again. Now, identifying when the field is given to a CURL function requires to look deeper a the code of the module, not being familiar with, I couldn't do it quickly and no much spare time here at this moment.
— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or mute the thread.
Some debug output just before the crash ``` Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: SET_QUEUE_STATUS: user='1018-customer0000' - ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foerdc.query.consul:8088/' - ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'AriFoehnUser' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'passwordfake0' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [async_http.c:578]: async_push_query(): query sent [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) to worker 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: SET_QUEUE_STATUS: Device='1018-customer0000' to be enabled req_id=39875-1076 ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:348]: notification_socket_cb(): query received: [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... with timeout 100, tls_verify_peer 0, tls_verify_host 0 (param=0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f4b57acaff8 to table 0x7f4b57463150 [922] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:523]: new_request(): set username to AriFoehnUser [authmethod 1] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x7f4b57e47c20 to multi 0x7f4b574361e0 (http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e47c20 what=IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 --- Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 23: action 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 200 OK#015#012 [17] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Asterisk/13.17.0#015#012 [26] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012 [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Cache-Control: no-cache, no-store#015#012 [35] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-type: application/json#015#012 [32] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 57#015#012 [20] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"state":"UNAVAILABLE","name":"Custom:1018-customer0000"} [57] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e47c20 what=REMOVE Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0xca8d80 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 23 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... => (0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:135]: async_http_cb(): query result = HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: application/json#015#012Content-Length: 57#015#012#015#012{"state":"UNAVAILABLE","name":"Custom:1018-customer0000"} [226] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:187]: async_http_cb(): successfully parsed http reply 0x7f4b684e20c0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: INFO: <script>: QUEUE_CHECK_STATUS_OR_SET QueueDevice='1018-customer0000' is in state='UNAVAILABLE' req_id=39875-1076 ci='123' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: SET_QUEUE_STATUS: user='1016-customer0000' - ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:578]: async_push_query(): query sent [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl...] (0x7f4b57a3fde0) to worker 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.h:133]: free_async_query(): freeing query 0x7f4b57bc6488 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [200] HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: ap plication/json#015#012Content-Length: 57#015#012#015#012{"state":"UNAVAILABLE","name":"Custom:1018-customer0000"} [226] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f4b57acaff8 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x7f4b57e47c20 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to -1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:147]: event_cb(): last transfer done, kill timeout Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:348]: notification_socket_cb(): query received: [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl...] (0x7f4b57a3fde0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl... with timeout 10000, tls_verify_peer 0, tls_verify_host 0 (param=0x7f4b57a3fde0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foerdc.query.consul:8088/' - ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'AriFoehnUser' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'passwordfake0' --- Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f4b57acaff8 to table 0x7f4b57463150 [922] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x7f4b57e47c20 to multi 0x7f4b574361e0 (http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl...) Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [async_http.c:578]: async_push_query(): query sent [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) to worker 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: SET_QUEUE_STATUS: Device='1016-customer0000' to be enabled req_id=39867-1065 ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:348]: notification_socket_cb(): query received: [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... with timeout 100, tls_verify_peer 0, tls_verify_host 0 (param=0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f4b57c32a08 to table 0x7f4b57463150 [51] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:523]: new_request(): set username to AriFoehnUser [authmethod 1] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x7f4b57e3ef20 to multi 0x7f4b574361e0 (http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e3ef20 what=IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 2 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 23: action 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 200 OK#015#012 [17] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Asterisk/13.17.0#015#012 [26] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012 [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Cache-Control: no-cache, no-store#015#012 [35] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-type: application/json#015#012 [32] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 55#015#012 [20] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"state":"NOT_INUSE","name":"Custom:1016-customer0000"} [55] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 --- Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e3ef20 what=REMOVE Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0xca8d80 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 23 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... => (0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:135]: async_http_cb(): query result = HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: app lication/json#015#012Content-Length: 55#015#012#015#012{"state":"NOT_INUSE","name":"Custom:1016-customer0000"} [224] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:187]: async_http_cb(): successfully parsed http reply 0x7f4b684e20c0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: INFO: <script>: QUEUE_CHECK_STATUS_OR_SET QueueDevice='1016-customer0000' is in state='NOT_INUSE' req_id=39867-1065 ci='123' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.h:133]: free_async_query(): freeing query 0x7f4b57bc6488 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [200] HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: ap plication/json#015#012Content-Length: 55#015#012#015#012{"state":"NOT_INUSE","name":"Custom:1016-customer0000"} [224] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f4b57c32a08 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x7f4b57e3ef20 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39847]: INFO: <script>: default onreply_route ci='4d37030636fbea05-39875@127.0.0.1' from='sip:1018-customer0000@sip.serverfake.com' to='<null>' method='REGISTER' status='200 src='172.18.241.29:5080' Dec 21 17:17:02 kamailio-1889-0 kamailio[39857]: INFO: <script>: from NAT address rm='NOTIFY' ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' Dec 21 17:17:02 kamailio-1889-0 kamailio[39857]: INFO: <script>: RELAY: method='NOTIFY' ip='172.18.241.29:5080' du='<null>' ru='sip:6B9500CD-5A3BAC99000C4A96-DCE61700@1.2.3.4.5;transport=udp' fu='sip:Unknown@sip.serverfake.com:5080' ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' Dec 21 17:17:02 kamailio-1889-0 kamailio[39857]: INFO: <script>: RELAY_BRANCH rm='NOTIFY' - ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 3 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=25 e=0x7f4b57e47c20 what=OUT Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: OUT Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39851]: INFO: <script>: default onreply_route ci='4d37030636fbe9fb-39867@127.0.0.1' from='sip:1016-customer0000@sip.serverfake.com' to='<null>' method='REGISTER' status='200 src='172.18.241.29:5080' Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: from NAT address rm='NOTIFY' ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 199 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 4 on socket 25: action 2 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 2 on socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=25 e=0x7f4b57e47c20 what=IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:184]: sock_cb(): Changing action from OUT to IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 2 on socket 25 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 25: action 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 401 Unauthorized#015#012 [27] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Asterisk/13.17.0#015#012 [26] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 --- Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) cec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012 [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Cache-Control: no-cache, no-store#015#012 [35] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: tenant=<null> call_type='outbound_b' from='sip:Unknown@sip.serverfake.com:5080' to='sip:1016-customer0000@kamailio-leader.query.consul' ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: WWW-Authenticate: Basic realm="Asterisk REST Interface"#015#012 [57] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-type: application/json#015#012 [32] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 37#015#012 [20] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: RELAY: method='NOTIFY' ip='172.18.241.29:5080' du='<null>' ru='sip:4a64058e38255f44@1.2.3.4.5;transport=udp' fu='sip:Unknown@sip.serverfake.com:5080' ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: RELAY_BRANCH rm='NOTIFY' - ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"message":"Authentication required"} [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=25 e=0x7f4b57e47c20 what=REMOVE Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0xca8d80 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 25 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl... => (0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:135]: async_http_cb(): query result = HTTP/1.1 401 Unauthorized#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012WWW-Aut henticate: Basic realm="Asterisk REST Interface"#015#012Content-type: application/json#015#012Content-Length: 37#015#012#015#012{"message":"Authentication required"} [273] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:187]: async_http_cb(): successfully parsed http reply 0x7f4b684e20c0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: INFO: <script>: HTTP_SET reply correctly req_id='39894-157' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.h:133]: free_async_query(): freeing query 0x7f4b57a3fde0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [401] HTTP/1.1 401 Unauthorized#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012WWW-Authenticate: Basic realm="Asterisk REST Interface"#015#012Content-type: application/json#015#012Content-Length: 37#015#012#015#012{"message":"Authentication required"} [273] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f4b57acaff8 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x7f4b57e47c20 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to -1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:147]: event_cb(): last transfer done, kill timeout Dec 21 17:17:02 kamailio-1889-0 kamailio[39862]: INFO: <script>: default onreply_route ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' from='sip:Unknown@sip.serverfake.com:5080' to='<null>' method='NOTIFY' status='200 src='1.2.3.4.5:5060' Dec 21 17:17:02 kamailio-1889-0 kamailio[39874]: INFO: <script>: default onreply_route ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' from='sip:Unknown@sip.serverfake.com:5080' to='<null>' method='NOTIFY' status='200 src='1.2.3.4.5:5060' Dec 21 17:17:05 kamailio-1889-0 kamailio[39866]: ERROR: <script>: auth_challenge error '-4' fu='sip:200-eloy@sip.serverfake.com' ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: INFO: <script>: SET_QUEUE_STATUS: user='200-eloy' - ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foeedc.query.consul' b='asterisk-green-profile1-foerdc.query.consul' c='asterisk-blue-profile1-foeedc.query.consul' d='asterisk-blue-profile1-foerdc.query.consul' ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foeedc.query.consul:8088/' - ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'AriFoehnUser' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'passwordfake0' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: : <core> [core/mem/q_malloc.c:483]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f4b573fb7c8), called from http_async_client: async_http.c: set_query_params(633), first free http_async_client: http_multi.c: curl_shm_free(334) - aborting Dec 21 17:17:11 kamailio-1889-0 kamailio[39911]: CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 70 Dec 21 17:17:11 kamailio-1889-0 kamailio[39829]: ALERT: <core> [main.c:743]: handle_sigs(): child process 39877 exited by a signal 6 ```
Hi, thanks all for looking at it. I'm relocating in these days, I'll have a look once I'm established and I have internet back.
Federico
On 22 Dec 2017 10:42, "Victor Seva" notifications@github.com wrote:
Some debug output just before the crash
Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: SET_QUEUE_STATUS: user='1018-customer0000' - ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foerdc.query.consul:8088/' - ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'AriFoehnUser' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'passwordfake0' Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: DEBUG: http_async_client [async_http.c:578]: async_push_query(): query sent [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) to worker 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: SET_QUEUE_STATUS: Device='1018-customer0000' to be enabled req_id=39875-1076 ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:348]: notification_socket_cb(): query received: [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... with timeout 100, tls_verify_peer 0, tls_verify_host 0 (param=0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f4b57acaff8 to table 0x7f4b57463150 [922] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:523]: new_request(): set username to AriFoehnUser [authmethod 1] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x7f4b57e47c20 to multi 0x7f4b574361e0 (http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39875]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='89374MDk1OWQxYjk0MDFmYzg3MmU3MDA5NjcyMDI3NTRmNDI' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e47c20 what=IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012
Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 23: action 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 200 OK#015#012 [17] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Asterisk/13.17.0#015#012 [26] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012 [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Cache-Control: no-cache, no-store#015#012 [35] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-type: application/json#015#012 [32] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 57#015#012 [20] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"state":"UNAVAILABLE","name":"Custom:1018-customer0000"} [57] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e47c20 what=REMOVE Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0xca8d80 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 23 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... => (0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:135]: async_http_cb(): query result = HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: application/json#015#012Content-Length: 57#015#012#015#012{"state":"UNAVAILABLE","name":"Custom:1018-customer0000"} [226] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:187]: async_http_cb(): successfully parsed http reply 0x7f4b684e20c0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: INFO: <script>: QUEUE_CHECK_STATUS_OR_SET QueueDevice='1018-customer0000' is in state='UNAVAILABLE' req_id=39875-1076 ci='123' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: SET_QUEUE_STATUS: user='1016-customer0000' - ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:578]: async_push_query(): query sent [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl...] (0x7f4b57a3fde0) to worker 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.h:133]: free_async_query(): freeing query 0x7f4b57bc6488 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [200] HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: ap plication/json#015#012Content-Length: 57#015#012#015#012{"state":"UNAVAILABLE","name":"Custom:1018-customer0000"} [226] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f4b57acaff8 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x7f4b57e47c20 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to -1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:147]: event_cb(): last transfer done, kill timeout Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:348]: notification_socket_cb(): query received: [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl...] (0x7f4b57a3fde0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl... with timeout 10000, tls_verify_peer 0, tls_verify_host 0 (param=0x7f4b57a3fde0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foerdc.query.consul:8088/' - ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'AriFoehnUser' Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'passwordfake0'
Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f4b57acaff8 to table 0x7f4b57463150 [922] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x7f4b57e47c20 to multi 0x7f4b574361e0 (http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl...) Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: DEBUG: http_async_client [async_http.c:578]: async_push_query(): query sent [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) to worker 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: SET_QUEUE_STATUS: Device='1016-customer0000' to be enabled req_id=39867-1065 ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:348]: notification_socket_cb(): query received: [http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...] (0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... with timeout 100, tls_verify_peer 0, tls_verify_host 0 (param=0x7f4b57bc6488) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f4b57c32a08 to table 0x7f4b57463150 [51] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:523]: new_request(): set username to AriFoehnUser [authmethod 1] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x7f4b57e3ef20 to multi 0x7f4b574361e0 (http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus...) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39867]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foerdc.query.consul' b='asterisk-green-profile1-foeedc.query.consul' c='asterisk-blue-profile1-foerdc.query.consul' d='asterisk-blue-profile1-foeedc.query.consul' ci='85992MDU2ODE1ZjZkOGI5OTM3ZDAxODBhZWE1MGQwNjkwNzc' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e3ef20 what=IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 2 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 23: action 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 23 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 200 OK#015#012 [17] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Asterisk/13.17.0#015#012 [26] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012 [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Cache-Control: no-cache, no-store#015#012 [35] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-type: application/json#015#012 [32] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 55#015#012 [20] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"state":"NOT_INUSE","name":"Custom:1016-customer0000"} [55] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51
Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e3ef20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=23 e=0x7f4b57e3ef20 what=REMOVE Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0xca8d80 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 23 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://asterisk-green-profile1-foerdc.query.consul:8088/ari/deviceStates/Cus... => (0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e3ef20 (8)-> 0x7f4b57e3ef20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e3ef20 is 51 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e3ef20 found on table entry 51#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:135]: async_http_cb(): query result = HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: app lication/json#015#012Content-Length: 55#015#012#015#012{"state":"NOT_INUSE","name":"Custom:1016-customer0000"} [224] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:187]: async_http_cb(): successfully parsed http reply 0x7f4b684e20c0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: INFO: <script>: QUEUE_CHECK_STATUS_OR_SET QueueDevice='1016-customer0000' is in state='NOT_INUSE' req_id=39867-1065 ci='123' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.h:133]: free_async_query(): freeing query 0x7f4b57bc6488 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [200] HTTP/1.1 200 OK#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012Content-type: ap plication/json#015#012Content-Length: 55#015#012#015#012{"state":"NOT_INUSE","name":"Custom:1016-customer0000"} [224] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f4b57c32a08 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x7f4b57e3ef20 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39847]: INFO: <script>: default onreply_route ci='4d37030636fbea05-39875@127.0.0.1' from='sip:1018-customer0000@sip.serverfake.com' to='<null>' method='REGISTER' status='200 src='172.18.241.29:5080' Dec 21 17:17:02 kamailio-1889-0 kamailio[39857]: INFO: <script>: from NAT address rm='NOTIFY' ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' Dec 21 17:17:02 kamailio-1889-0 kamailio[39857]: INFO: <script>: RELAY: method='NOTIFY' ip='172.18.241.29:5080' du='<null>' ru='sip:6B9500CD-5A3BAC99000C4A96-DCE61700@1.2.3.4.5;transport=udp' fu='sip:Unknown@sip.serverfake.com:5080' ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' Dec 21 17:17:02 kamailio-1889-0 kamailio[39857]: INFO: <script>: RELAY_BRANCH rm='NOTIFY' - ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 3 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=25 e=0x7f4b57e47c20 what=OUT Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: OUT Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39851]: INFO: <script>: default onreply_route ci='4d37030636fbe9fb-39867@127.0.0.1' from='sip:1016-customer0000@sip.serverfake.com' to='<null>' method='REGISTER' status='200 src='172.18.241.29:5080' Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: from NAT address rm='NOTIFY' ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 199 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 4 on socket 25: action 2 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 2 on socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=25 e=0x7f4b57e47c20 what=IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:184]: sock_cb(): Changing action from OUT to IN Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0xca8d80 to socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 2 on socket 25 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 25: action 1 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 25 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 401 Unauthorized#015#012 [27] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Asterisk/13.17.0#015#012 [26] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012
Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) cec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012 [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Cache-Control: no-cache, no-store#015#012 [35] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: tenant=<null> call_type='outbound_b' from='sip:Unknown@sip.serverfake.com:5080' to='sip:1016-customer0000@kamailio-leader.query.consul' ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: WWW-Authenticate: Basic realm="Asterisk REST Interface"#015#012 [57] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-type: application/json#015#012 [32] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 37#015#012 [20] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: RELAY: method='NOTIFY' ip='172.18.241.29:5080' du='<null>' ru='sip:4a64058e38255f44@1.2.3.4.5;transport=udp' fu='sip:Unknown@sip.serverfake.com:5080' ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39849]: INFO: <script>: RELAY_BRANCH rm='NOTIFY' - ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"message":"Authentication required"} [37] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x7f4b57e47c20) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=25 e=0x7f4b57e47c20 what=REMOVE Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0xca8d80 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 25 performed Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://asterisk-green-profile1-foerdc.query.consul:8088/ari/asterisk/variabl... => (0) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x7f4b57e47c20 (8)-> 0x7f4b57e47c20 (14) Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x7f4b57e47c20 is 922 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x7f4b57e47c20 found on table entry 922#012 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:135]: async_http_cb(): query result = HTTP/1.1 401 Unauthorized#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012WWW-Aut henticate: Basic realm="Asterisk REST Interface"#015#012Content-type: application/json#015#012Content-Length: 37#015#012#015#012{"message":"Authentication required"} [273] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.c:187]: async_http_cb(): successfully parsed http reply 0x7f4b684e20c0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: INFO: <script>: HTTP_SET reply correctly req_id='39894-157' Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [async_http.h:133]: free_async_query(): freeing query 0x7f4b57a3fde0 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [401] HTTP/1.1 401 Unauthorized#015#012Server: Asterisk/13.17.0#015#012Date: Thu, 21 Dec 2017 17:17:02 GMT#015#012Cache-Control: no-cache, no-store#015#012WWW-Authenticate: Basic realm="Asterisk REST Interface"#015#012Content-type: application/json#015#012Content-Length: 37#015#012#015#012{"message":"Authentication required"} [273] Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f4b57acaff8 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x7f4b57e47c20 Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to -1 ms Dec 21 17:17:02 kamailio-1889-0 kamailio[39894]: DEBUG: http_async_client [http_multi.c:147]: event_cb(): last transfer done, kill timeout Dec 21 17:17:02 kamailio-1889-0 kamailio[39862]: INFO: <script>: default onreply_route ci='2f7392ee04d01c7f1ca209d4268a9e87@sip.serverfake.com' from='sip:Unknown@sip.serverfake.com:5080' to='<null>' method='NOTIFY' status='200 src='1.2.3.4.5:5060' Dec 21 17:17:02 kamailio-1889-0 kamailio[39874]: INFO: <script>: default onreply_route ci='89374MTk0MmI1OGYyYWVmNTUwYmEwZmM3OGFmZGNlNjdjOTk' from='sip:Unknown@sip.serverfake.com:5080' to='<null>' method='NOTIFY' status='200 src='1.2.3.4.5:5060' Dec 21 17:17:05 kamailio-1889-0 kamailio[39866]: ERROR: <script>: auth_challenge error '-4' fu='sip:200-eloy@sip.serverfake.com' ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: INFO: <script>: SET_QUEUE_STATUS: user='200-eloy' - ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: INFO: <script>: set dispatch to a='asterisk-green-profile1-foeedc.query.consul' b='asterisk-green-profile1-foerdc.query.consul' c='asterisk-blue-profile1-foeedc.query.consul' d='asterisk-blue-profile1-foerdc.query.consul' ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: INFO: <script>: Device State URL is 'http://asterisk-green-profile1-foeedc.query.consul:8088/' - ci='84929NTkyYzNmMWFmZDc3NDQ1MGZhN2NhOTM5N2JkOWI1YmQ' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'AriFoehnUser' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: DEBUG: http_async_client [http_async_client_mod.c:476]: set_query_cparam(): param set to 'passwordfake0' Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: DEBUG: http_async_client [async_http.c:411]: async_send_query(): no pre-existing transaction, switching to transaction-less behavior Dec 21 17:17:05 kamailio-1889-0 kamailio[39877]: : <core> [core/mem/q_malloc.c:483]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f4b573fb7c8), called from http_async_client: async_http.c: set_query_params(633), first free http_async_client: http_multi.c: curl_shm_free(334) - aborting Dec 21 17:17:11 kamailio-1889-0 kamailio[39911]: CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 70 Dec 21 17:17:11 kamailio-1889-0 kamailio[39829]: ALERT: <core> [main.c:743]: handle_sigs(): child process 39877 exited by a signal 6
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kamailio/kamailio/issues/1340#issuecomment-353561342, or mute the thread https://github.com/notifications/unsubscribe-auth/ADip439hOVEANuMJB8SLoyPrXeu2F87xks5tC3mNgaJpZM4Qs2oq . ...
Applied fix on production. No crashes so far, it's been 10 hours.
Closed #1340 via 7c61d3f82bd0779a530f921bd69cd4b1b32e4e05.
-
arik -
Daniel-Constantin Mierla
-
Federico Cabiddu
-
Victor Seva