[kamailio/kamailio] kazoo_query causes crash of kamailio (Issue #2922) - sr-dev

6 Nov 2021

<!--
Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please
use this template only for bug reports.

If you have questions about using Kamailio or related to its configuration file, ask on
sr-users mailing list:

  * http://lists.kamailio.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.kamailio.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 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
Found following issue when trying to solve #2895 :
<!--
Explain what you did, what you expected to happen, and what actually happened.
-->
function kazoo_query (as shown in the module's documentation) causes kamailio to
crash.

### Troubleshooting

#### Reproduction
Compile kamailio master-branch from scratch (with module "kazoo" enabled).

Modify kamailio-config with minimal settings required to use function
"kazoo_query":
```
diff /usr/local/etc/kamailio/kamailio.cfg.sample  /usr/local/etc/kamailio/kamailio.cfg
496a497,501
...
  loadmodule "kazoo.so"
 modparam("kazoo", "amqp_connection",
"amqp://guest:guest@rabbitmqhost:5672")
 modparam("kazoo", "node_hostname",
"sipproxy.mydomain.com")
 modparam("kazoo", "pua_mode", 0)
  517a523,533
...
  xlog("SCRIPT: Snipppet from
kazoo_query-documentation:\n");
 $var(amqp_payload_request) = "{'Event-Category' : 'call_event' ,
'Event-Name' : 'query_user_channels_req', 'Realm' : '" +
$fd + "', 'Username' : '" + $fU + "',
'Active-Only' : false }";
 kazoo_encode("$ci", "$var(callid_encoded)");
 $var(amqp_routing_key) = "call.status_req.$var(callid_encoded)";
 if(kazoo_query("callevt", $var(amqp_routing_key), $var(amqp_payload_request),
"$var(amqp_result)")) {
    kazoo_json("$var(amqp_result)", "Channels[0].switch_url",
"$du");
    if($du != $null) {
        xlog("L_INFO", "$ci|log|user channels found redirecting call to
$du");
        return;
    }
 } ```

Start kamailio and register. Kamailio crashes when reaching kazoo_query:

```
Nov  6 16:19:37 hostname kamailio: INFO: <core> [core/tcp_main.c:4997]: init_tcp():
using epoll_lt as the io watch method (auto detected)
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: rr [../outbound/api.h:52]:
ob_load_api(): unable to import bind_ob - maybe module is not loaded
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: rr [rr_mod.c:188]: mod_init():
outbound module not available
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [main.c:3035]: main():
processes (at least): 52 - shm size: 67108864 - pkg size: 8388608
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [core/udp_server.c:154]:
probe_max_receive_buffer(): SO_RCVBUF is initially 212992
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [core/udp_server.c:206]:
probe_max_receive_buffer(): SO_RCVBUF is finally 425984
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [core/udp_server.c:154]:
probe_max_receive_buffer(): SO_RCVBUF is initially 212992
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [core/udp_server.c:206]:
probe_max_receive_buffer(): SO_RCVBUF is finally 425984
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [core/udp_server.c:154]:
probe_max_receive_buffer(): SO_RCVBUF is initially 212992
Nov  6 16:19:37 hostname src/kamailio[352171]: INFO: <core> [core/udp_server.c:206]:
probe_max_receive_buffer(): SO_RCVBUF is finally 425984
Nov  6 16:19:37 hostname src/kamailio[352200]: INFO: jsonrpcs [jsonrpcs_sock.c:443]:
jsonrpc_dgram_process(): a new child 0/352200
Nov  6 16:19:37 hostname src/kamailio[352202]: INFO: ctl [io_listener.c:213]:
io_listen_loop(): io_listen_loop:  using epoll_lt io watch method (config)
Nov  6 16:19:37 hostname src/kamailio[352203]: ERROR: kazoo [kz_amqp.c:2387]:
kz_amqp_consumer_event_cfg(): kazoo:consumer-event not found
Nov  6 16:19:42 hostname src/kamailio[352203]: ERROR: kazoo [kz_amqp.c:2387]:
kz_amqp_consumer_event_cfg(): kazoo:consumer-event not found
Nov  6 16:19:49 hostname src/kamailio[352213]: ERROR: {1 1 REGISTER
OUfeIVS08Xrbmw8Nr-udtg..} <script>: SCRIPT: Snipppet from
kazoo_query-documentation:
Nov  6 16:19:49 hostname src/kamailio[352221]: CRITICAL: <core>
[core/pass_fd.c:277]: receive_fd(): EOF on 72
Nov  6 16:19:49 hostname src/kamailio[352171]: ALERT: <core> [main.c:774]:
handle_sigs(): child process 352213 exited by a signal 6
Nov  6 16:19:49 hostname src/kamailio[352171]: ALERT: <core> [main.c:777]:
handle_sigs(): core was generated
Nov  6 16:19:49 hostname src/kamailio[352171]: INFO: <core> [main.c:799]:
handle_sigs(): terminating due to SIGCHLD
Nov  6 16:19:49 hostname src/kamailio[352220]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352218]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352209]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352219]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352201]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352187]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352207]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352205]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352202]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352199]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352195]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352210]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352193]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352196]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352183]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352191]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352176]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352203]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352189]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352192]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352175]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352208]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352185]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352182]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352216]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352190]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352206]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352194]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352177]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352215]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352186]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352173]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352204]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352184]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352188]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352217]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352214]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352180]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352198]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352172]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352221]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352174]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352197]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352200]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352211]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352212]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352181]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352179]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352178]: INFO: <core> [main.c:854]: sig_usr():
signal 15 received
Nov  6 16:19:49 hostname src/kamailio[352171]: INFO: <core> [core/sctp_core.c:53]:
sctp_core_destroy(): SCTP API not initialized
```

#### 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.
-->

backtrace with gdb shows:
```
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007fc47407a859 in __GI_abort () at abort.c:79
#2  0x00007fc47407a729 in __assert_fail_base (fmt=0x7fc474210588 "%s%s%s:%u:
%s%sAssertion `%s' failed.\n%n", 
    assertion=0x7fc46f0fe2d0 "json_object_get_type(jso) == json_type_object",
file=0x7fc46f0fe044 "json_object.c", line=476, function=<optimized out>)
at assert.c:92
#3  0x00007fc47408bf36 in __GI___assert_fail (assertion=0x7fc46f0fe2d0
"json_object_get_type(jso) == json_type_object", file=0x7fc46f0fe044
"json_object.c", line=476, 
    function=0x7fc46f0fe280 "json_object_object_add_ex") at assert.c:101
