Description

I used dmq on two machines, registered two softphones on the 111 machine, and then used one phone to call another. After the call was connected, dmq sent a dialog message with an error message 400 bad request.

Here is the 111 config, 113 almost same to 111:

loadmodule "dmq.so"
modparam("dmq", "server_address", "sip:172.16.4.111:5464")
modparam("dmq", "server_socket", "udp:172.16.4.111:5464")
modparam("dmq", "notification_address", "sip:172.16.4.113:5464")
modparam("dmq", "notification_channel", "peers")
modparam("dmq", "num_workers", 4)
modparam("dmq", "ping_interval", 30)

loadmodule "dmq_usrloc.so"
modparam("dmq_usrloc", "enable", 1)
modparam("dmq_usrloc", "sync", 1)
modparam("dmq_usrloc", "batch_msg_contacts", 50)  # 50 contacts / message
modparam("dmq_usrloc", "batch_size", 10000)       # 10000 contacts / batch
modparam("dmq_usrloc", "batch_usleep", 500000)

loadmodule "dialog.so"
modparam("dialog", "enable_stats", 1)
modparam("dialog", "enable_dmq", 1)
...
if (is_method("INVITE")) {
                setflag(FLT_ACC); # do accounting
                dlg_manage();
        }

Here is the sip:
_17429739595923.png (view on web)

the 113 log error:

dialog [dlg_dmq.c:127]: dlg_dmq_handle_msg(): no content length header found

Troubleshooting

Reproduction

The inevitable bug

Debugging Data

(paste your debugging data here)

Log Messages

113 log:

22(4389) DEBUG: <core> [core/udp_server.c:708]: udp_rcv_loop(): received on udp socket: (106/100/767) [[KDMQ sip:dialog@172.16.4.113:5464 SIP/2.0 0D  0A Via: SIP/2.0/UDP 172.16.4.111:5464;branch=z9hG4bK28e.2ec7]]
22(4389) DEBUG: <core> [core/receive.c:190]: ksr_evrt_received(): event route core:msg-received not defined
22(4389) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first line type 1 (request) flags 1
22(4389) DEBUG: <core> [core/parser/msg_parser.c:722]: parse_msg(): SIP Request:
22(4389) DEBUG: <core> [core/parser/msg_parser.c:724]: parse_msg():  method:  <KDMQ>
22(4389) DEBUG: <core> [core/parser/msg_parser.c:726]: parse_msg():  uri:     <sip:dialog@172.16.4.113:5464>
22(4389) DEBUG: <core> [core/parser/msg_parser.c:728]: parse_msg():  version: <SIP/2.0>
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [Via] type 1
22(4389) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK28e.2ec78467000000000000000000000000.0>; state=16
22(4389) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
22(4389) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2
22(4389) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [To] type 3
22(4389) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
22(4389) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [32]; uri=[sip:dialog@172.16.4.113:5464]
22(4389) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:dialog@172.16.4.113:5464>
], to tag (0)[]
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [From] type 4
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [CSeq] type 5
22(4389) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <10> <KDMQ>
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [Call-ID] type 6
22(4389) DEBUG: <core> [core/receive.c:397]: receive_msg(): --- received sip message - request - call-id: [6ecc0d71033645ea-1972@172.16.4.111] - cseq: [10 KDMQ]
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/receive.c:474]: receive_msg(): preparing to run routing scripts...
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=584 a=26 n=xlog
22(4389) INFO: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <script>: 172.16.4.111:5464|172.16.4.113:5464|udp|KDMQ
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=592 a=16 n=if
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=589 a=25 n=is_method
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=590 a=24 n=dmq_process_message
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dmq [message.c:154]: ki_dmq_process_message_rc(): dmq_handle_message [KDMQ sip:dialog@172.16.4.113:5464]
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dmq [message.c:168]: ki_dmq_process_message_rc(): dmq_handle_message peer found: dialog
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=6c399121368d030ed41b62758342ea91-0405b528
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dialog [dlg_dmq.c:124]: dlg_dmq_handle_msg(): dmq message received
22(4389) ERROR: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dialog [dlg_dmq.c:127]: dlg_dmq_handle_msg(): no content length header found


SIP Traffic

(paste your sip traffic here)

Possible Solutions

Additional Information

version: kamailio 5.8.5 (x86_64/linux) 
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, 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_SEND_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:  
compiled on 11:27:01 Mar 21 2025 with gcc 4.8.5
centos7.9


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <kamailio/kamailio/issues/4189@github.com>

