Hi Guys,
upon further checking I'm seeing opensips sending a CANCEL as while microsoft
teams replying with a 100 Trying. Is this I'm missing something for
multi-tenancy in opensips config? I can even see a 180 Ringing coming but it
appears opensips cancelling the transaction right after it send the INVITE to
teams. Following is my opensips.cfg for aliases. I tried adding the second
domain as an alias too, but it has no effect.
Thank you
/etc/opensips.cfg
auto_aliases=no
alias=tls:voippabx.cloud:5061
alias=tls:pasanm.voippabx.cloud:5061
alias=udp:172.31.36.39:5060
listen=tls:172.31.36.39:5061
listen=udp:172.31.36.39:5060 # CUSTOMIZE ME
advertised_address=x.x.x.x
#### Transaction Module
loadmodule "tm.so"
modparam("tm", "fr_timeout", 15)
modparam("tm", "fr_inv_timeout", 90)
modparam("tm", "restart_fr_on_each_reply", 0)
modparam("tm", "onreply_avp_mode", 1)
modparam("tm", "via1_matching", 0)
modparam("tm", "ruri_matching", 0)
modparam("tls_mgm", "certificate", "/etc/opensips/tls/default.crt")
modparam("tls_mgm", "private_key","/etc/opensips/tls/default.key")
modparam("tls_mgm", "ca_list", "/etc/opensips/tls/ca-default.crt")
modparam("tls_mgm", "ca_dir", "/etc/ssl/certs/")
modparam("tls_mgm","verify_cert", "1")
modparam("tls_mgm","require_cert", "1")
modparam("tls_mgm", "server_domain", "dom1=172.31.36.39:5061")
modparam("tls_mgm","verify_cert", "[dom1]0")
modparam("tls_mgm","require_cert", "[dom1]1")
modparam("tls_mgm","tls_method", "[dom1]TLSv1_2")
modparam("tls_mgm","certificate",
"[dom1]/etc/tls/voippabx.cloud/voippabx.cloud.crt")
modparam("tls_mgm","private_key",
"[dom1]/etc/tls/voippabx.cloud/voippabx.cloud.key")
modparam("tls_mgm", "ca_list",
"[dom1]/etc/tls/voippabx.cloud/voippabx.cloud-ca.crt")
modparam("tls_mgm", "ca_dir", "[dom1]/etc/ssl/certs/")
modparam("tls_mgm", "tls_handshake_timeout", 3000)
modparam("proto_tls", "tls_max_msg_chunks", 4048)
--- fail call log of inbound call to teams ---
[29809] DBG:proto_tls:tls_update_fd: New fd is 73
[29809] DBG:proto_tls:tls_write: write was successful (1240 bytes)
[29809] DBG:proto_tls:proto_tls_send: after write: c= 0x7fa175ec28e8 n=1240
fd=73
[29809] DBG:proto_tls:proto_tls_send: buf=
INVITE sip:[email protected] SIP/2.0
Record-Route:
<sip:pasanm.voippabx.cloud:5061;transport=tls;ftag=as0e54f44e;lr;r2=on>
Record-Route: <sip:172.31.36.39:5060;ftag=as0e54f44e;lr;r2=on>
Via: SIP/2.0/TLS a.a.a.a:5061;branch=z9hG4bKa8.655a009.0;i=0599f386
Via: SIP/2.0/TLS
b.b.b.b:5061;received=b.b.b.b;branch=z9hG4bK4449b234;rport=34212
Max-Forwards: 69
From: "Private" <sip:[email protected]>;tag=as0e54f44e
To: <sip:[email protected]>
Contact: <sip:[email protected]:5061;transport=tls>
Call-ID: [email protected]:5061
CSeq: 102 INVITE
User-Agent: Asterisk PBX 16.2.1~dfsg-1+deb10u2
Date: Thu, 02 Sep 2021 11:14:53 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces
Content-Type: application/sdp
Content-Length: 339
#015
v=0
o=root 698222221 698222221 IN IP4 b.b.b.b
s=Asterisk PBX 16.2.1~dfsg-1+deb10u2
c=IN IP4 b.b.b.b
t=0 0
m=audio 11364 RTP/SAVP 8 101
a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:EQ71mHmln2YJHJn8ujv0J/v+MiH6XJlfv7lSiXsv
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv
[29809] DBG:tm:insert_timer_unsafe: [0]: 0x7fa175f4c480 (939)
[29809] DBG:tm:do_t_cleanup: transaction 0x7fa175f4c230 already updated!
Skipping update!
[29809] DBG:tm:t_unref: UNREF_UNSAFE: [0x7fa175f4c230] after is 0
[29809] DBG:core:destroy_avp_list: destroying list (nil)
[29809] DBG:core:receive_msg: cleaning up
[29809] DBG:proto_tls:tls_read_req: tls_read_req end
[29809] DBG:proto_tls:tls_read_req: Using the global ( per process ) buff
[29809] DBG:proto_tls:tls_update_fd: New fd is 5
[29809] DBG:proto_tls:_tls_read: 460 bytes read
[29809] DBG:proto_tls:tcp_handle_req: content-length= 0
[29809] DBG:proto_tls:tcp_handle_req: Nothing more to read on TCP conn
0x7fa175ea5000, currently in state 0
[29809] DBG:core:parse_msg: SIP Request:
[29809] DBG:core:parse_msg: method: <CANCEL>
[29809] DBG:core:parse_msg: uri:
<sip:[email protected]>
[29809] DBG:core:parse_msg: version: <SIP/2.0>
[29809] DBG:core:parse_headers: flags=ffffffffffffffff
[29809] DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK4449b234>; state=6
[29809] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>;
state=17
[29809] DBG:core:parse_via: end of header reached, state=5
[29809] DBG:core:parse_headers: via found, flags=ffffffffffffffff
[29809] DBG:core:parse_headers: this is the first via
[29809] DBG:core:_parse_to: end of header reached, state=10
[29809] DBG:core:_parse_to: display={},
ruri={sip:[email protected]}
[29809] DBG:core:get_hdr_field: <To> [46];
uri=[sip:[email protected]]
[29809] DBG:core:get_hdr_field: to body
[<sip:[email protected]>
]
[29809] DBG:core:get_hdr_field: cseq <CSeq>: <102> <CANCEL>
[29809] DBG:core:get_hdr_field: content_length=0
[29809] DBG:core:get_hdr_field: found end of header
[29809] DBG:core:receive_msg: After parse_msg...
[29809] DBG:core:receive_msg: preparing to run routing scripts...
[29809] DBG:maxfwd:is_maxfwd_present: value = 70
[29809] DBG:core:parse_headers: flags=78
[29809] DBG:tm:t_lookupOriginalT: searching on hash entry 138
[29809] DBG:tm:matching_3261: RFC3261 transaction matched, tid=4449b234
[29809] DBG:tm:t_lookupOriginalT: canceled transaction found
(0x7fa175f4c230)!
[29809] DBG:tm:t_lookupOriginalT: REF_UNSAFE:[0x7fa175f4c230] after is 1
[29809] DBG:tm:t_lookupOriginalT: t_lookupOriginalT completed
[29809] DBG:uri:has_totag: no totag
[29809] DBG:core:parse_headers: flags=78
[29809] DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff
[29809] DBG:core:parse_headers: flags=ffffffffffffffff
[29809] DBG:core:parse_headers: flags=78
[29809] DBG:tm:t_lookup_request: start searching: hash=138, isACK=0
[29809] DBG:tm:matching_3261: RFC3261 transaction matching failed
[29809] DBG:tm:t_lookup_request: no transaction found
[29809] DBG:core:MD5StringArray: MD5 calculated:
691657b3333bfaff8b58f9a39aceccad
[29809] DBG:core:parse_headers: flags=ffffffffffffffff
[29809] DBG:core:_shm_resize: resize(0) called
[29809] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
[29809] DBG:tm:insert_timer_unsafe: [2]: 0x7fa175f6d250 (929)
[29809] DBG:core:tcp_conn_get: con found in state 0
[29809] DBG:core:tcp_conn_get: tcp connection found (0x7fa175ea5000) already
in this process ( 14 ) , fd = 5
[29809] DBG:proto_tls:proto_tls_send: sending via fd 5...
[29809] DBG:proto_tls:tls_update_fd: New fd is 5
[29809] DBG:proto_tls:tls_write: write was successful (415 bytes)
[29809] DBG:proto_tls:proto_tls_send: after write: c= 0x7fa175ea5000 n=415
fd=5
[29809] DBG:proto_tls:proto_tls_send: buf=
SIP/2.0 200 canceling
Via: SIP/2.0/TLS
b.b.b.b:5061;received=b.b.b.b;branch=z9hG4bK4449b234;rport=34212
From: "Private" <sip:[email protected]>;tag=as0e54f44e
To:
<sip:[email protected]>;tag=b731-691657b3333bfaff8b58f9a39aceccad
Call-ID: [email protected]:5061
CSeq: 102 CANCEL
Server: OpenSIPS (2.4.8 (x86_64/linux))
Content-Length: 0
#015
[29809] DBG:tm:_reply_light: reply sent out. buf=0x7fa17de3dfa0: SIP/2.0
2..., shmem=0x7fa175f07700: SIP/2.0 2
[29811] DBG:core:parse_msg: SIP Reply (status):
[29811] DBG:core:parse_msg: version: <SIP/2.0>
[29811] DBG:core:parse_msg: status: <100>
[29811] DBG:core:parse_msg: reason: <Trying>
[29811] DBG:core:parse_headers: flags=ffffffffffffffff
[29811] DBG:core:_parse_to: end of header reached, state=10
[29811] DBG:core:_parse_to: display={},
ruri={sip:[email protected]}
[29811] DBG:core:get_hdr_field: <TO> [46];
uri=[sip:[email protected]]
[29811] DBG:core:get_hdr_field: to body
[<sip:[email protected]>
]
[29811] DBG:core:get_hdr_field: cseq <CSEQ>: <102> <INVITE>
[29811] DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bKa8.655a009.0>; state=6
[29811] DBG:core:parse_via_param: found param type 236, <i> = <0599f386>;
state=9
[29811] DBG:core:parse_via: next_via
[29811] DBG:core:parse_via_param: found param type 234, <received> =
<b.b.b.b>; state=6
[29811] DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK4449b234>; state=6
[29811] DBG:core:parse_via_param: found param type 235, <rport> = <34212>;
state=16
[29811] DBG:core:parse_via: end of header reached, state=5
[29811] DBG:core:parse_headers: via found, flags=ffffffffffffffff
[29811] DBG:core:parse_headers: this is the first via
[29811] DBG:core:get_hdr_field: content_length=0
[29811] DBG:core:get_hdr_field: found end of header
[29811] DBG:core:receive_msg: After parse_msg...
[29811] DBG:core:forward_reply: found module tm, passing reply to it
[29811] DBG:tm:t_check: start=0xffffffffffffffff
[29811] DBG:core:parse_headers: flags=22
[29811] DBG:core:parse_headers: flags=8
[29811] DBG:tm:t_reply_matching: hash 138 label 151037270 branch 0
[29811] DBG:tm:t_reply_matching: REF_UNSAFE:[0x7fa175f4c230] after is 1
[29811] DBG:tm:t_reply_matching: reply matched (T=0x7fa175f4c230)!
[29811] DBG:tm:t_check: end=0x7fa175f4c230
[29811] DBG:tm:reply_received: org. status uas=100, uac[0]=0 local=0
is_invite=1)
[29811] incoming reply: RR=Trying, RS=100, SI=52.114.16.74
[email protected]:5061
[29811] DBG:tm:build_local: using FROM=<From: "Private"
<sip:[email protected]>;tag=as0e54f44e
>, TO=<To: <sip:[email protected]>
>, CSEQ_N=<CSeq: 102>
[29811] DBG:tm:cancel_branch: sending cancel...
[29811] DBG:core:tcp_conn_get: con found in state 0
[29811] DBG:core:tcp_conn_get: tcp connection found (0x7fa175ec28e8) already
in this process ( 16 ) , fd = 5
[29811] DBG:proto_tls:proto_tls_send: sending via fd 5...
[29811] DBG:proto_tls:tls_update_fd: New fd is 5
[29811] DBG:proto_tls:tls_write: write was successful (398 bytes)
[29811] DBG:proto_tls:proto_tls_send: after write: c= 0x7fa175ec28e8 n=398
fd=5
[29811] DBG:proto_tls:proto_tls_send: buf=
CANCEL sip:[email protected] SIP/2.0
Via: SIP/2.0/TLS a.a.a.a:5061;branch=z9hG4bKa8.655a009.0
From: "Private" <sip:[email protected]>;tag=as0e54f44e
Call-ID: [email protected]:5061
To: <sip:[email protected]>
CSeq: 102 CANCEL
Max-Forwards: 70
User-Agent: OpenSIPS (2.4.8 (x86_64/linux))
Content-Length: 0
#015
[29811] DBG:tm:insert_timer_unsafe: [0]: 0x7fa175f4c548 (939)
[29811] DBG:tm:t_should_relay_response: T_code=100, new_code=100
[29811] DBG:tm:relay_reply: T_state=5, branch=0, save=0, relay=-1,
cancel_BM=0
[29811] DBG:tm:reply_received: FR_INV_TIMER = 90
[29811] DBG:tm:set_timer: relative timeout is 90
[29811] DBG:tm:insert_timer_unsafe: [1]: 0x7fa175f4c480 (1014)
SIP/2.0 180 Ringing
FROM: "Private"<sip:[email protected]>;tag=as5d689a00
TO:
<sip:[email protected]>;tag=e4748eaef0f44bf687956fe76d968596
CSEQ: 102 INVITE
CALL-ID: [email protected]:5061
VIA: SIP/2.0/TLS
b.b.b.b:5061;received=b.b.b.b;branch=z9hG4bK502b3c25;rport=34212
RECORD-ROUTE:
<sip:sip-du-a-au.pstnhub.microsoft.com:5061;transport=tls;lr>,<sip:pasanm.voippabx.cloud:5061;transport=tls;ftag=as5d689a00;lr;r2=on>,<sip:172.31.36.39:5060;ftag=as5d689a00;lr;r2=on>
CONTACT:
<sip:api-du-a-auea.pstnhub.microsoft.com:443;x-i=f65bd2eb-86c9-4a76-85ea-84f5df8f4635;x-c=595513d129e95e99bf4e9e900b804fe1/s/1/e4f1e971d27f46829c743e805ba58c16>
CONTENT-LENGTH: 0
ALLOW: INVITE,ACK,OPTIONS,CANCEL,BYE,NOTIFY
SERVER: Microsoft.PSTNHub.SIPProxy v.2021.8.30.8 i.AUEA.2
#015
DBG:tm:relay_reply: sent buf=0x7fa17de3e820: SIP/2.0 1...,
shmem=0x7fa175f768a8: SIP/2.0 1
DBG:tm:reply_received: FR_INV_TIMER = 90
DBG:tm:set_timer: relative timeout is 90
DBG:tm:insert_timer_unsafe: [1]: 0x7fa175f4c480 (1721)
DBG:tm:t_unref: UNREF_UNSAFE: [0x7fa175f4c230] after is 0
DBG:core:destroy_avp_list: destroying list (nil)
DBG:core:receive_msg: cleaning up
DBG:proto_tls:tls_read_req: tls_read_req end
DBG:proto_tls:tls_read_req: Using the global ( per process ) buff
DBG:proto_tls:tls_update_fd: New fd is 5
DBG:proto_tls:_tls_read: 460 bytes read
DBG:proto_tls:tcp_handle_req: content-length= 0
DBG:proto_tls:tcp_handle_req: Nothing more to read on TCP conn 0x7fa175ea5000,
currently in state 0
DBG:core:parse_msg: SIP Request:
DBG:core:parse_msg: method: <CANCEL>
DBG:core:parse_msg: uri: <sip:[email protected]>
DBG:core:parse_msg: version: <SIP/2.0>
DBG:core:parse_headers: flags=ffffffffffffffff
DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK502b3c25>;
state=6
DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17
DBG:core:parse_via: end of header reached, state=5
DBG:core:parse_headers: via found, flags=ffffffffffffffff
DBG:core:parse_headers: this is the first via
DBG:core:_parse_to: end of header reached, state=10
DBG:core:_parse_to: display={},
ruri={sip:[email protected]}
DBG:core:get_hdr_field: <To> [46];
uri=[sip:[email protected]]
DBG:core:get_hdr_field: to body [<sip:[email protected]>
]
DBG:core:get_hdr_field: cseq <CSeq>: <102> <CANCEL>
DBG:core:get_hdr_field: content_length=0
DBG:core:get_hdr_field: found end of header
DBG:core:receive_msg: After parse_msg...
DBG:core:receive_msg: preparing to run routing scripts...
DBG:maxfwd:is_maxfwd_present: value = 70
DBG:core:parse_headers: flags=78
DBG:tm:t_lookupOriginalT: searching on hash entry 19441
DBG:tm:matching_3261: RFC3261 transaction matched, tid=502b3c25
DBG:tm:t_lookupOriginalT: canceled transaction found (0x7fa175f4c230)!
DBG:tm:t_lookupOriginalT: REF_UNSAFE:[0x7fa175f4c230] after is 1
DBG:tm:t_lookupOriginalT: t_lookupOriginalT completed
DBG:uri:has_totag: no totag
DBG:core:parse_headers: flags=78
DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff
DBG:core:parse_headers: flags=ffffffffffffffff
DBG:core:parse_headers: flags=78
DBG:tm:t_lookup_request: start searching: hash=19441, isACK=0
DBG:tm:matching_3261: RFC3261 transaction matching failed
DBG:tm:t_lookup_request: no transaction found
DBG:core:MD5StringArray: MD5 calculated: 31453c5e285c477e8c5ea130fd29f816
DBG:core:parse_headers: flags=ffffffffffffffff
DBG:core:_shm_resize: resize(0) called
DBG:tm:cleanup_uac_timers: RETR/FR timers reset
DBG:tm:insert_timer_unsafe: [2]: 0x7fa175f6d250 (1636)
DBG:core:tcp_conn_get: con found in state 0
DBG:core:tcp_conn_get: tcp connection found (0x7fa175ea5000) already in this
process ( 14 ) , fd = 5
DBG:proto_tls:proto_tls_send: sending via fd 5...
DBG:proto_tls:tls_update_fd: New fd is 5
DBG:proto_tls:tls_write: write was successful (415 bytes)
DBG:proto_tls:proto_tls_send: after write: c= 0x7fa175ea5000 n=415 fd=5
DBG:proto_tls:proto_tls_send: buf=
SIP/2.0 200 canceling
Via: SIP/2.0/TLS
b.b.b.b:5061;received=b.b.b.b;branch=z9hG4bK502b3c25;rport=34212
From: "Private" <sip:[email protected]>;tag=as5d689a00
To:
<sip:[email protected]>;tag=b731-31453c5e285c477e8c5ea130fd29f816
Call-ID: [email protected]:5061
CSeq: 102 CANCEL
Server: OpenSIPS (2.4.8 (x86_64/linux))
Content-Length: 0
#015
Distinguishing What && How !
On Wednesday, 1 September 2021, 03:07:59 pm GMT+5:30, Pasan Meemaduma via
Users <[email protected]> wrote:
Hi All,
I hope all of you are well and safe. I was able to setup teams direct routing
referring to this blogpost
https://blog.opensips.org/2019/09/16/opensips-as-ms-teams-sbc/
When I add a second tenant, incoming calls to the second tenant don't work, as
Microsoft teams not responding to the invite. outgoing calls from the second
tenant works fine.
I have configured the second tenant using a derived trunk. any idea why
following INVITE not respond by Microsoft but later (first tenant INVITE )
works?
------ SECOND TENANT INVITE -------
Sep 1 17:13:47 msteams-sbc opensips[26043]: INVITE
sip:[email protected] SIP/2.0
Sep 1 17:13:47 msteams-sbc opensips[26043]: Record-Route:
<sip:pasanm.voippabx.cloud:5061;transport=tls;ftag=as0e9dc8dc;lr;r2=on>
Sep 1 17:13:47 msteams-sbc opensips[26043]: Record-Route:
<sip:172.31.36.39:5060;ftag=as0e9dc8dc;lr;r2=on>
Sep 1 17:13:47 msteams-sbc opensips[26043]: Via: SIP/2.0/TLS
x.x.x.x:5061;branch=z9hG4bKf0c.bd20fe7.0;i=609325e7
Sep 1 17:13:47 msteams-sbc opensips[26043]: Via: SIP/2.0/TLS
y.y.y.y:5061;received=y.y.y.y;branch=z9hG4bK54c25df9;rport=49408
Sep 1 17:13:47 msteams-sbc opensips[26043]: Max-Forwards: 69
Sep 1 17:13:47 msteams-sbc opensips[26043]: From: "Private"
<sip:[email protected]>;tag=as0e9dc8dc
Sep 1 17:13:47 msteams-sbc opensips[26043]: To:
<sip:[email protected]>
Sep 1 17:13:47 msteams-sbc opensips[26043]: Contact:
<sip:[email protected]:5061;transport=tls>
---FIRST TENANT INVITE---- (WORKING)
Sep 1 17:17:46 msteams-sbc opensips[26043]: INVITE
sip:[email protected] SIP/2.0
Sep 1 17:17:46 msteams-sbc opensips[26043]: Record-Route:
<sip:voippabx.cloud:5061;transport=tls;ftag=as5e20130f;lr;r2=on>
Sep 1 17:17:46 msteams-sbc opensips[26043]: Record-Route:
<sip:172.31.36.39:5060;ftag=as5e20130f;lr;r2=on>
Sep 1 17:17:46 msteams-sbc opensips[26043]: Via: SIP/2.0/TLS
x.x.x.x:5061;branch=z9hG4bKe5f8.239f87a3.0;i=009325e7
Sep 1 17:17:46 msteams-sbc opensips[26043]: Via: SIP/2.0/TLS
z.z.z.z:5061;received=z.z.z.z;branch=z9hG4bK7ff0149e;rport=44650
Sep 1 17:17:46 msteams-sbc opensips[26043]: Max-Forwards: 69
Sep 1 17:17:46 msteams-sbc opensips[26043]: From: "Extension"
<sip:[email protected]>;tag=as5e20130f
Sep 1 17:17:46 msteams-sbc opensips[26043]: To:
<sip:[email protected]>
Sep 1 17:17:46 msteams-sbc opensips[26043]: Contact:
<sip:[email protected]:5061;transport=tls>
I only have voippabx.cloud configured as a sbc on first Tenant. As per the
above documentation I'm putting correct domain on RR header. Did I miss
anything? Thank you.
Distinguishing What && How
!_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
