Hi All,
I am playing with the new dmq_replicate module and am banging my head
against an issue I have come accross. I can see the kamailio registrars
sending the replication messages to the other node(s) in the dmq bus,
and the payload looks to be of type json. However, on the recieving
nodes, when I try to issue a kamctl ul show --brief, the output of the
AOR's are garbled.
I had a look at the dmq/dmq_ursloc moduled, and the dmq module docs
mention that we may need to load our own deserializers, is this the case
when using the dmq_usrloc module as well? I am only using dmq to
replicate registration messages.
Here is a sample of the dmq workers on a recieving node applying the
update, and you can see that it thinks the contact to add is
'p÷#031#002', is was expecting the actual AOR of the subriber to show up
here.
Am I missing something simple here or is there something more sinister
at play.
Any pointers would be greatly appreciated.
Kamailio Version:
version: kamailio 4.3.0 (x86_64/linux) c6aa95
flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS,
DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC,
F_MALLOC, DBG_F_MALLOC, 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_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: c6aa95
compiled on 16:14:27 Jun 23 2015 with gcc 4.4.7
Debug log below:
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:606]: parse_msg(): SIP Request:
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:608]: parse_msg(): method: <KDMQ>
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:610]: parse_msg(): uri: <sip:usrloc@10.6.0.174:5060>
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:612]: parse_msg(): version: <SIP/2.0>
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/parse_via.c:1254]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK9b3c.fe993716000000000000000000000000.0>; state=16
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/parse_via.c:2642]: parse_via(): end of header reached, state=5
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found,
flags=2
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the
first via
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[receive.c:134]: receive_msg(): After parse_msg...
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[receive.c:177]: receive_msg(): preparing to run routing scripts...
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: tm
[t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=450 global
id=449 T start=0xffffffffffffffff
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header
reached, state=10
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To>
[30]; uri=[sip:usrloc@10.6.0.174:5060]
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body
[<sip:usrloc@10.6.0.174:5060>#015#012]
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>:
<10> <KDMQ>
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body :
content_length=471
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: tm
[t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching:
hash=50105, isACK=0
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: tm
[t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching
failed
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: tm
[t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no
transaction found
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: tm
[t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=450 global
id=450 T end=(nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: dmq
[message.c:53]: dmq_handle_message(): dmq_handle_message [KDMQ
sip:usrloc@10.6.0.174:5060] [ ]
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: dmq
[message.c:65]: dmq_handle_message(): dmq_handle_message peer found: usrloc
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq
[worker.c:84]: worker_loop(): dmq_worker [0 23014] lock acquired
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: <core>
[parser/parse_addr_spec.c:172]: parse_to_param(): DEBUG: add_param:
tag=390c95c339281829d3cea6f43c8512cb-7e62
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: <core>
[parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header
reached, state=29
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:250]: usrloc_dmq_handle_msg(): dmq message received from
sip:usrloc@10.6.0.173:5060
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:353]: usrloc_dmq_handle_msg(): Received DMQ_UPDATE.
Update contact info...
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:60]: add_contact(): 'p÷#031#002' found in usrloc
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:62]: add_contact(): get_ucontact = 0
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:72]: add_contact(): Found contact
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: usrloc
[ucontact.c:1688]: update_ucontact(): exists callback for type=
UL_CONTACT_UPDATE
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: usrloc
[ul_callback.h:84]: run_ul_callbacks(): contact=0x7ffe86eabad8, callback
type 2/15, id 0 entered
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:494]: dmq_ul_cb_contact(): Callback from usrloc with type=2
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:517]: dmq_ul_cb_contact(): Contact recieved from DMQ... skip
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:85]: add_contact(): Release record
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq_usrloc
[usrloc_sync.c:87]: add_contact(): Unlock udomain
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: sl
[sl.c:280]: send_reply(): reply in stateless mode (sl)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: <core>
[msg_translator.c:158]: check_via_address(): (10.6.0.173, 10.6.0.173, 0)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23007]: DEBUG: <core>
[receive.c:278]: receive_msg(): cleaning up
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq
[worker.c:134]: worker_loop(): sent reply
Jul 1 20:40:52 bfievkrl02 /usr/sbin/kamailio[23014]: DEBUG: dmq
[worker.c:82]: worker_loop(): dmq_worker [0 23014] getting lock