#4  0x00007fc46f0f7d26 in json_object_object_add_ex () from
/lib/x86_64-linux-gnu/libjson-c.so.4
#5  0x00007fc46f14ebe4 in kz_amqp_add_payload_common_properties (json_obj=0x559b3c3b30c0,
server_id=0x7ffda57606f0
&quot;kamailio(a)sipproxy.mydomain.com-&lt;352213&gt;-script-0&quot;;-script-0", 
    unique=0x7ffda5760660) at kz_amqp.c:1023
#6  0x00007fc46f1509a0 in kz_amqp_pipe_send_receive (str_exchange=0x7ffda57609c0,
str_routing_key=0x7ffda57609d0, str_payload=0x7ffda57609b0, kz_timeout=0x7ffda57609e0, 
    json_ret=0x7ffda5760a10) at kz_amqp.c:1159
#7  0x00007fc46f158763 in kz_amqp_query_ex (msg=0x7fc47394beb8, exchange=0x7fc4738f03d0
"(q\216s\304\177", routing_key=0x7fc4738f57c8 "0\213\207s\304\177", 
    payload=0x7fc4738f58d8 "hX\217s\304\177") at kz_amqp.c:1494
#8  0x00007fc46f1588b2 in kz_amqp_query (msg=0x7fc47394beb8, exchange=0x7fc4738f03d0
"(q\216s\304\177", routing_key=0x7fc4738f57c8 "0\213\207s\304\177", 
    payload=0x7fc4738f58d8 "hX\217s\304\177", dst=0x7fc4738f04f0
"p\004\217s\304\177") at kz_amqp.c:1517
#9  0x0000559b3b1c7355 in do_action (h=0x7ffda5761370, a=0x7fc4738f1d98,
msg=0x7fc47394beb8) at core/action.c:1151
#10 0x0000559b3b1d0463 in run_actions (h=0x7ffda5761370, a=0x7fc4738f1d98,
msg=0x7fc47394beb8) at core/action.c:1581
#11 0x0000559b3b1d0bd6 in run_actions_safe (h=0x7ffda5761f70, a=0x7fc4738f1d98,
msg=0x7fc47394beb8) at core/action.c:1645
#12 0x0000559b3b16a4b0 in rval_get_int (h=0x7ffda5761f70, msg=0x7fc47394beb8,
i=0x7ffda5761750, rv=0x7fc4738f4040, cache=0x0) at core/rvalue.c:949
#13 0x0000559b3b16fa9c in rval_expr_eval_int (h=0x7ffda5761f70, msg=0x7fc47394beb8,
res=0x7ffda5761750, rve=0x7fc4738f4038) at core/rvalue.c:1947
#14 0x0000559b3b1c0ec8 in do_action (h=0x7ffda5761f70, a=0x7fc4738f7f28,
msg=0x7fc47394beb8) at core/action.c:1052
#15 0x0000559b3b1d0463 in run_actions (h=0x7ffda5761f70, a=0x7fc4738e8ca8,
msg=0x7fc47394beb8) at core/action.c:1581
#16 0x0000559b3b1d0ce6 in run_top_route (a=0x7fc4738e8ca8, msg=0x7fc47394beb8, c=0x0) at
core/action.c:1666
#17 0x0000559b3b37f932 in receive_msg (
    buf=0x559b3c3a0960 "REGISTER sip:10.0.0.24:5060;transport=TCP SIP/2.0\r\nVia:
