<p>Hello,</p>
<p>I'm trying to set up kamailio as a simple load balancer proxy between VOIP Providers<br>
and a cluster of asterisk servers.</p>
<p>I have started with the default kamailio.cfg.</p>
<p>At the end, i got this up and running, but with one exception: if incoming<br>
call is not answered by the asterisk end (i.e. it is in ringing state), and<br>
then the gateway sends CANCEL request, kamailio is unable to recognize the<br>
transaction and is not forwarding the request to asterisk. The result is:<br>
the call is left "dangling" in the PBX and is not properly hang up.</p>
<p>I have call flow: Provider 214.22.198.51 -> Kamailio 38.149.172.163 -> Asterisk 38.149.172.164.</p>
<p><strong>Log from Provider 214.22.198.51</strong></p>
<p>Reliably Transmitting (no NAT) to 38.149.172.163:5060:<br>
INVITE sip:100@38.149.172.163:5060 SIP/2.0<br>
Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff<br>
Max-Forwards: 70<br>
From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5<br>
To: sip:100@38.149.172.163:5060<br>
Contact: sip:123456@214.22.198.51:5060<br>
Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060<br>
CSeq: 102 INVITE<br>
User-Agent: Asterisk PBX 14.6.2<br>
Date: Thu, 07 Feb 2019 10:45:15 GMT<br>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE<br>
Supported: replaces, timer<br>
Content-Type: application/sdp<br>
Content-Length: 310</p>
<p>v=0<br>
o=root 610375704 610375704 IN IP4 214.22.198.51<br>
s=Asterisk PBX 14.6.2<br>
c=IN IP4 214.22.198.51<br>
t=0 0<br>
m=audio 13076 RTP/AVP 18 8 0 101<br>
a=rtpmap:18 G729/8000<br>
a=fmtp:18 annexb=no<br>
a=rtpmap:8 PCMA/8000<br>
a=rtpmap:0 PCMU/8000<br>
a=rtpmap:101 telephone-event/8000<br>
a=fmtp:101 0-16<br>
a=maxptime:150<br>
a=sendrecv</p>
<hr>
<pre><code>-- Called SIP/kamailio/100
</code></pre>
<p><--- SIP read from UDP:38.149.172.163:5060 ---><br>
SIP/2.0 100 Trying<br>
Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff<br>
From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5<br>
To: sip:100@38.149.172.163:5060<br>
Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060<br>
CSeq: 102 INVITE<br>
Server: kamailio (5.2.0 (x86_64/linux))<br>
Content-Length: 0</p>
<p><-------------><br>
--- (8 headers 0 lines) ---</p>
<p><--- SIP read from UDP:38.149.172.163:5060 ---><br>
SIP/2.0 100 Trying<br>
Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff<br>
From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5<br>
To: sip:100@38.149.172.163:5060<br>
Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060<br>
CSeq: 102 INVITE<br>
Server: Asterisk PBX 16.1.1<br>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE<br>
Supported: replaces, timer<br>
Session-Expires: 1800;refresher=uas<br>
Contact: sip:100@38.149.172.164:5060<br>
Content-Length: 0</p>
<p><-------------><br>
--- (12 headers 0 lines) ---</p>
<p><--- SIP read from UDP:38.149.172.163:5060 ---><br>
SIP/2.0 180 Ringing<br>
Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff<br>
From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5<br>
To: sip:100@38.149.172.163:5060;tag=as14e62645<br>
Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060<br>
CSeq: 102 INVITE<br>
Server: Asterisk PBX 16.1.1<br>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE<br>
Supported: replaces, timer<br>
Session-Expires: 1800;refresher=uas<br>
Contact: sip:100@38.149.172.164:5060<br>
Content-Length: 0</p>
<p><-------------><br>
--- (12 headers 0 lines) ---<br>
sip_route_dump: route/path hop: sip:100@38.149.172.164:5060<br>
-- SIP/kamailio-0007f2d9 is ringing<br>
Scheduling destruction of SIP dialog '0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060' in 32000 ms (Method: INVITE)<br>
Reliably Transmitting (no NAT) to 38.149.172.163:5060:<br>
CANCEL sip:100@38.149.172.163:5060 SIP/2.0<br>
Via: SIP/2.0/UDP 214.22.198.51:5060;branch=z9hG4bK7d220dff<br>
Max-Forwards: 70<br>
From: "testaccount" sip:123456@214.22.198.51;tag=as5a9816e5<br>
To: sip:100@38.149.172.163:5060<br>
Call-ID: 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060<br>
CSeq: 102 CANCEL<br>
User-Agent: Asterisk PBX 14.6.2<br>
Content-Length: 0</p>
<p><strong>Kamailio 38.149.172.163</strong><br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [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]]<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:612]: parse_msg(): method: <br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:614]: parse_msg(): uri: sip:100@38.149.172.163:5060<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0><br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, = ; state=16<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:500]: parse_headers(): this is the first via<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:171]: get_hdr_field(): [31]; uri=[sip:100@38.149.172.163:5060]<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:174]: get_hdr_field(): to body [sip:100@38.149.172.163:5060<br>
Feb 7 12:45:20 kamailion-ser kamailio: ], to tag []<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:152]: get_hdr_field(): cseq : <102> <br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060] - cseq: [102 CANCEL]<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/receive.c:295]: receive_msg(): preparing to run routing scripts...<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as5a9816e5<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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<br>
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!<br>
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<br>
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)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/receive.c:353]: receive_msg(): request-route executed in: 220 usec<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)<br>
Feb 7 12:45:20 kamailion-ser kamailio: 24(22599) DEBUG: {1 102 CANCEL 0891a0e9592a055f2828c0f00af09783@214.22.198.51:5060} [core/receive.c:457]: receive_msg(): cleaning up</p>
<p>kamailio -v<br>
version: kamailio 5.2.0 (x86_64/linux) 535e13<br>
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<br>
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144 MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB<br>
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.<br>
id: 535e13<br>
compiled on 01:27:51 Dec 16 2018 with gcc 4.8.5</p>
<p>How can i fix this?<br>
Thanks!</p>
<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br />You are receiving this because you are subscribed to this thread.<br />Reply to this email directly, <a href="https://github.com/kamailio/kamailio/issues/1841">view it on GitHub</a>, or <a href="https://github.com/notifications/unsubscribe-auth/AF36ZWbkzpELyoeaG3ETVgWAH_qSLTbXks5vLAXXgaJpZM4anCmc">mute the thread</a>.<img src="https://github.com/notifications/beacon/AF36Zdl3aVeoUpQ3A1CbRVHKNX-Zzzayks5vLAXXgaJpZM4anCmc.gif" height="1" width="1" alt="" /></p>
<script type="application/json" data-scope="inboxmarkup">{"api_version":"1.0","publisher":{"api_key":"05dde50f1d1a384dd78767c55493e4bb","name":"GitHub"},"entity":{"external_key":"github/kamailio/kamailio","title":"kamailio/kamailio","subtitle":"GitHub repository","main_image_url":"https://github.githubassets.com/images/email/message_cards/header.png","avatar_image_url":"https://github.githubassets.com/images/email/message_cards/avatar.png","action":{"name":"Open in GitHub","url":"https://github.com/kamailio/kamailio"}},"updates":{"snippets":[{"icon":"DESCRIPTION","message":"Problem with CANCEL handling (#1841)"}],"action":{"name":"View Issue","url":"https://github.com/kamailio/kamailio/issues/1841"}}}</script>
<script type="application/ld+json">[
{
"@context": "http://schema.org",
"@type": "EmailMessage",
"potentialAction": {
"@type": "ViewAction",
"target": "https://github.com/kamailio/kamailio/issues/1841",
"url": "https://github.com/kamailio/kamailio/issues/1841",
"name": "View Issue"
},
"description": "View this Issue on GitHub",
"publisher": {
"@type": "Organization",
"name": "GitHub",
"url": "https://github.com"
}
}
]</script>