QuincyGaoQuincyGao created an issue (kamailio/kamailio#4189)

Description

I used dmq on two machines, registered two softphones on the 111 machine, and then used one phone to call another. After the call was connected, dmq sent a dialog message with an error message 400 bad request.

Here is the 111 config, 113 almost same to 111:

loadmodule "dmq.so"
modparam("dmq", "server_address", "sip:172.16.4.111:5464")
modparam("dmq", "server_socket", "udp:172.16.4.111:5464")
modparam("dmq", "notification_address", "sip:172.16.4.113:5464")
modparam("dmq", "notification_channel", "peers")
modparam("dmq", "num_workers", 4)
modparam("dmq", "ping_interval", 30)

loadmodule "dmq_usrloc.so"
modparam("dmq_usrloc", "enable", 1)
modparam("dmq_usrloc", "sync", 1)
modparam("dmq_usrloc", "batch_msg_contacts", 50)  # 50 contacts / message
modparam("dmq_usrloc", "batch_size", 10000)       # 10000 contacts / batch
modparam("dmq_usrloc", "batch_usleep", 500000)

loadmodule "dialog.so"
modparam("dialog", "enable_stats", 1)
modparam("dialog", "enable_dmq", 1)
...
if (is_method("INVITE")) {
                setflag(FLT_ACC); # do accounting
                dlg_manage();
        }

Here is the sip:
_17429739595923.png (view on web)

the 113 log error:

dialog [dlg_dmq.c:127]: dlg_dmq_handle_msg(): no content length header found

Troubleshooting

Reproduction

The inevitable bug

Debugging Data

(paste your debugging data here)

Log Messages

113 log:

22(4389) DEBUG: <core> [core/udp_server.c:708]: udp_rcv_loop(): received on udp socket: (106/100/767) [[KDMQ sip:dialog@172.16.4.113:5464 SIP/2.0 0D  0A Via: SIP/2.0/UDP 172.16.4.111:5464;branch=z9hG4bK28e.2ec7]]
22(4389) DEBUG: <core> [core/receive.c:190]: ksr_evrt_received(): event route core:msg-received not defined
22(4389) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first line type 1 (request) flags 1
22(4389) DEBUG: <core> [core/parser/msg_parser.c:722]: parse_msg(): SIP Request:
22(4389) DEBUG: <core> [core/parser/msg_parser.c:724]: parse_msg():  method:  <KDMQ>
22(4389) DEBUG: <core> [core/parser/msg_parser.c:726]: parse_msg():  uri:     <sip:dialog@172.16.4.113:5464>
22(4389) DEBUG: <core> [core/parser/msg_parser.c:728]: parse_msg():  version: <SIP/2.0>
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [Via] type 1
22(4389) DEBUG: <core> [core/parser/parse_via.c:1312]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK28e.2ec78467000000000000000000000000.0>; state=16
22(4389) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5
22(4389) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2
22(4389) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [To] type 3
22(4389) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10
22(4389) DEBUG: <core> [core/parser/msg_parser.c:173]: get_hdr_field(): <To> [32]; uri=[sip:dialog@172.16.4.113:5464]
22(4389) DEBUG: <core> [core/parser/msg_parser.c:176]: get_hdr_field(): to body (32)[<sip:dialog@172.16.4.113:5464>
], to tag (0)[]
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [From] type 4
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [CSeq] type 5
22(4389) DEBUG: <core> [core/parser/msg_parser.c:154]: get_hdr_field(): cseq <CSeq>: <10> <KDMQ>
22(4389) DEBUG: <core> [core/parser/parse_hname2.c:316]: parse_sip_header_name(): parsed header name [Call-ID] type 6
22(4389) DEBUG: <core> [core/receive.c:397]: receive_msg(): --- received sip message - request - call-id: [6ecc0d71033645ea-1972@172.16.4.111] - cseq: [10 KDMQ]
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/receive.c:474]: receive_msg(): preparing to run routing scripts...
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=584 a=26 n=xlog
22(4389) INFO: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <script>: 172.16.4.111:5464|172.16.4.113:5464|udp|KDMQ
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=592 a=16 n=if
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=589 a=25 n=is_method
22(4389) exec: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/usr/local/bin/../etc/kamailio/conf/kamailio.cfg] l=590 a=24 n=dmq_process_message
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dmq [message.c:154]: ki_dmq_process_message_rc(): dmq_handle_message [KDMQ sip:dialog@172.16.4.113:5464]
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dmq [message.c:168]: ki_dmq_process_message_rc(): dmq_handle_message peer found: dialog
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=6c399121368d030ed41b62758342ea91-0405b528
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29
22(4389) DEBUG: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dialog [dlg_dmq.c:124]: dlg_dmq_handle_msg(): dmq message received
22(4389) ERROR: |25-03-26 15:25:01|6ecc0d71033645ea-1972@172.16.4.111| dialog [dlg_dmq.c:127]: dlg_dmq_handle_msg(): no content length header found


SIP Traffic

(paste your sip traffic here)

Possible Solutions

Additional Information

version: kamailio 5.8.5 (x86_64/linux) 
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, 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_SEND_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:  
compiled on 11:27:01 Mar 21 2025 with gcc 4.8.5
centos7.9


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <kamailio/kamailio/issues/4189@github.com>