[SR-Users] dmq_replicate deserializing?

Asgaroth 00asgaroth00 at gmail.com
Wed Jul 1 21:48:51 CEST 2015 

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

More information about the sr-users mailing list