Trying to setup Opensips as SBC for MS Teams.

[VoipTerminator1]

I m trying to setup opensips as SBC for MS Teams . I m using version 3.1
certificates are configured. But when probing packets are sent to MS it fails Below are logs .

DBG:core:parse_msg: SIP Request:
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_msg: method:
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_msg: uri: sip:sip3.pstnhub.microsoft.com
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_msg: version: <SIP/2.0>
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_via_param: found param type 232, = <z9hG4bKefbd.2f2fa4.0>; state=16
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_via: end of header reached, state=5
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: via found, flags=ffffffffffffffff
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: this is the first via
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:_parse_to: end of header reached, state=9
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:_parse_to: display={}, ruri={sip:sip3.pstnhub.microsoft.com}
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:get_hdr_field: [32]; uri=[sip:sip3.pstnhub.microsoft.com]
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:get_hdr_field: to body [sip:sip3.pstnhub.microsoft.com#015#012]
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:get_hdr_field: cseq : <14>
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:get_hdr_field: content_length=0
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:get_hdr_field: found end of header
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: flags=78
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:tm:run_local_route: Change in local route -> rebuilding buffer
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: flags=2000
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:extract_ftc_hdrs: flags = 15
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:extract_ftc_hdrs: hdr 2 extracted as <To: sip:sip3.pstnhub.microsoft.com#015#012>
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:extract_ftc_hdrs: hdr 1 extracted as <From: sip:pinger@sbc.expertflow.com;tag=18bc3d90336c8efb57e37a2b9b811e43-aab0#015#012>
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:extract_ftc_hdrs: hdr 8 extracted as <Call-ID: 360937f37456ee26-10641@<OPENSIP_IP>#15#012>
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:proto_tls:proto_tls_send: no open tcp connection found, opening new one
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:probe_max_sock_buff: getsockopt: snd is initially 16384
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:probe_max_sock_buff: using snd buffer of 416 kb
Jul 8 15:26:16 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:init_sock_keepalive: TCP keepalive enabled on socket 5
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:print_ip: tcpconn_new: new tcp connection to: 52.114.32.169
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:tcpconn_new: on port 5061, proto 3
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: DBG:proto_tls:tls_conn_init: Creating a whole new ssl connection
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: ERROR:proto_tls:tls_conn_init: no TLS client domain found
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: ERROR:core:tcp_conn_new: failed to do proto 3 specific init for conn 0x7ff72f73b5e0
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: DBG:core:tcpconn_destroy: destroying connection 0x7ff72f73b5e0, flags 0018
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: ERROR:proto_tls:tls_sync_connect: tcp_conn_create failed, closing the socket
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: ERROR:proto_tls:proto_tls_send: connect failed
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: ERROR:tm:msg_send: send() to 52.114.32.169:5061 for proto tls/3 failed
Jul 8 15:26:17 debian10-openSIP /usr/sbin/opensips[10641]: ERROR:tm:t_uac: attempt to send to 'sip:sip3.pstnhub.microsoft.com' failed

Any help will be appreciated.

Regards
AHmed

[rvlad-patrascu]

Hi @VoipTerminator1 ,

Can you post your tls_mgm settings?

[VoipTerminator1]

Hi @rvlad-patrascu thank you for reply

Here is my tls_mgm settings

modparam("tls_mgm", "server_domain", "sbc.com")
modparam("tls_mgm", "match_ip_address", "[sbc.com]<opensip_IP>5061")
modparam("tls_mgm", "match_sip_domain", "[sbc.com]sbc.com")

modparam("tls_mgm", "verify_cert", "[sbc.com]1")
modparam("tls_mgm", "require_cert", "[sbc.com]1")
modparam("tls_mgm", "tls_method", "[sbc.com]TLSv1-")
modparam("tls_mgm", "certificate", "[sbc.com]/etc/opensips/tls/sbc.com/fullchain.pem")
modparam("tls_mgm", "private_key", "[sbc.com]/etc/opensips/tls/sbc.com/privkey.pem")
modparam("tls_mgm", "ca_list", "[sbc.com]/etc/opensips/tls/sbc.com/cert.pem")
modparam("proto_tls", "tls_handshake_timeout", 300)
modparam("proto_tls", "tls_send_timeout", 2000)
modparam("proto_tls", "tls_max_msg_chunks", 8)

i ve changed my original domain name with sbc.com

[rvlad-patrascu]

It looks like you have not configured a TLS client domain, which is required for initiating TLS connections from OpenSIPS.

[VoipTerminator1]

modparam("tls_mgm", "client_domain", "sbc")
modparam("tls_mgm", "match_sip_domain", "[sbc]*.pstnhub.microsoft.com")

modparam("tls_mgm", "verify_cert", "[sbc]1")
modparam("tls_mgm", "require_cert", "[sbc]1")
modparam("tls_mgm", "tls_method", "[sbc]TLSv1-")
modparam("tls_mgm", "certificate", "[sbc]/etc/opensips/tls/sbc.com/fullchain.pem")
modparam("tls_mgm", "private_key", "[sbc]/etc/opensips/tls/sbc.com/privkey.pem")
modparam("tls_mgm", "ca_list", "[sbc]/etc/opensips/tls/sbc.com/cert.pem")
modparam("proto_tls", "tls_handshake_timeout", 300)
modparam("proto_tls", "tls_send_timeout", 2000)

here is config for TLS client domain

[VoipTerminator1]

modparam("tls_mgm", "client_domain", "sbc")
modparam("tls_mgm", "match_sip_domain", "[sbc]*.pstnhub.microsoft.com")

modparam("tls_mgm", "verify_cert", "[sbc]1")
modparam("tls_mgm", "require_cert", "[sbc]1")
modparam("tls_mgm", "tls_method", "[sbc]TLSv1-")
modparam("tls_mgm", "certificate", "[sbc]/etc/opensips/tls/sbc.com/fullchain.pem")
modparam("tls_mgm", "private_key", "[sbc]/etc/opensips/tls/sbc.com/privkey.pem")
modparam("tls_mgm", "ca_list", "[sbc]/etc/opensips/tls/sbc.com/cert.pem")
modparam("proto_tls", "tls_handshake_timeout", 300)
modparam("proto_tls", "tls_send_timeout", 2000)

modparam("tls_mgm", "server_domain", "sbc.com")
modparam("tls_mgm", "match_ip_address", "[sbc.com]<opensip_IP>5061")
modparam("tls_mgm", "match_sip_domain", "[sbc.com]sbc.com")

modparam("tls_mgm", "verify_cert", "[sbc.com]1")
modparam("tls_mgm", "require_cert", "[sbc.com]1")
modparam("tls_mgm", "tls_method", "[sbc.com]TLSv1-")
modparam("tls_mgm", "certificate", "[sbc.com]/etc/opensips/tls/sbc.com/fullchain.pem")
modparam("tls_mgm", "private_key", "[sbc.com]/etc/opensips/tls/sbc.com/privkey.pem")
modparam("tls_mgm", "ca_list", "[sbc.com]/etc/opensips/tls/sbc.com/cert.pem")
modparam("proto_tls", "tls_handshake_timeout", 300)
modparam("proto_tls", "tls_send_timeout", 2000)
modparam("proto_tls", "tls_max_msg_chunks", 8)

here is the complete config of tls_mgm

[rvlad-patrascu]

Do you set the client_sip_domain_avp in the script before sending a message? If not, can you try setting modparam("tls_mgm", "match_sip_domain", "[sbc]*") ?

[VoipTerminator1]

Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12076]: DBG:core:io_watch_del: [TCP_main] io_watch_del op on index 1 98 (0x5595fe28f500, 98, 1, 0x0,0x1) fd_no=24 called
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12076]: DBG:core:send2worker: to tcp worker 0 (0), 0x7fce6183a140 rw 1
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: NOTICE:tls_mgm:verify_callback: depth = 1, verify failure
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: NOTICE:tls_mgm:verify_callback: subject = /C=US/O=Microsoft Corporation/CN=Microsoft RSA TLS CA 02
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: NOTICE:tls_mgm:verify_callback: issuer = /C=IE/O=Baltimore/OU=CyberTrust/CN=Baltimore CyberTrust Root
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: NOTICE:tls_mgm:verify_callback: verify error: unable to get local issuer certificate [error=20]
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: ERROR:proto_tls:tls_connect: New TLS connection to 52.114.32.169:5061 failed
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: ERROR:proto_tls:tls_connect: TLS error: 1 (ret=-1) err=Success(0)
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:proto_tls:proto_tls_send: after write: c= 0x7fce6183a140 n=-1 fd=5
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:proto_tls:proto_tls_send: buf=#012OPTIONS sip:sip.pstnhub.microsoft.com SIP/2.0#015#012Via: SIP/2.0/TLS 104.248.14.215:5061;branch=z9hG4bKafbd.db0d439.1;i=0#015#012To: sip:sip.pstnhub.microsoft.com#015#012From: sip:pinger@sbc.expertflow.com;tag=18bc3d90336c8efb57e37a2b9b811e43-9dad#015#012CSeq: 14 OPTIONS#015#012Call-ID: 231432034b23d5a8-12071@104.248.14.215#015#012Max-Forwards: 70#015#012Content-Length: 0#015#012User-Agent: OpenSIPS (3.1.2 (x86_64/linux))#15#012Contact: sip:sbc.expertflow.com:5061;transport=tls#15#012#015#012
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: ERROR:proto_tls:proto_tls_send: failed to send
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:core:tcpconn_release: releasing con 0x7fce6183a140, state -2, fd=-1, id=1712064796
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:core:tcpconn_release: extra_data 0x7fce6181d6c8
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: ERROR:tm:msg_send: send() to 52.114.32.169:5061 for proto tls/3 failed
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: ERROR:tm:t_forward_nonack: sending request failed
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:tm:local_reply: branch=0, save=0, winner=0
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:tm:local_reply: local transaction completed
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:tm:run_trans_callbacks: trans=0x7fce6183ee60, callback type 256, id 0 entered
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:tm:insert_timer_unsafe: [2]: 0x7fce6183eee0 (310)
Jul 8 17:53:54 debian10-openSIP /usr/sbin/opensips[12074]: DBG:tm:final_response_handler: done