SIP/2.0/TCP
10.0.0.33:47335;branch=z9hG4bK-524287-1---83d016a408b857dd;rport\r\nMax-Forwards:
69\r\nContact: <sip:1234@10.0.0.33:47335;rinstance=837"..., len=578,
rcv_info=0x7fc46f4c01a8) at core/receive.c:513
#18 0x0000559b3b41dfb3 in receive_tcp_msg (
    tcpbuf=0x7fc46f4c0530 "REGISTER sip:10.0.0.24:5060;transport=TCP SIP/2.0\r\nVia:
SIP/2.0/TCP
10.0.0.33:47335;branch=z9hG4bK-524287-1---83d016a408b857dd;rport\r\nMax-Forwards:
70\r\nContact: <sip:1234@10.0.0.33:47335;rinstance=837"..., len=578,
rcv_info=0x7fc46f4c01a8, con=0x7fc46f4c0190) at core/tcp_read.c:1424
#19 0x0000559b3b4205f8 in tcp_read_req (con=0x7fc46f4c0190, bytes_read=0x7ffda5762618,
read_flags=0x7ffda576261c) at core/tcp_read.c:1607
#20 0x0000559b3b423af5 in handle_io (fm=0x7fc473954a08, events=1, idx=-1) at
core/tcp_read.c:1782
#21 0x0000559b3b40eccc in io_wait_loop_epoll (h=0x559b3b6f62e0 <io_w>, t=2,
repeat=0) at core/io_wait.h:1070
#22 0x0000559b3b426aa8 in tcp_receive_loop (unix_sock=75) at core/tcp_read.c:1978
#23 0x0000559b3b2a161e in tcp_init_children (woneinit=0x7ffda5762a00) at
core/tcp_main.c:5153
#24 0x0000559b3b153f0b in main_loop () at main.c:1843
#25 0x0000559b3b15e745 in main (argc=1, argv=0x7ffda57630e8) at main.c:3058
```

#### 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).
-->

#### 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

This somehow pointed me to the payload - so I tried to change the AMQP-payload in the
config to a minimalistic custom JSON document. With this config, the crash does no longer
occur:

```
diff /usr/local/etc/kamailio/kamailio.cfg /usr/local/etc/kamailio/kamailio.cfg.sample 
497,501d496
< loadmodule "kazoo.so"
< modparam("kazoo", "amqp_connection",
"amqp://guest:guest@guest@rabbitmqhost:5672")
< modparam("kazoo", "node_hostname",
"sipproxy.mydomain.com")
< modparam("kazoo", "pua_mode", 0)
< 
523,533d517
< xlog("SCRIPT: Snipppet from kazoo_query-documentation:\n");
< #$var(amqp_payload_request) = "{'Event-Category' : 'call_event'
, 'Event-Name' : 'query_user_channels_req', 'Realm' : '"
+ $fd + "', 'Username' : '" + $fU + "',
'Active-Only' : false }";
< kazoo_encode("$ci", "$var(callid_encoded)");
< $var(amqp_routing_key) = "call.status_req.$var(callid_encoded)";
< if(kazoo_query("callevt", $var(amqp_routing_key),
"{\"blop\":\"example\"}", "$var(amqp_result)")) {
<    kazoo_json("$var(amqp_result)", "Channels[0].switch_url",
"$du");
<    if($du != $null) {
<        xlog("L_INFO", "$ci|log|user channels found redirecting call to
$du");
<        return;
<    }
< }
```

So, some issue in the exmaple's payload causes the crash. One the one hand, I think an
example from the documentation should somehow work, on the other hand I think that an
error in a JSON-payload is not indended to crash kamailio anyway.
<!--
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`

```
kamailio -v
version: kamailio 5.6.0-dev2 (x86_64/linux) 63a349
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST,
DNS_IP_HACK, 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_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535,
DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 63a349 
compiled on 16:12:36 Nov  6 2021 with gcc 9.3.0

```

* **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 `lsb_release -a` and `uname -a`)
-->

```
uname -a
Linux hostname 5.11.0-38-generic #42~20.04.1-Ubuntu SMP Tue Sep 28 20:41:07 UTC 2021
x86_64 x86_64 x86_64 GNU/Linux

lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.3 LTS
Release:        20.04
Codename:       focal
```

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2922