### Description
When using dispatcher module to select destination we didn't configure explicit port:
``` sh-4.1# cat /etc/kamailio/dispatcher.list # $Id$ # dispatcher destination sets #
# line format # setit(int) destination(sip uri) flags(int,opt) priority(int,opt) attributes(str,opt) 1 sip:127.0.0.1 0 0 ```
When we try to rewrite port in R-URI as in following configuration:
``` sh-4.1# cat /etc/kamailio/kamailio.cfg #!KAMAILIO #
debug=3 sip_warning=yes port=5060
mpath="/usr/lib64/kamailio/modules/"
loadmodule "pv.so" loadmodule "xlog.so" loadmodule "dispatcher.so"
modparam("dispatcher", "list_file", "/etc/kamailio/dispatcher.list")
route { ds_select_dst("1", "4"); xlog("will update <$ru>"); xlog("changing $rd to $dd\n"); $rd = $dd; xlog("changing $rp to $dp\n"); $rp = $dp; xlog("final RURI is <$ru>"); exit; } ```
Kamailio crashes on line: ``` $rp = $dp; ```
Interesting thing is that we get port on previous line (see attached log).
### Troubleshooting
#### Reproduction
Use provided configuration and dispatcher.list file and send any SIP request message to Kamailio.
#### 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. -->
``` sh-4.1# gdb /usr/sbin/kamailio /core GNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6) Copyright (C) 2010 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu". For bug reporting instructions, please see: http://www.gnu.org/software/gdb/bugs/... Reading symbols from /usr/sbin/kamailio...Reading symbols from /usr/lib/debug/usr/sbin/kamailio.debug...done. done. [New Thread 25] Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libdl.so.2 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libc.so.6 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /usr/lib64/kamailio/modules/pv.so...Reading symbols from /usr/lib/debug/usr/lib64/kamailio/modules/pv.so.debug...done. done. Loaded symbols for /usr/lib64/kamailio/modules/pv.so Reading symbols from /usr/lib64/kamailio/libsrutils.so.1...Reading symbols from /usr/lib/debug/usr/lib64/kamailio/libsrutils.so.1.0.debug...done. done. Loaded symbols for /usr/lib64/kamailio/libsrutils.so.1 Reading symbols from /lib64/libm.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libm.so.6 Reading symbols from /usr/lib64/kamailio/modules/xlog.so...Reading symbols from /usr/lib/debug/usr/lib64/kamailio/modules/xlog.so.debug...done. done. Loaded symbols for /usr/lib64/kamailio/modules/xlog.so Reading symbols from /usr/lib64/kamailio/modules/dispatcher.so...Reading symbols from /usr/lib/debug/usr/lib64/kamailio/modules/dispatcher.so.debug...done. done. Loaded symbols for /usr/lib64/kamailio/modules/dispatcher.so Reading symbols from /usr/lib64/kamailio/libsrdb1.so.1...Reading symbols from /usr/lib/debug/usr/lib64/kamailio/libsrdb1.so.1.0.debug...done. done. Loaded symbols for /usr/lib64/kamailio/libsrdb1.so.1 Reading symbols from /lib64/libnss_files.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libnss_files.so.2
warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7ffe573ea000 Core was generated by `/usr/sbin/kamailio -DD -E'. Program terminated with signal 11, Segmentation fault. #0 0x00007f52b624785b in pv_set_ruri_port (msg=0x7f52b65860c8, param=0x7f52b6564af8, op=254, val=0x7ffe572d2ac0) at pv_core.c:2561 2561 val->rs.s[val->rs.len] = '\0'; Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.212.el6.x86_64 (gdb) bt full #0 0x00007f52b624785b in pv_set_ruri_port (msg=0x7f52b65860c8, param=0x7f52b6564af8, op=254, val=0x7ffe572d2ac0) at pv_core.c:2561 act = {cline = 0, cfile = 0x0, rname = 0x0, type = 0, count = 0, next = 0x0, val = {{type = STRING_ST, u = {number = 139993220313123, string = 0x7f52b62af023 "5060", str = {s = 0x7f52b62af023 "5060", len = 0}, data = 0x7f52b62af023, attr = 0x7f52b62af023, select = 0x7f52b62af023}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = { number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}}} h = {rec_lev = 0, run_flags = 0, last_retcode = 0, jmp_env = {{__jmpbuf = {0, 0, 0, 0, 4294967296, 0, 0, 0}, __mask_was_saved = 0, __saved_mask = {__val = {0 <repeats 16 times>}}}}} backup = 0 '\000' __FUNCTION__ = "pv_set_ruri_port" #1 0x00000000004e4521 in lval_pvar_assign (h=0x7ffe572d3650, msg=0x7f52b65860c8, lv=0x7f52b6564bb0, rv=0x7f52b6565198) at core/lvalue.c:352 pvar = 0x7f52b6564ae0 pval = {rs = {s = 0x7f52b62af023 "5060", len = 4}, ri = 5060, flags = 12} r_avp = 0x7f52b1774583 avp_val = {n = 22, s = {s = 0x16 <Address 0x16 out of bounds>, len = -1235807720}, re = 0x16} ret = 1 v = 0 destroy_pval = 1 __FUNCTION__ = "lval_pvar_assign" #2 0x00000000004e4f88 in lval_assign (h=0x7ffe572d3650, msg=0x7f52b65860c8, lv=0x7f52b6564bb0, rve=0x7f52b6565190) at core/lvalue.c:400 rv = 0x7f52b6565198 ret = 0 __FUNCTION__ = "lval_assign" #3 0x0000000000442484 in do_action (h=0x7ffe572d3650, a=0x7f52b6564e10, msg=0x7f52b65860c8) at core/action.c:1452 ret = -5 v = 1 dst = {send_sock = 0x7f52b769e190, to = {s = {sa_family = 30144, sa_data = "i\267R\177\000\000\227\201B\250\000\000\000"}, sin = {sin_family = 30144, sin_port = 46953, sin_addr = {s_addr = 32594}, sin_zero = "\227\201B\250\000\000\000"}, sin6 = {sin6_family = 30144, sin6_port = 46953, sin6_flowinfo = 32594, sin6_addr = {__in6_u = {__u6_addr8 = "\227\201B\250\000\000\000\000jbH\267R\177\000", __u6_addr16 = {33175, 43074, 0, 0, 25194, 46920, 32594, 0}, __u6_addr32 = {2822930839, 0, 3074974314, 32594}}}, sin6_scope_id = 0}}, id = 0, send_flags = {f = 30144, blst_imask = 46953}, proto = 82 'R', proto_pad0 = 127 '\177', proto_pad1 = 0} tmp = 0x3000000001 <Address 0x3000000001 out of bounds> new_uri = 0x7f52b769e190 "" end = 0x7ffe572d3360 "x\rV\266R\177" crt = 0x7f52b17745b6 "\nMax-Forwards:60\nContact:sip:127.0.0.1:5060;transport=SCTP\n\n" cmd = 0x7f52b6560d78 len = 7125671 user = 0 uri = {user = {s = 0xb6563058 <Address 0xb6563058 out of bounds>, len = -1235865792}, passwd = {s = 0x7f52b6563090 "\350", len = 6906779}, host = {s = 0x80ded0 "core", len = -1317583573}, port = {s = 0x80e626 "", len = 18}, params = {s = 0x0, len = 7954568}, sip_params = {s = 0x7ffe572d3510 "X\343\200", len = -1219996010}, headers = {s = 0x3000000030 <Address 0x3000000030 out of bounds>, len = 1462579856}, port_no = 12800, proto = 22317, type = 32766, flags = 1462579856, transport = {s = 0x5 <Address 0x5 out of bounds>, len = -1217825432}, ttl = {s = 0xa8428197 <Address 0xa8428197 out of bounds>, len = -1219993630}, user_param = {s = 0x80ded0 "core", len = 44108294}, maddr = {s = 0xe84ce00000000017 <Address 0xe84ce00000000017 out of bounds>, len = -1228093084}, method = {s = 0x0, len = 1462580240}, lr = {s = 0x7f52b6ccdc48 "", len = -1228065280}, r2 = { s = 0x7f52b64c9010 "\001", len = -1235865848}, gr = {s = 0x7f52b6501440 "", len = -1236265920}, transport_val = {s = 0x809572d33b8 <Address 0x809572d33b8 out of bounds>, len = -1235720032}, ttl_val = {s = 0x7f52b769e190 "", len = 0}, user_param_val = {s = 0x7f52b76975c0 "^dA", len = -1217826816}, maddr_val = {s = 0x40f469 "_setjmp", len = -1228036264}, method_val = {s = 0x403948 "\351\002", len = 0}, lr_val = { s = 0x1000003bd <Address 0x1000003bd out of bounds>, len = 7612120}, r2_val = {s = 0x7f52b6586938 "\020", len = -1217796888}, gr_val = {s = 0x7ffe572d3460 "", len = 1462580360}} next_hop = {user = {s = 0x0, len = 0}, passwd = {s = 0x14 <Address 0x14 out of bounds>, len = 25}, host = {s = 0x796088 "DEBUG", len = 8463808}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = {s = 0x400000000 <Address 0x400000000 out of bounds>, len = 8458000}, ttl = {s = 0x0, len = 0}, user_param = { s = 0x300070064 <Address 0x300070064 out of bounds>, len = -1317583372}, maddr = {s = 0x7ffe572d3270 "@\024P\266R\177", len = 7096900}, method = {s = 0x812e50 "parse_addr_spec", len = 10}, lr = {s = 0x0, len = 0}, r2 = { s = 0x0, len = 0}, gr = {s = 0x0, len = -1235865512}, transport_val = {s = 0x7f52b64c9010 "\001", len = 131077}, ttl_val = {s = 0x7f52b64c9f30 "", len = -1236492496}, user_param_val = { s = 0x22572d3258 <Address 0x22572d3258 out of bounds>, len = -1235865848}, maddr_val = {s = 0x7ffe572d3190 "\220\060V\266R\177", len = 6904354}, method_val = {s = 0x7400000000 <Address 0x7400000000 out of bounds>, len = -1235865792}, lr_val = {s = 0x7f52b17745f4 "", len = -1317583551}, r2_val = {s = 0x4b6562f08 <Address 0x4b6562f08 out of bounds>, len = 0}, gr_val = { s = 0x7f52b177457b "Call-ID:8EFCC0126CBA18AF6D6ECE17@4742ffffffff\nCSeq:1 INVITE\nMax-Forwards:60\nContact:sip:127.0.0.1:5060;transport=SCTP\n\n", len = -1317583524}} u = 0x0 ---Type <return> to continue, or q <return> to quit--- port = 0 dst_host = 0x7ffe572d3410 i = 0 flags = 0 avp = 0x7ffe572d3428 st = {flags = 1462579824, id = 32766, name = {n = -1227780152, s = {s = 0x7f52b6d18fc8 "H\201\304\330", len = 48}, re = 0x7f52b6d18fc8}, avp = 0x7ffe572d30d0} sct = 0x1b65868d8 sjt = 0x7f52b17745f4 rve = 0x40f469 mct = 0x7f52b17745b6 rv = 0x0 rv1 = 0x7f52b17745b0 c1 = {cache_type = 1462580848, val_type = 32766, c = {avp_val = {n = -1227824898, s = {s = 0x7f52b6d0e0fe "A\211\304\353\274\017\037D", len = 917540}, re = 0x7f52b6d0e0fe}, pval = {rs = { s = 0x7f52b6d0e0fe "A\211\304\353\274\017\037D", len = 917540}, ri = 8463856, flags = 0}}, i2s = "\210`y\000\000\000\000\000\210`y\000\000\000\000\000\203`y\000\000"} s = {s = 0x7ffe572d3660 "\b\207{", len = -72537977} srevp = {0xffffffff00060014, 0x7f52b7059120} evp = {data = 0x0, rcv = 0x0, dst = 0x0} mod_f_params = {{type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}} __FUNCTION__ = "do_action" #4 0x0000000000443f95 in run_actions (h=0x7ffe572d3650, a=0x7f52b6562018, msg=0x7f52b65860c8) at core/action.c:1578 t = 0x7f52b6564e10 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = -1317583372, tz_dsttime = 32594} tdiff = 3059247320 __FUNCTION__ = "run_actions" #5 0x0000000000444710 in run_top_route (a=0x7f52b6562018, msg=0x7f52b65860c8, c=0x0) at core/action.c:1663 ctx = {rec_lev = 1, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {8095496, 281128530964031683, 7954568, 139993141429635, 8, 139993141429678, 281128531062597827, -280795226126899005}, __mask_was_saved = 0, __saved_mask = {__val = {25, 7954568, 8095461, 120, 139993223291080, 139993223292976, 139993141429687, 139993141429687, 139993141429748, 4294967296, 139993223291080, 0, 1073741825, 8095496, 8095496, 7954568}}}}} p = 0x7ffe572d3650 ret = -1317583442 sfbk = 0 #6 0x0000000000551d16 in receive_msg ( buf=0x7f52b17744c1 "INVITE sip:B@127.0.0.1;user=phone SIP/2.0\nContent-Length:0\nFrom:sip:A@127.0.0.1;tag=13X72gb4A0gYZBa5\nTo:sip:B@127.0.0.1\nVia:SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bKZ2a_U73e_8Z7Be26\nCall-ID:8EFCC0"..., len=307, rcv_info=0x7f52b17741e0) at core/receive.c:424 msg = 0x7f52b65860c8 ctx = {rec_lev = -72515580, run_flags = 0, last_retcode = 0, jmp_env = {{__jmpbuf = {0, 0, 140733120872452, 140730360994068, 140730361004196, 139993141428680, 140730360994000, 4294983372}, __mask_was_saved = -1317584312, __saved_mask = {__val = {139990164045831, 0, 1, 67108864, 8388608, 7954563, 0, 140730361002720, 6629180, 0, 16262913, 139990164045852, 139993230924336, 0, 140730361002816, 139993230924872}}}}} bctx = 0x7ffe572d19ce ret = 1462581616 tvb = {tv_sec = 1584604157, tv_usec = 660616} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 0, tz_dsttime = 0} diff = 0 inb = { s = 0x7f52b17744c1 "INVITE sip:B@127.0.0.1;user=phone SIP/2.0\nContent-Length:0\nFrom:sip:A@127.0.0.1;tag=13X72gb4A0gYZBa5\nTo:sip:B@127.0.0.1\nVia:SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bKZ2a_U73e_8Z7Be26\nCall-ID:8EFCC0"..., len = 307} ---Type <return> to continue, or q <return> to quit--- netinfo = {data = {s = 0x796083 "INFO", len = 0}, rcv = 0x7ffe572d3940, dst = 0x651f07} keng = 0x0 evp = {data = 0x7ffe572d3870, rcv = 0x7f52b17741e0, dst = 0x0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 1 __FUNCTION__ = "receive_msg" #7 0x0000000000659729 in receive_tcp_msg ( tcpbuf=0x7f52b17744c1 "INVITE sip:B@127.0.0.1;user=phone SIP/2.0\nContent-Length:0\nFrom:sip:A@127.0.0.1;tag=13X72gb4A0gYZBa5\nTo:sip:B@127.0.0.1\nVia:SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bKZ2a_U73e_8Z7Be26\nCall-ID:8EFCC0"..., len=307, rcv_info=0x7f52b17741e0, con=0x7f52b17741c8) at core/tcp_read.c:1399 buf = 0x0 bsize = 0 blen = -1217796888 __FUNCTION__ = "receive_tcp_msg" #8 0x000000000065bba1 in tcp_read_req (con=0x7f52b17741c8, bytes_read=0x7ffe572d40ac, read_flags=0x7ffe572d40a4) at core/tcp_read.c:1631 bytes = 1 total_bytes = 1 resp = 1 size = 12884901888 req = 0x7f52b1774248 dst = {send_sock = 0x7ffe572d4098, to = {s = {sa_family = 8, sa_data = "\000\000\000\000\000\000\001 \000\000\250+W\266"}, sin = {sin_family = 8, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\001 \000\000\250+W\266"}, sin6 = {sin6_family = 8, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = "\001 \000\000\250+W\266R\177\000\000\000\000\000", __u6_addr16 = {8193, 0, 11176, 46679, 32594, 0, 0, 0}, __u6_addr32 = {8193, 3059166120, 32594, 0}}}, sin6_scope_id = 3059166120}}, id = 32594, send_flags = {f = 29360, blst_imask = 127}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} c = 0 '\000' ret = 1245623521 __FUNCTION__ = "tcp_read_req" #9 0x000000000065f777 in handle_io (fm=0x7f52b6572ba8, events=1, idx=-1) at core/tcp_read.c:1862 ret = 0 n = 247 read_flags = 1 con = 0x7f52b17741c8 s = 7 resp = 1 t = 1245623521 __FUNCTION__ = "handle_io" #10 0x000000000064d268 in io_wait_loop_epoll (h=0xaf8300, t=2, repeat=0) at core/io_wait.h:1062 n = 1 r = 0 fm = 0x7f52b6572ba8 revents = 1 __FUNCTION__ = "io_wait_loop_epoll" #11 0x0000000000660bd7 in tcp_receive_loop (unix_sock=30) at core/tcp_read.c:1974 __FUNCTION__ = "tcp_receive_loop" #12 0x000000000064336c in tcp_init_children () at core/tcp_main.c:5174 r = 0 i = 7 reader_fd_1 = 30 pid = 0 si_desc = "tcp receiver (generic)\000\000\000\000\200\000\000\000\000\000\203`y", '\000' <repeats 14 times>, "D-W\376\177\000\000\315\213^\000\000\000\000\000\016\323}\000\000\000\000\000\363\261}", '\000' <repeats 13 times>"\220, \351V\266R\177\000\000\000D-W\376\177\000\000\b\237f\000\000\000\000\000\360C-W\027\000\000\000\022\000\000\000\000\000\000" si = 0x0 ---Type <return> to continue, or q <return> to quit--- __FUNCTION__ = "tcp_init_children" #13 0x0000000000426e10 in main_loop () at main.c:1761 i = 8 pid = 23 si = 0x0 si_desc = "udp receiver child=7 sock=172.17.0.2:5060\000q\261R\177\000\000\210`y\000\000\000\000\000\035\000\000\000\000\000\000\000\000\000\000\004\000\000\000\000\000\000\200\000\000\000\000\000\203`y", '\000' <repeats 13 times>, "@J-W\376\177\000\000\003\000\000\000R\177\000\000\060\000\000\000\060\000\000\000\360E-W\376\177\000" nrprocs = 8 woneinit = 1 __FUNCTION__ = "main_loop" #14 0x000000000042e52a in main (argc=3, argv=0x7ffe572d4b28) at main.c:2802 cfg_stream = 0x2b1a010 c = -1 r = 0 tmp = 0x7f52b769e190 "" tmp_len = 0 port = 1 proto = 0 ahost = 0x0 aport = 0 options = 0x77edf8 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:" ret = -1 seed = 2913456231 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 2 n_lst = 0x7ffe572d4a10 p = 0x7f52b6d5a457 "H\205\300t\024\017\266P\003\017\266\312\071\351\017\204\345" st = {st_dev = 112, st_ino = 3424178, st_nlink = 2, st_mode = 16877, st_uid = 499, st_gid = 499, __pad0 = 0, st_rdev = 0, st_size = 4096, st_blksize = 4096, st_blocks = 8, st_atim = {tv_sec = 1584572724, tv_nsec = 529744000}, st_mtim = {tv_sec = 1584369530, tv_nsec = 0}, st_ctim = {tv_sec = 1584572724, tv_nsec = 503744000}, __unused = {0, 0, 0}} tbuf = '\000' <repeats 264 times>"\226, VH\267R\177\000\000\000\000\000\000\000\000\000\000PH-W\376\177\000\000\000\000\000\000\000\000\000\000PH-W\376\177\000\000\001\000\000\000\000\000\000\000H\347i\267R\177\000\000\177U\335q\000\000\000\000\226VH\267R\177\000\000\000\000\000\000\000\000\000\000\220H-W\376\177\000\000?\000\000\000\000\000\000\000\220H-W\376\177\000\000\005\000\000\000\000\000\000\000hui\267R\177\000\000.N=\366\000\000\000\000\342_H\267R\177\000\000\000\000\000\000\000\000\000\000\070\365\330\003\000\000\000\000.\000\000\000\000\000\000\000T\332\314\266R\177\000\000\000\000\000\000\000\000\000\000\020J-W\376\177\000\000H\334\314\266R\177\000\000\240\233\315\266R\177\000\000pJ-W\376\177\000\000 \347i\267R\177\000\000_\372\341\266R\177\000\000\230\242>W\376"... option_index = 0 long_options = {{name = 0x781880 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x77b694 "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x781885 "alias", has_arg = 1, flag = 0x0, val = 1024}, { name = 0x78188b "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x781891 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x78189a "substdefs", has_arg = 1, flag = 0x0, val = 1027}, { name = 0x7818a4 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __FUNCTION__ = "main" (gdb) info locals act = {cline = 0, cfile = 0x0, rname = 0x0, type = 0, count = 0, next = 0x0, val = {{type = STRING_ST, u = {number = 139993220313123, string = 0x7f52b62af023 "5060", str = {s = 0x7f52b62af023 "5060", len = 0}, data = 0x7f52b62af023, attr = 0x7f52b62af023, select = 0x7f52b62af023}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = { s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}}} h = {rec_lev = 0, run_flags = 0, last_retcode = 0, jmp_env = {{__jmpbuf = {0, 0, 0, 0, 4294967296, 0, 0, 0}, __mask_was_saved = 0, __saved_mask = {__val = {0 <repeats 16 times>}}}}} backup = 0 '\000' __FUNCTION__ = "pv_set_ruri_port" (gdb) list 2556 2557 memset(&act, 0, sizeof(act)); 2558 act.val[0].type = STRING_ST; 2559 act.val[0].u.string = val->rs.s; 2560 backup = val->rs.s[val->rs.len]; 2561 val->rs.s[val->rs.len] = '\0'; 2562 act.type = SET_PORT_T; 2563 init_run_actions_ctx(&h); 2564 if (do_action(&h, &act, msg)<0) 2565 { ```
#### Log Messages
``` 0(1) DEBUG: <core> [core/cfg.y:1783]: yyparse(): loading modules under /usr/lib64/kamailio/modules/ 0(1) DEBUG: <core> [core/cfg.y:1764]: yyparse(): loading module pv.so 0(1) DEBUG: <core> [core/sr_module.c:505]: load_module(): trying to load </usr/lib64/kamailio/modules/pv.so> 0(1) DEBUG: <core> [core/kemi.c:2642]: sr_kemi_modules_add(): adding core module 0(1) DEBUG: <core> [core/kemi.c:2646]: sr_kemi_modules_add(): adding pv module 0(1) DEBUG: <core> [core/kemi.c:2650]: sr_kemi_modules_add(): adding hdr module 0(1) DEBUG: <core> [core/kemi.c:2664]: sr_kemi_modules_add(): adding module: pvx 0(1) DEBUG: <core> [core/sr_module.c:267]: register_module(): register PV from: pv 0(1) DEBUG: <core> [core/cfg.lex:1781]: pp_define(): defining id: MOD_pv 0(1) DEBUG: <core> [core/cfg.y:1764]: yyparse(): loading module xlog.so 0(1) DEBUG: <core> [core/sr_module.c:505]: load_module(): trying to load </usr/lib64/kamailio/modules/xlog.so> 0(1) DEBUG: <core> [core/kemi.c:2664]: sr_kemi_modules_add(): adding module: xlog 0(1) DEBUG: <core> [core/sr_module.c:267]: register_module(): register PV from: xlog 0(1) DEBUG: <core> [core/cfg.lex:1781]: pp_define(): defining id: MOD_xlog 0(1) DEBUG: <core> [core/cfg.y:1764]: yyparse(): loading module dispatcher.so 0(1) DEBUG: <core> [core/sr_module.c:505]: load_module(): trying to load </usr/lib64/kamailio/modules/dispatcher.so> 0(1) DEBUG: <core> [core/kemi.c:2664]: sr_kemi_modules_add(): adding module: dispatcher 0(1) DEBUG: <core> [core/cfg.lex:1781]: pp_define(): defining id: MOD_dispatcher 0(1) DEBUG: <core> [core/mem/shm.c:100]: shm_core_pools_init(): preparing to initialize shm core pools 0(1) DEBUG: <core> [core/mem/q_malloc.c:200]: qm_malloc_init(): QM_OPTIMIZE=16384, /ROUNDTO=2048 0(1) DEBUG: <core> [core/mem/q_malloc.c:202]: qm_malloc_init(): QM_HASH_SIZE=2099, qm_block size=235152 0(1) DEBUG: <core> [core/mem/q_malloc.c:204]: qm_malloc_init(): qm_malloc_init(0x7f52b16dd000, 67108864), start=0x7f52b16dd000 0(1) DEBUG: <core> [core/mem/q_malloc.c:213]: qm_malloc_init(): size= 67108864, init_overhead=235256 0(1) DEBUG: <core> [core/modparam.c:107]: set_mod_param_regex(): 'dispatcher' matches module 'dispatcher' 0(1) DEBUG: <core> [core/sr_module.c:725]: find_param_export(): found <list_file> in module dispatcher [/usr/lib64/kamailio/modules/dispatcher.so] 0(1) DEBUG: <core> [core/modparam.c:123]: set_mod_param_regex(): found <list_file> in module dispatcher [/usr/lib64/kamailio/modules/dispatcher.so] 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #0/2: 9(9)/ (nil) 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #1/2: 3(3)/ (nil) 0(1) DEBUG: <core> [core/sr_module.c:633]: find_mod_export_record(): found export of <ds_select_dst> in module dispatcher [/usr/lib64/kamailio/modules/dispatcher.so] 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #0/2: 9(9)/ (nil) 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #1/2: 3(3)/ (nil) 0(1) DEBUG: <core> [core/sr_module.c:633]: find_mod_export_record(): found export of <xlog> in module xlog [/usr/lib64/kamailio/modules/xlog.so] 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #0/2: 9(9)/ (nil) 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #1/2: 3(3)/ (nil) 0(1) DEBUG: <core> [core/sr_module.c:633]: find_mod_export_record(): found export of <xlog> in module xlog [/usr/lib64/kamailio/modules/xlog.so] 0(1) DEBUG: <core> [core/pvapi.c:335]: pv_cache_add(): PV cache not initialized, doing it now 0(1) DEBUG: <core> [core/pvapi.c:371]: pv_cache_add(): pvar [$rd] added in cache 0(1) DEBUG: <core> [core/pvapi.c:371]: pv_cache_add(): pvar [$dd] added in cache 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#63 #0/2: 21(15)/ 0x7f52b6563b18 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#63 #1/2: 22(16)/ 0x7f52b6563e40 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #0/2: 9(9)/ (nil) 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #1/2: 3(3)/ (nil) 0(1) DEBUG: <core> [core/sr_module.c:633]: find_mod_export_record(): found export of <xlog> in module xlog [/usr/lib64/kamailio/modules/xlog.so] 0(1) DEBUG: <core> [core/pvapi.c:371]: pv_cache_add(): pvar [$rp] added in cache 0(1) DEBUG: <core> [core/pvapi.c:371]: pv_cache_add(): pvar [$dp] added in cache 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#63 #0/2: 21(15)/ 0x7f52b6564bb0 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#63 #1/2: 22(16)/ 0x7f52b6565190 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #0/2: 9(9)/ (nil) 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#24 #1/2: 3(3)/ (nil) 0(1) DEBUG: <core> [core/sr_module.c:633]: find_mod_export_record(): found export of <xlog> in module xlog [/usr/lib64/kamailio/modules/xlog.so] 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#2 #0/2: 3(3)/ 0x1 0(1) DEBUG: <core> [core/route_struct.c:129]: mk_action(): ACTION_#2 #1/2: 3(3)/ 0x1 0(1) DEBUG: <core> [core/ppcfg.c:231]: pp_ifdef_level_check(): same number of pairing preprocessor directives #!IF[N]DEF - #!ENDIF 0(1) DEBUG: <core> [core/route.c:129]: route_add(): mapping routing block (0xb57c00)[core:receive-parse-error] to 1 0(1) INFO: <core> [core/sctp_core.c:75]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module 0(1) DEBUG: <core> [core/socket_info.c:1325]: add_interfaces(): If: lo Fam: 2 Flg: 10049 Adr: 127.0.0.1 0(1) DEBUG: <core> [core/socket_info.c:1325]: add_interfaces(): If: eth0 Fam: 2 Flg: 11043 Adr: 172.17.0.2 0(1) DEBUG: <core> [core/socket_info.c:1325]: add_interfaces(): If: lo Fam: 2 Flg: 10049 Adr: 127.0.0.1 0(1) DEBUG: <core> [core/socket_info.c:1325]: add_interfaces(): If: eth0 Fam: 2 Flg: 11043 Adr: 172.17.0.2 0(1) DEBUG: <core> [core/mem/pkg.c:109]: pkg_print_manager(): pkg - using memory manager: q_malloc 0(1) DEBUG: <core> [core/mem/shm.c:301]: shm_print_manager(): shm - using memory manager: q_malloc 0(1) DEBUG: <core> [core/cfg/cfg.c:174]: cfg_declare(): new config group has been registered: 'core' (num=56, size=224) 0(1) DEBUG: <core> [core/cfg/cfg.c:174]: cfg_declare(): new config group has been registered: 'tcp' (num=27, size=108) 0(1) DEBUG: <core> [core/timer.c:239]: init_timer(): starting with *ticks=1245622805 0(1) DEBUG: <core> [core/timer.c:281]: init_timer(): timer_list between 0x7f52b1716af0 and 0x7f52b175aaf0 0(1) DEBUG: <core> [core/pt.c:139]: register_procs(): registering new processes: 0 (old) + 1 (new) = 1 (total) loading modules under config path: /usr/lib64/kamailio/modules/ Listening on udp: 127.0.0.1:5060 udp: 172.17.0.2:5060 tcp: 127.0.0.1:5060 tcp: 172.17.0.2:5060 Aliases: tcp: 4f94e19b0c05:5060 tcp: localhost:5060 udp: 4f94e19b0c05:5060 udp: localhost:5060
0(1) INFO: <core> [core/tcp_main.c:5043]: init_tcp(): using epoll_lt as the io watch method (auto detected) 0(1) DEBUG: <core> [core/daemonize.c:207]: enable_dumpable(): trying enable core dumping... 0(1) DEBUG: <core> [core/daemonize.c:225]: enable_dumpable(): core dumping is enabled now (1)... 0(1) DEBUG: <core> [core/daemonize.c:583]: set_core_dump(): core dump limits set to 18446744073709551615 0(1) DEBUG: <core> [core/async_task.c:123]: async_task_init(): start initializing asynk task framework 0(1) DEBUG: <core> [core/sr_module.c:847]: init_mod(): pv 0(1) DEBUG: <core> [core/sr_module.c:847]: init_mod(): xlog 0(1) DEBUG: <core> [core/cfg/cfg.c:174]: cfg_declare(): new config group has been registered: 'xlog' (num=1, size=4) 0(1) DEBUG: <core> [core/sr_module.c:847]: init_mod(): dispatcher 0(1) DEBUG: <core> [core/cfg/cfg.c:174]: cfg_declare(): new config group has been registered: 'dispatcher' (num=3, size=24) 0(1) DEBUG: dispatcher [dispatch.c:516]: add_dest2list(): dest [1/1] sip:127.0.0.1 0(1) DEBUG: dispatcher [dispatch.c:850]: ds_load_list(): found [0] dest sets 0(1) DEBUG: dispatcher [dispatch.c:203]: ds_log_dst_cb(): dst>> 1 sip:127.0.0.1 0 0 (,0,0,0) 0(1) DEBUG: dispatcher [dispatcher.c:388]: mod_init(): loaded dispatching list 0(1) DEBUG: <core> [core/pt.c:100]: init_pt(): registering new processes: 1 (old) + 28 (new) = 29 (total) 0(1) INFO: <core> [main.c:2780]: main(): processes (at least): 29 - shm size: 67108864 - pkg size: 8388608 0(1) DEBUG: <core> [core/route.c:885]: fix_actions(): fixing ds_select_dst() 0(1) DEBUG: <core> [core/route.c:885]: fix_actions(): fixing xlog() 0(1) DEBUG: <core> [core/pvapi.c:497]: pv_spec_lookup(): PV <$ru> is not in cache 0(1) DEBUG: <core> [core/pvapi.c:371]: pv_cache_add(): pvar [$ru] added in cache 0(1) DEBUG: <core> [core/route.c:885]: fix_actions(): fixing xlog() 0(1) DEBUG: <core> [core/pvapi.c:399]: pv_cache_lookup(): pvar [$rd] found in cache 0(1) DEBUG: <core> [core/pvapi.c:399]: pv_cache_lookup(): pvar [$dd] found in cache 0(1) DEBUG: <core> [core/rvalue.c:2873]: fix_rval(): RV fixing type 7 0(1) DEBUG: <core> [core/route.c:885]: fix_actions(): fixing xlog() 0(1) DEBUG: <core> [core/pvapi.c:399]: pv_cache_lookup(): pvar [$rp] found in cache 0(1) DEBUG: <core> [core/pvapi.c:399]: pv_cache_lookup(): pvar [$dp] found in cache 0(1) DEBUG: <core> [core/rvalue.c:2873]: fix_rval(): RV fixing type 7 0(1) DEBUG: <core> [core/route.c:885]: fix_actions(): fixing xlog() 0(1) DEBUG: <core> [core/pvapi.c:399]: pv_cache_lookup(): pvar [$ru] found in cache 0(1) INFO: <core> [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 0(1) INFO: <core> [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 0(1) INFO: <core> [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 0(1) INFO: <core> [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 0(1) DEBUG: <core> [core/tcp_main.c:3060]: tcp_init(): added 127.0.0.1:5060 0(1) DEBUG: <core> [core/tcp_main.c:3060]: tcp_init(): added 172.17.0.2:5060 0(1) DEBUG: <core> [core/daemonize.c:207]: enable_dumpable(): trying enable core dumping... 0(1) DEBUG: <core> [core/daemonize.c:225]: enable_dumpable(): core dumping is enabled now (1)... 0(1) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_INIT with rank -127 0(1) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 0 rank -127: dispatcher [main] 1(6) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1138164497 657242635 1936217831 1(6) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_SIPINIT with rank 1 1(6) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 1 rank 1: dispatcher [udp receiver child=0 sock=127.0.0.1:5060] 1(6) DEBUG: <core> [core/action.c:1681]: run_child_one_init_route(): attempting to run event_route[core:worker-one-init] 1(6) DEBUG: <core> [core/route.c:129]: route_add(): mapping routing block (0xb57c00)[core:worker-one-init] to 2 2(7) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 767621824 1903169421 3094393287 2(7) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 2 2(7) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 2 rank 2: dispatcher [udp receiver child=1 sock=127.0.0.1:5060] 3(8) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1404086465 261080756 770401788 3(8) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 3 3(8) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 3 rank 3: dispatcher [udp receiver child=2 sock=127.0.0.1:5060] 4(9) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1276199264 1346413345 2657742810 4(9) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 4 4(9) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 4 rank 4: dispatcher [udp receiver child=3 sock=127.0.0.1:5060] 5(10) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 426380731 684525899 1595360440 5(10) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 5 5(10) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 5 rank 5: dispatcher [udp receiver child=4 sock=127.0.0.1:5060] 6(11) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 109773679 1341474029 2008829924 6(11) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 6 6(11) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 6 rank 6: dispatcher [udp receiver child=5 sock=127.0.0.1:5060] 9(14) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 485860116 476468826 2655924202 7(12) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1857608191 1922761176 1237080075 9(14) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 9 9(14) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 9 rank 9: dispatcher [udp receiver child=0 sock=172.17.0.2:5060] 7(12) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 7 7(12) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 7 rank 7: dispatcher [udp receiver child=6 sock=127.0.0.1:5060] 8(13) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 562716326 1340065989 3126261784 8(13) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 8 8(13) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 8 rank 8: dispatcher [udp receiver child=7 sock=127.0.0.1:5060] 10(15) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 202372237 1429362131 3169714441 10(15) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 10 10(15) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 10 rank 10: dispatcher [udp receiver child=1 sock=172.17.0.2:5060] 11(16) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1063199497 966236880 107442987 11(16) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 11 11(16) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 11 rank 11: dispatcher [udp receiver child=2 sock=172.17.0.2:5060] 12(17) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 2020596441 1564950130 866753896 12(17) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 12 12(17) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 12 rank 12: dispatcher [udp receiver child=3 sock=172.17.0.2:5060] 13(18) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 33883575 1983372148 799990916 13(18) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 13 13(18) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 13 rank 13: dispatcher [udp receiver child=4 sock=172.17.0.2:5060] 14(19) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 2007235399 2019994138 2394392753 14(19) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 14 14(19) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 14 rank 14: dispatcher [udp receiver child=5 sock=172.17.0.2:5060] 15(20) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1393726726 1930799296 2068801996 17(22) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1702053370 1759107173 2317004371 17(22) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_TIMER with rank -1 15(20) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 15 17(22) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 17 rank -1: dispatcher [slow timer] 15(20) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 15 rank 15: dispatcher [udp receiver child=6 sock=172.17.0.2:5060] 0(1) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_MAIN with rank 0 0(1) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 0 rank 0: dispatcher [main] 19(24) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 2047276621 1783092597 1028234677 19(24) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_TIMER with rank -1 19(24) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 19 rank -1: dispatcher [secondary timer] 16(21) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 1760686381 1461439773 352661441 16(21) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 16 16(21) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 16 rank 16: dispatcher [udp receiver child=7 sock=172.17.0.2:5060] 21(26) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 18 21(26) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 21 rank 18: dispatcher [tcp receiver (generic) child=1] 21(26) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 22(27) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 19 22(27) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 22 rank 19: dispatcher [tcp receiver (generic) child=2] 21(26) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 32, 1, (nil)), fd_no=0 23(28) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 20 23(28) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 23 rank 20: dispatcher [tcp receiver (generic) child=3] 22(27) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 22(27) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 34, 1, (nil)), fd_no=0 23(28) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 23(28) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 36, 1, (nil)), fd_no=0 25(30) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 22 25(30) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 25 rank 22: dispatcher [tcp receiver (generic) child=5] 25(30) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 25(30) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 40, 1, (nil)), fd_no=0 27(32) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 24 27(32) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 27 rank 24: dispatcher [tcp receiver (generic) child=7] 0(1) DEBUG: <core> [main.c:1796]: main_loop(): Expect maximum 2197 open fds 27(32) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 27(32) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 44, 1, (nil)), fd_no=0 28(33) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 2107779165 267268442 1172423650 28(33) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_TCP_MAIN with rank -4 28(33) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 28 rank -4: dispatcher [tcp main process] 20(25) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 17 20(25) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 20 rank 17: dispatcher [tcp receiver (generic) child=0] 28(33) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xab4228 and 0xaf8228 20(25) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 6, 1, 0x7f52b656ea08), fd_no=0 20(25) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 30, 1, (nil)), fd_no=0 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 7, 1, 0x7f52b656ec00), fd_no=1 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 8, 4, 0x7f52b1771f44), fd_no=2 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 9, 4, 0x7f52b1771fd8), fd_no=3 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 10, 4, 0x7f52b177206c), fd_no=4 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 11, 4, 0x7f52b1772100), fd_no=5 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 12, 4, 0x7f52b1772194), fd_no=6 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 13, 4, 0x7f52b1772228), fd_no=7 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 14, 4, 0x7f52b17722bc), fd_no=8 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 15, 4, 0x7f52b1772350), fd_no=9 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 16, 4, 0x7f52b17723e4), fd_no=10 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 17, 4, 0x7f52b1772478), fd_no=11 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 18, 4, 0x7f52b177250c), fd_no=12 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 19, 4, 0x7f52b17725a0), fd_no=13 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 20, 4, 0x7f52b1772634), fd_no=14 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 21, 4, 0x7f52b17726c8), fd_no=15 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 22, 4, 0x7f52b177275c), fd_no=16 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 23, 4, 0x7f52b17727f0), fd_no=17 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 24, 4, 0x7f52b1772884), fd_no=18 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 25, 4, 0x7f52b1772918), fd_no=19 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 26, 4, 0x7f52b17729ac), fd_no=20 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 27, 4, 0x7f52b1772a40), fd_no=21 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 28, 4, 0x7f52b1772ad4), fd_no=22 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 30, 4, 0x7f52b1772b68), fd_no=23 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 32, 4, 0x7f52b1772bfc), fd_no=24 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 34, 4, 0x7f52b1772c90), fd_no=25 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 36, 4, 0x7f52b1772d24), fd_no=26 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 38, 4, 0x7f52b1772db8), fd_no=27 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 40, 4, 0x7f52b1772e4c), fd_no=28 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 29, 3, 0x7f52b656e138), fd_no=29 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 31, 3, 0x7f52b656e158), fd_no=30 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 33, 3, 0x7f52b656e178), fd_no=31 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 35, 3, 0x7f52b656e198), fd_no=32 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 37, 3, 0x7f52b656e1b8), fd_no=33 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 39, 3, 0x7f52b656e1d8), fd_no=34 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 41, 3, 0x7f52b656e1f8), fd_no=35 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 43, 3, 0x7f52b656e218), fd_no=36 18(23) DEBUG: <core> [core/pt.c:311]: fork_process(): test random numbers 894168009 1714857032 1695342316 18(23) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing PROC_TIMER with rank -1 18(23) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 18 rank -1: dispatcher [timer] 24(29) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 21 24(29) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 24 rank 21: dispatcher [tcp receiver (generic) child=4] 24(29) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 24(29) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 38, 1, (nil)), fd_no=0 26(31) DEBUG: <core> [core/sr_module.c:820]: init_child(): initializing CHILD with rank 23 26(31) DEBUG: <core> [core/sr_module.c:779]: init_mod_child(): idx 26 rank 23: dispatcher [tcp receiver (generic) child=6] 26(31) DEBUG: <core> [core/local_timer.c:61]: init_local_timer(): timer_list between 0xaf84c8 and 0xb3c4c8 26(31) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 42, 1, (nil)), fd_no=0 28(33) DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 127.0.0.1 28(33) DEBUG: <core> [core/tcp_main.c:1236]: tcpconn_new(): on port 55080, type 2 28(33) DEBUG: <core> [core/tcp_main.c:1559]: tcpconn_add(): hashes: 1656:1670:1381, 1 28(33) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xab4060, 44, 2, 0x7f52b17741c8), fd_no=37 28(33) DEBUG: <core> [core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0xab4060, 44, -1, 0x0) fd_no=38 called 28(33) DEBUG: <core> [core/tcp_main.c:4517]: handle_tcpconn_ev(): sending to child, events 1 28(33) DEBUG: <core> [core/tcp_main.c:4190]: send2child(): selected tcp worker idx:0 proc:20 pid:25 for activity on [tcp:127.0.0.1:5060], 0x7f52b17741c8 20(25) DEBUG: <core> [core/tcp_read.c:1759]: handle_io(): received n=8 con=0x7f52b17741c8, fd=7 20(25) DEBUG: <core> [core/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0xaf8300, 7, 2, 0x7f52b17741c8), fd_no=1 20(25) DEBUG: <core> [core/tcp_read.c:1560]: tcp_read_req(): content-length=0 20(25) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: 20(25) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <INVITE> 20(25) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: sip:B@127.0.0.1;user=phone 20(25) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> 20(25) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 20(25) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 20(25) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [18]; uri=[sip:B@127.0.0.1] 20(25) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [sip:B@127.0.0.1 ], to tag [] 20(25) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKZ2a_U73e_8Z7Be26>; state=15 20(25) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 20(25) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 20(25) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via 20(25) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE> 20(25) DEBUG: <core> [core/receive.c:325]: receive_msg(): --- received sip message - request - call-id: [8EFCC0126CBA18AF6D6ECE17@4742ffffffff] - cseq: [1 INVITE] 20(25) DEBUG: <core> [core/receive.c:380]: receive_msg(): preparing to run routing scripts... 20(25) DEBUG: dispatcher [dispatch.c:2062]: ds_manage_routes(): set [1] 20(25) DEBUG: dispatcher [dispatch.c:2168]: ds_manage_routes(): using alg [4] hash [0] 20(25) DEBUG: dispatcher [dispatch.c:2214]: ds_manage_routes(): selected [4-1-0/0] sip:127.0.0.1 20(25) DEBUG: dispatcher [dispatch.c:2023]: ds_select_dst_limit(): selected target destinations: 0 20(25) ERROR: <script>: will update sip:B@127.0.0.1;user=phone20(25) ERROR: <script>: changing 127.0.0.1 to 127.0.0.1 20(25) ERROR: <script>: changing 5060 to 5060 18(23) WARNING: <core> [core/timer.c:413]: adjust_ticks(): our timer runs faster than real-time (45000 ms / 720 ticks our time .-> 44929 ms / 718 ticks real time) 28(33) DEBUG: <core> [core/tcp_main.c:3593]: handle_tcp_child(): dead tcp child 0 (pid 25, no 20) (shutting down?) 28(33) DEBUG: <core> [core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0xab4060, 29, -1, 0x0) fd_no=37 called 28(33) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 27 28(33) DEBUG: <core> [core/tcp_main.c:3825]: handle_ser_child(): dead child 20, pid 25 (shutting down?) 28(33) DEBUG: <core> [core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0xab4060, 27, -1, 0x0) fd_no=36 called 0(1) ALERT: <core> [main.c:767]: handle_sigs(): child process 25 exited by a signal 11 0(1) ALERT: <core> [main.c:770]: handle_sigs(): core was generated 0(1) INFO: <core> [main.c:792]: handle_sigs(): terminating due to SIGCHLD 0(1) DEBUG: <core> [main.c:794]: handle_sigs(): terminating due to SIGCHLD 1(6) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 3(8) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 2(7) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 8(13) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 11(16) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 4(9) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 14(19) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 16(21) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 7(12) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 15(20) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 6(11) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 25(30) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 17(22) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 23(28) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 12(17) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 5(10) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 19(24) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 26(31) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 10(15) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 21(26) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 22(27) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 28(33) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 13(18) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 9(14) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 18(23) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 24(29) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 27(32) INFO: <core> [main.c:847]: sig_usr(): signal 15 received 0(1) INFO: <core> [core/sctp_core.c:53]: sctp_core_destroy(): SCTP API not initialized 0(1) DEBUG: <core> [core/mem/shm.c:289]: shm_destroy_manager(): destroying memory manager: q_malloc 0(1) DEBUG: <core> [core/mem/q_malloc.c:1185]: qm_shm_lock_destroy(): destroying the shared memory lock 0(1) DEBUG: <core> [core/mem/pkg.c:98]: pkg_destroy_manager(): destroying memory manager: q_malloc```
#### 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). -->
``` INVITE sip:B@127.0.0.1;user=phone SIP/2.0 Content-Length:0 From:sip:A@127.0.0.1;tag=13X72gb4A0gYZBa5 To:sip:B@127.0.0.1 Via:SIP/2.0/TCP 127.0.0.1:5060;branch=z9hG4bKZ2a_U73e_8Z7Be26 Call-ID:8EFCC0126CBA18AF6D6ECE17@4742ffffffff CSeq:1 INVITE Max-Forwards:60 Contact:sip:127.0.0.1:5060;transport=TCP
```
### Possible Solutions
<!-- If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix. -->
As a workaround all dispatcher module entries need to have explicit port configured.
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
I have used official packages for CentOS 6 for Kamailio 5.3.3. I was able to reproduce it on Kamailio 5.2 also.
``` sh-4.1# kamailio -v version: kamailio 5.3.3 (x86_64/linux) c918a3 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_BLACKLIST, HAVE_RESOLV_RES 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: c918a3 compiled on 14:33:03 Mar 16 2020 with gcc 4.4.7 ```
* **Operating System**:
``` Linux ac8386769ce8 4.19.76-linuxkit #1 SMP Thu Oct 17 19:31:58 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux sh-4.1# cat /etc/redhat-release CentOS release 6.10 (Final) ```
I pushed a commit for it. Can you try with the patch referenced above?
Thanks a lot for fast patch. I will test it today.
Fix is working.
``` /usr/local/sbin/kamailio[7421]: ERROR: <script>: will update sip:B@127.0.0.1;user=phone /usr/local/sbin/kamailio[7421]: ERROR: <script>: changing 127.0.0.1 to 127.0.0.1
/usr/local/sbin/kamailio[7421]: ERROR: <script>: changing 5060 to 5060
/usr/local/sbin/kamailio[7421]: ERROR: <script>: final RURI is sip:B@127.0.0.1:5060;user=phone /usr/local/sbin/kamailio[7421]: DEBUG: <core> [core/receive.c:438]: receive_msg(): request-route executed in: 2827 usec ```
Thank you again for quick patch.
Closed #2258.