Hello,
I'm trying to set up kamailio as a simple load balancer proxy between VOIP Providers and a cluster of asterisk servers.
I have started with the default kamailio.cfg.
At the end, i got this up and running, but with one exception: if incoming call is not answered by the asterisk end (i.e. it is in ringing state), and then the gateway sends CANCEL request, kamailio is unable to recognize the transaction and is not forwarding the request to asterisk. The result is: the call is left "dangling" in the PBX and is not properly hang up.
I have call flow: Provider 214.22.198.51 -> Kamailio 38.149.172.163 -> Asterisk 38.149.172.164.
**Log from Provider 214.22.198.51**
Reliably Transmitting (no NAT) to 38.149.172.163:5060: INVITE sip:100@38.149.172.163:5060 SIP/2.0 Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff Max-Forwards: 70 From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5 To: sip:100@38.149.172.163:5060 Contact: sip:123456@214.22.198.51:5060 Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 14.6.2 Date: Thu, 07 Feb 2019 10:45:15 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 310
v=0 o=root 610375704 610375704 IN IP4 214.22.198.51 s=Asterisk PBX 14.6.2 c=IN IP4 214.22.198.51 t=0 0 m=audio 13076 RTP/AVP 18 8 0 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv
--- -- Called SIP/kamailio/100
<--- SIP read from UDP:38.149.172.163:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5 To: sip:100@38.149.172.163:5060 Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060 CSeq: 102 INVITE Server: kamailio (5.2.0 (x86_64/linux)) Content-Length: 0
<-------------> --- (8 headers 0 lines) ---
<--- SIP read from UDP:38.149.172.163:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5 To: sip:100@38.149.172.163:5060 Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060 CSeq: 102 INVITE Server: Asterisk PBX 16.1.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: sip:100@38.149.172.164:5060 Content-Length: 0
<-------------> --- (12 headers 0 lines) ---
<--- SIP read from UDP:38.149.172.163:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5 To: sip:100@38.149.172.163:5060;tag=as14e62645 Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060 CSeq: 102 INVITE Server: Asterisk PBX 16.1.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: sip:100@38.149.172.164:5060 Content-Length: 0
<-------------> --- (12 headers 0 lines) --- sip_route_dump: route/path hop: sip:100@38.149.172.164:5060 -- SIP/kamailio-0007f2d9 is ringing Scheduling destruction of SIP dialog '0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060' in 32000 ms (Method: INVITE) Reliably Transmitting (no NAT) to 38.149.172.163:5060: CANCEL sip:100@38.149.172.163:5060 SIP/2.0 Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff Max-Forwards: 70 From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5 To: sip:100@38.149.172.163:5060 Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060 CSeq: 102 CANCEL User-Agent: Asterisk PBX 14.6.2 Content-Length: 0
**Kamailio 38.149.172.163** Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/359) [[CANCEL sip:100@38.149.172.163:5060 SIP/2.0 0D 0A Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220d]] Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <CANCEL> Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: sip:100@38.149.172.163:5060 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK7d220dff>; state=16 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [31]; uri=[sip:100@38.149.172.163:5060] Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [sip:100@38.149.172.163:5060 Feb 7 12:45:20 kamailion-ser kamailio: ], to tag [] Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <102> <CANCEL> Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060] - cseq: [102 CANCEL] Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:321]: check_via1_header(): check via1 header Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:558]: check_cl(): check_cl entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:583]: check_cl(): check_cl passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:632]: check_expires_value(): no expires header found Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:746]: check_parse_uris(): looking up From header Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:760]: check_parse_uris(): parsing From header Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as5a9816e5 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:804]: check_parse_uris(): looking up To header Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} tm [t_lookup.c:712]: t_lookupOriginalT(): searching on hash entry 23780 Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} tm [t_lookup.c:436]: matching_3261(): RFC3261 transaction matching failed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} tm [t_lookup.c:802]: t_lookupOriginalT(): no CANCEL matching found! Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} tm [t_lookup.c:804]: t_lookupOriginalT(): lookup completed Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} tm [tm.c:1093]: ki_t_lookup_cancel_flags(): lookup_original: t_lookupOriginalT returned: (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 220 usec Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} <core> [core/receive.c:457]: receive_msg(): cleaning up
kamailio -v version: kamailio 5.2.0 (x86_64/linux) 535e13 flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, 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: 535e13 compiled on 01:27:51 Dec 16 2018 with gcc 4.8.5
How can i fix this? Thanks!