great modparam("tls_mgm", "match_sip_domain", "[sbc]*") this thing works but getting error of local issuer certificate

[rvlad-patrascu]

@VoipTerminator1 This could indicate an issue with the CA certificate. Does openssl verify -CAfile /etc/opensips/tls/sbc.com/cert.pem /etc/opensips/tls/sbc.com/fullchain.pem successfully verify your certerificate ?

[VoipTerminator1]

Hi @rvlad-patrascu @bogdan-iancu Now i can see the TLS connection is being established with MS servers. But getting following error in logs where OS trying to send Options packets but during this it gets
DBG:proto_tls:proto_tls_send: no open tcp connection found, opening new one
Any help will be appreciated.

Here is full log
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_msg: SIP Request:
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_msg: method:
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_msg: uri: sip:sip2.pstnhub.microsoft.com
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_msg: version: <SIP/2.0>
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: flags=ffffffffffffffff
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_via_param: found param type 232, = <z9hG4bKf04a.b90a2864.0>; state=16
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_via: end of header reached, state=5
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: via found, flags=ffffffffffffffff
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: this is the first via
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:_parse_to: end of header reached, state=9
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:_parse_to: display={}, ruri={sip:sip2.pstnhub.microsoft.com}
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:get_hdr_field: [32]; uri=[sip:sip2.pstnhub.microsoft.com]
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:get_hdr_field: to body [sip:sip2.pstnhub.microsoft.com#015#012]
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:get_hdr_field: cseq : <14>
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:get_hdr_field: content_length=0
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:get_hdr_field: found end of header
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: flags=ffffffffffffffff
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: flags=78
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: flags=ffffffffffffffff
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:tm:run_local_route: Change in local route -> rebuilding buffer
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: flags=2000
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:parse_headers: flags=ffffffffffffffff
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:extract_ftc_hdrs: flags = 15
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:extract_ftc_hdrs: hdr 2 extracted as <To: sip:sip2.pstnhub.microsoft.com#015#012>
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:extract_ftc_hdrs: hdr 1 extracted as <From: sip:sbc.com;tag=18bc3d90336c8efb57e37a2b9b811e43-5dc8#015#012>
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:extract_ftc_hdrs: hdr 8 extracted as <Call-ID: 063fc45145f47e38-10076@104.248.14.215#015#012>
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:proto_tls:proto_tls_send: no open tcp connection found, opening new one
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:probe_max_sock_buff: getsockopt: snd is initially 16384
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:probe_max_sock_buff: using snd buffer of 416 kb
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:init_sock_keepalive: TCP keepalive enabled on socket 5
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:print_ip: tcpconn_new: new tcp connection to: 52.114.76.76
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:core:tcpconn_new: on port 5061, proto 3
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:proto_tls:tls_conn_init: Creating a whole new ssl connection
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:tls_mgm:tls_find_client_domain: found TLS client domain: sbc.expertflow.com
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:proto_tls:tls_conn_init: Setting in CONNECT mode (client)
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:proto_tls:proto_tls_send: sending via fd 5...
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10076]: DBG:proto_tls:tls_update_fd: New fd is 5
Aug 4 21:43:38 debian10-openSIP /usr/sbin/opensips[10079]: DBG:core:handle_worker: read response= 7f4c840245f8, 2, fd 98 from 11 (10076)

[bogdan-iancu]

This report proved not to be a TLS issue at all. From this point further it is a matter of using and configuring OpenSIPS, which is outside the scope of this tracker (for bugs, issues, feature requests).
@VoipTerminator1 , please use the public "users" mailing list for seeking guidance on OpenSIPS usage - http://lists.opensips.org/cgi-bin/mailman/listinfo/users