[OpenSIPS-Users] MS team issue
Miha
miha at softnet.si
Mon May 10 17:23:20 EST 2021
Hello
it seems for me that this works now. I only do not know why
after 200 ok, opensips sends OPTIONS also to it self, which
is quite wird.
pasting logs.
y 10 19:20:26 mtsbc opensips[7582]:
DBG:tm:print_request_uri: sip:sip.pstnhub.microsoft.com
May 10 19:20:26 mtsbc opensips[7582]:
DBG:tm:run_local_route: building sip_msg from buffer
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:parse_msg:
SIP Request:
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:parse_msg:
method: <OPTIONS>
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:parse_msg:
uri: <sip:sip.pstnhub.microsoft.com>
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:parse_msg:
version: <SIP/2.0>
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK2c5c.fa46c831.0>; state=16
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:parse_via:
end of header reached, state=5
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: via found, flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: this is the first via
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:_parse_to:
end of header reached, state=9
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:_parse_to:
display={}, ruri={sip:sip.pstnhub.microsoft.com}
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:get_hdr_field: <To> [31];
uri=[sip:sip.pstnhub.microsoft.com]
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:get_hdr_field: to body
[sip:sip.pstnhub.microsoft.com#015#012]
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:get_hdr_field: cseq <CSeq>: <14> <OPTIONS>
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:get_hdr_field: content_length=0
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:get_hdr_field: found end of header
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=78
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_to_param:
tag=a665d66adab06c7308a33b8567de92d6-7c10
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:_parse_to:
end of header reached, state=29
May 10 19:20:26 mtsbc opensips[7582]: DBG:core:_parse_to:
display={}, ruri={sip:prober at localhost}
May 10 19:20:26 mtsbc opensips[7582]:
DBG:sipcapture:w_sip_capture: src_ip: [xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7582]:
DBG:sipcapture:w_sip_capture: dst_ip: [xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7582]:
DBG:sipcapture:w_sip_capture: dst_port: [5061]
May 10 19:20:26 mtsbc opensips[7582]:
DBG:sipcapture:w_sip_capture: src_port: [5061]
May 10 19:20:26 mtsbc opensips[7582]:
DBG:sipcapture:w_sip_capture: DONE
May 10 19:20:26 mtsbc opensips[7582]:
DBG:sipcapture:db_sync_store: storing info...
May 10 19:20:26 mtsbc opensips[7582]:
DBG:db_mysql:db_mysql_do_prepared_query:
conn=0x7f60225e6108 (tail=140050870197640)
MC=0x7f60225e6218
May 10 19:20:26 mtsbc opensips[7582]:
DBG:db_mysql:db_mysql_do_prepared_query: new query=|insert
into sip_capture
(date,micro_ts,method,reply_reason,ruri,ruri_user,from_user,from_tag,to_user,to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,reason,content_type,auth,user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,originator_port,proto,family,rtp_stat,type,node,correlation_id,from_domain,to_domain,ruri_domain,msg,custom_field1,custom_field2,custom_field3
) values
(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)|
May 10 19:20:26 mtsbc opensips[7582]:
DBG:db_mysql:re_init_statement: query is <insert into
sip_capture
(date,micro_ts,method,reply_reason,ruri,ruri_user,from_user,from_tag,to_user,to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,reason,content_type,auth,user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,originator_port,proto,family,rtp_stat,type,node,correlation_id,from_domain,to_domain,ruri_domain,msg,custom_field1,custom_field2,custom_field3
) values
(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)>,
ptr=(nil)
May 10 19:20:26 mtsbc opensips[7582]:
DBG:tm:run_local_route: Change in local route -> rebuilding
buffer
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=2000
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:extract_ftc_hdrs: flags = 15
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:extract_ftc_hdrs: hdr 2 extracted as <To:
sip:sip.pstnhub.microsoft.com#015#012>
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:extract_ftc_hdrs: hdr 1 extracted as <From:
<sip:prober at localhost>;tag=a665d66adab06c7308a33b8567de92d6-7c10#015#012>
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:extract_ftc_hdrs: hdr 8 extracted as <Call-ID:
63f6e4340443163b-7582 at xxx.xxx.xxx.xxx#015#012>
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:tcp_conn_get: con found in state 0
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:tcp_conn_get: tcp connection found
(0x7f6005804fc8), acquiring fd
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:tcp_conn_get: c= 0x7f6005804fc8, n=16, Usock=123
May 10 19:20:26 mtsbc opensips[7583]:
DBG:core:handle_worker: read response= 7f6005804fc8, 1, fd
-1 from 17 (7582)
May 10 19:20:26 mtsbc opensips[7582]:
DBG:core:tcp_conn_get: after receive_fd: c= 0x7f6005804fc8
n=8 fd=5
May 10 19:20:26 mtsbc opensips[7582]:
DBG:proto_tls:proto_tls_send: sending via fd 5...
May 10 19:20:26 mtsbc opensips[7582]:
DBG:proto_tls:tls_update_fd: New fd is 5
May 10 19:20:26 mtsbc opensips[7582]:
DBG:proto_tls:tls_write: write was successful (423 bytes)
May 10 19:20:26 mtsbc opensips[7582]:
DBG:proto_tls:proto_tls_send: after write: c=
0x7f6005804fc8 n=423 fd=5
May 10 19:20:26 mtsbc opensips[7582]:
DBG:proto_tls:proto_tls_send: buf=#012OPTIONS
sip:sip.pstnhub.microsoft.com SIP/2.0#015#012Via:
SIP/2.0/TLS
xxx.xxx.xxx.xxx:5061;branch=z9hG4bK2c5c.fa46c831.0#015#012To:
sip:sip.pstnhub.microsoft.com#015#012From:
<sip:prober at localhost>;tag=a665d66adab06c7308a33b8567de92d6-7c10#015#012CSeq:
14 OPTIONS#015#012Call-ID:
63f6e4340443163b-7582 at xxx.xxx.xxx.xxx#015#012Max-Forwards:
70#015#012Content-Length: 0#015#012User-Agent: OpenSIPS
(3.1.1 (x86_64/linux))#015#012Contact:
<sip:mtsbc.test.com:5061;transport=tls>#015#012#015#012
May 10 19:20:26 mtsbc opensips[7582]:
DBG:tm:insert_timer_unsafe: [0]: 0x7f6005838b78 (13415)
May 10 19:20:26 mtsbc opensips[7574]:
DBG:proto_tls:tls_read_req: Using the global ( per process
) buff
May 10 19:20:26 mtsbc opensips[7574]:
DBG:proto_tls:tls_update_fd: New fd is 5
May 10 19:20:26 mtsbc opensips[7574]:
DBG:proto_tls:_tls_read: 383 bytes read
May 10 19:20:26 mtsbc opensips[7574]:
DBG:proto_tls:tcp_handle_req: content-length= 0
May 10 19:20:26 mtsbc opensips[7574]:
DBG:proto_tls:tcp_handle_req: Nothing more to read on TCP
conn 0x7f6005804fc8, currently in state 0
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:parse_msg:
SIP Reply (status):
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:parse_msg:
version: <SIP/2.0>
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:parse_msg:
status: <200>
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:parse_msg:
reason: <OK>
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:_parse_to:
end of header reached, state=10
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:_parse_to:
display={}, ruri={sip:sip.pstnhub.microsoft.com}
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:get_hdr_field: <TO> [33];
uri=[sip:sip.pstnhub.microsoft.com]
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:get_hdr_field: to body
[<sip:sip.pstnhub.microsoft.com>#015#012]
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:get_hdr_field: cseq <CSEQ>: <14> <OPTIONS>
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK2c5c.fa46c831.0>; state=16
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:parse_via:
end of header reached, state=5
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:parse_headers: via found, flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:parse_headers: this is the first via
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:get_hdr_field: content_length=0
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:get_hdr_field: found end of header
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:receive_msg:
After parse_msg...
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:forward_reply: found module tm, passing reply to
it
May 10 19:20:26 mtsbc opensips[7574]: DBG:tm:t_check:
start=0xffffffffffffffff
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:parse_headers: flags=22
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:t_reply_matching: hash 50626 label 327967919 branch
0
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:t_reply_matching: REF_UNSAFE:[0x7f6005838928] after
is 1
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:t_reply_matching: reply matched (T=0x7f6005838928)!
May 10 19:20:26 mtsbc opensips[7574]: DBG:tm:t_check:
end=0x7f6005838928
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:reply_received: org. status uas=0, uac[0]=0 local=2
is_invite=0)
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:t_should_relay_response: T_code=0, new_code=200
May 10 19:20:26 mtsbc opensips[7574]: DBG:tm:local_reply:
branch=0, save=0, winner=0
May 10 19:20:26 mtsbc opensips[7574]: DBG:tm:local_reply:
local transaction completed
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:run_trans_callbacks: trans=0x7f6005838928, callback
type 256, id 0 entered
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:cleanup_uac_timers: RETR/FR timers reset
May 10 19:20:26 mtsbc opensips[7574]:
DBG:tm:insert_timer_unsafe: [2]: 0x7f60058389a8 (13415)
May 10 19:20:26 mtsbc opensips[7574]: DBG:tm:t_unref:
UNREF_UNSAFE: [0x7f6005838928] after is 0
May 10 19:20:26 mtsbc opensips[7574]:
DBG:core:destroy_avp_list: destroying list (nil)
May 10 19:20:26 mtsbc opensips[7574]: DBG:core:receive_msg:
cleaning up
May 10 19:20:26 mtsbc opensips[7574]:
DBG:proto_tls:tls_read_req: tls_read_req end
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:tls_read_req: Using the global ( per process
) buff
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:tls_update_fd: New fd is 5
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:_tls_read: 503 bytes read
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:tcp_handle_req: content-length= 0
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:tcp_handle_req: Nothing more to read on TCP
conn 0x7f60058267d0, currently in state 0
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:parse_msg:
SIP Request:
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:parse_msg:
method: <OPTIONS>
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:parse_msg:
uri: <sip:mtsbc.test.com:5061;transport=tls>
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:parse_msg:
version: <SIP/2.0>
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:_parse_to:
end of header reached, state=10
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:_parse_to:
display={}, ruri={sip:prober at localhost}
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:get_hdr_field: <TO> [24];
uri=[sip:prober at localhost]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:get_hdr_field: to body
[<sip:prober at localhost>#015#012]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:get_hdr_field: cseq <CSEQ>: <1> <OPTIONS>
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK9fe9fb55>; state=16
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:parse_via:
end of header reached, state=5
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_headers: via found, flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_headers: this is the first via
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:get_hdr_field: content_length=0
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:get_hdr_field: found end of header
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:receive_msg:
After parse_msg...
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:receive_msg:
preparing to run routing scripts...
May 10 19:20:26 mtsbc opensips[7575]:
DBG:maxfwd:is_maxfwd_present: value = 70
May 10 19:20:26 mtsbc opensips[7575]:
DBG:sipmsgops:has_totag: no totag
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_headers: flags=78
May 10 19:20:26 mtsbc opensips[7575]:
DBG:tm:t_lookup_request: start searching: hash=62537,
isACK=0
May 10 19:20:26 mtsbc opensips[7575]: DBG:tm:matching_3261:
RFC3261 transaction matching failed
May 10 19:20:26 mtsbc opensips[7575]:
DBG:tm:t_lookup_request: no transaction found
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_to_param:
tag=dd7d4e13-28ca-405e-9108-d83d4ea81f40
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:_parse_to:
end of header reached, state=29
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:_parse_to:
display={},
ruri={sip:sip-du-a-eu.pstnhub.microsoft.com:5061}
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:grep_sock_info_ext: checking if host==us: 33==14
&& [sip-du-a-eu.pstnhub.microsoft.com] ==
[xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:grep_sock_info_ext: checking if host==us: 33==14
&& [sip-du-a-eu.pstnhub.microsoft.com] ==
[xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7575]: DBG:core:check_self:
host != me
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:grep_sock_info_ext: checking if host==us: 16==14
&& [mtsbc.test.com] == [xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:grep_sock_info_ext: checking if host==us: 16==14
&& [mtsbc.test.com] == [xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:tcp_conn_get: con found in state 0
May 10 19:20:26 mtsbc opensips[7575]:
DBG:tls_mgm:tls_is_peer_verified: corresponding TLS/TCP
connection found. s=125, fd=5, id=926084752
May 10 19:20:26 mtsbc opensips[7575]:
DBG:tls_mgm:tls_is_peer_verified: peer is successfully
verified... done
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_headers: flags=200
May 10 19:20:26 mtsbc opensips[7575]:
DBG:rr:find_first_route: No Route headers found
May 10 19:20:26 mtsbc opensips[7575]: DBG:rr:loose_route:
There is no Route HF
May 10 19:20:26 mtsbc opensips[7575]:
DBG:permissions:check_src_addr: Looking for : <default:0,
52.114.75.24, 3, 13248, >
May 10 19:20:26 mtsbc opensips[7575]:
DBG:permissions:hash_match: no match in the hash table
May 10 19:20:26 mtsbc opensips[7575]:
DBG:permissions:match_subnet_table: subnet table is empty
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:grep_sock_info_ext: checking if host==us: 16==14
&& [mtsbc.test.com] == [xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:grep_sock_info_ext: checking if host==us: 16==14
&& [mtsbc.test.com] == [xxx.xxx.xxx.xxx]
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:MD5StringArray: MD5 calculated:
8217c8258ec89ff4f5427ff311954104
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:parse_headers: flags=ffffffffffffffff
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:tcp_conn_get: con found in state 0
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:tcp_conn_get: tcp connection found
(0x7f60058267d0) already in this process ( 10 ) , fd = 5
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:proto_tls_send: sending via fd 5...
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:tls_update_fd: New fd is 5
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:tls_write: write was successful (380 bytes)
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:proto_tls_send: after write: c=
0x7f60058267d0 n=380 fd=5
May 10 19:20:26 mtsbc opensips[7575]:
DBG:proto_tls:proto_tls_send: buf=#012SIP/2.0 484 Address
Incomplete#015#012FROM:
<sip:sip-du-a-eu.pstnhub.microsoft.com:5061>;tag=dd7d4e13-28ca-405e-9108-d83d4ea81f40#015#012TO:
<sip:prober at localhost>;tag=bd3a.8217c8258ec89ff4f5427ff311954104#015#012CSEQ:
1 OPTIONS#015#012CALL-ID:
bf155f68-8a4c-4f18-b5f5-1340da0d618d#015#012VIA:
SIP/2.0/TLS
52.114.75.24:5061;branch=z9hG4bK9fe9fb55#015#012Server:
OpenSIPS (3.1.1 (x86_64/linux))#015#012Content-Length:
0#015#012#015#012
May 10 19:20:26 mtsbc opensips[7575]:
DBG:core:destroy_avp_list: destroying list (nil)
On Mon, 10 May 2021 11:45:32 -0300
Carlos Eduardo <kaduww at gmail.com> wrote:
> Thank you Nick.
>
> I've read these docs lots of times and didn't pay
> attention on it.
>
>
> Em seg., 10 de mai. de 2021 às 11:44, Nick Altmann
> <nick at altmann.pro>
> escreveu:
>
> > Yes. You can use avp for this.
> >
>
https://opensips.org/docs/modules/3.1.x/tls_mgm.html#param_client_sip_domain_avp
> >
> > --
> > Nick
> >
> > пн, 10 мая 2021 г. в 16:09, Carlos Eduardo
> <kaduww at gmail.com>:
> >
> >> Hey all,
> >>
> >> About using the right certificate, is it possible to
> ensure opensips is
> >> going to use the right one when multiple are set in
> tls_mgm?
> >>
> >> Em seg., 10 de mai. de 2021 às 04:41, Răzvan Crainea
> <razvan at opensips.org>
> >> escreveu:
> >>
> >>> Hi, Miha!
> >>>
> >>> According to your logs, opensips is 100% sending the
> OPTIONS through
> >>> tls, but I am not sure it is using the right
> certificate.
> >>> You can try to setup sip trace and see the
> communication between
> >>> opensips and MSTeams.
> >>>
> >>> Best regards,
> >>>
> >>> Răzvan Crainea
> >>> OpenSIPS Core Developer
> >>> http://www.opensips-solutions.com
> >>>
> >>> On 5/10/21 9:54 AM, Miha via Users wrote:
> >>> > Hello
> >>> >
> >>> > I have used letsenrypt for generating certs for
> Opensips.
> >>> >
> >>> > Regarding configuration i have fallowed your
> configuration steps on
> >>> > OpenSips blog.
> >>> >
> >>> > socket=udp:xxx.xxx.xxx.xxx:5060 # CUSTOMIZE ME
> >>> > socket=tls:xxx.xxx.xxx.xxx:5061
> >>> >
> >>> >
> >>> >
> >>> >
> >>> > ### Proto TLS
> >>> > loadmodule "proto_tls.so"
> >>> > modparam("proto_tls", "tls_handshake_timeout", 300)
> >>> > #### TLS module
> >>> > loadmodule "tls_mgm.so"
> >>> > #modparam("tls_mgm", "db_url",
> "mysql://root:xxxx@localhost/opensips")
> >>> > modparam("tls_mgm", "client_sip_domain_avp",
> "mtsbcs.test.com")
> >>> > modparam("tls_mgm", "server_domain", "mt")
> >>> > #modparam("tls_mgm", "match_ip_address",
> "[mt]xxx.xxx.xxx.xxx:5061")
> >>> > #modparam("tls_mgm", "match_sip_domain",
> "[mt]mtsbcs.test.com")
> >>> > modparam("tls_mgm", "certificate",
> >>> >
> "[mt]/etc/letsencrypt/live/mtsbcs.test.com/cert.pem")
> >>> > modparam("tls_mgm", "private_key",
> >>> >
> "[mt]/etc/letsencrypt/live/mtsbcs.test.com/privkey.pem")
> >>> > modparam("tls_mgm", "ca_list",
> >>> "[mt]/etc/ssl/certs/ca-certificates.crt")
> >>> > modparam("tls_mgm", "ca_dir",
> "[mt]/etc/ssl/certs/")
> >>> > modparam("tls_mgm","verify_cert", "[mt]1")
> >>> > modparam("tls_mgm","require_cert", "[mt]1")
> >>> > modparam("tls_mgm","tls_method", "[mt]TLSv1_2")
> >>> > modparam("proto_tls", "tls_max_msg_chunks", 8)
> >>> > #modparam("tls_mgm", "tls_handshake_timeout", 300)
> >>> >
> >>> > if(is_method("OPTIONS") &&
> is_domain_local("$rd") &&
> >>> > check_source_address(0)) {
> >>> > xlog("L_INFO", "[MS TEAMS] OPTIONS
> In");
> >>> > send_reply(200, "OK");
> >>> > exit;
> >>> > }
> >>> >
> >>> >
> >>> > local_route {
> >>> > $var(dst) = "pstnhub.microsoft.com";
> >>> > xlog("L_INFO","promding TEST");
> >>> > xlog("TESTING");
> >>> > if (is_method("OPTIONS") && ($(ru{s.index,
> $var(dst)}) != NULL))
> >>> > append_hf("Contact: <sip:mtsbcs.test.com:5061
> >>> ;transport=tls>\r\n");
> >>> > xlog("L_INFO", "SEDING OPTIONS TO SBC");
> >>> > }
> >>> >
> >>> >
> >>> > I thnk that the main issue is that OPENSIPS does
> not send encrypted
> >>> > OPTION to MS teams.
> >>> >
> >>> > Logs:
> >>> >
> >>> > May 10 08:53:10 mtsbc opensips[1020]: DBG:tm:t_uac:
> >>> > next_hop=<sip:sip.pstnhub.microsoft.com>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:mk_proxy: doing DNS
> >>> lookup...
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:sip_resolvehost: no
> >>> port,
> >>> > has proto -> do SRV lookup!
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:do_srv_lookup:
> >>> resolving
> >>> > [sip.pstnhub.microsoft.com]
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:do_srv_lookup:
> >>> > SRV(_sips._tcp.sip.pstnhub.microsoft.com) =
> >>> sip.pstnhub.microsoft.com:5061
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:a2dns_node: storing
> >>> > sip2.pstnhub.microsoft.com:5061
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:a2dns_node: storing
> >>> > sip3.pstnhub.microsoft.com:5061
> >>> > May 10 08:53:10 mtsbc opensips[1020]: DBG:tm:t_uac:
> sending socket is
> >>> > 212.13.249.132
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:tm:print_request_uri:
> >>> > sip:sip.pstnhub.microsoft.com
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:tm:run_local_route: building
> >>> > sip_msg from buffer
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_msg: SIP Request:
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_msg: method:
> >>> <OPTIONS>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_msg: uri:
> >>> > <sip:sip.pstnhub.microsoft.com>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_msg: version:
> >>> <SIP/2.0>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> > flags=ffffffffffffffff
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_via_param: found
> >>> > param type 232, <branch> =
> <z9hG4bK8d8a.3706b135.0>; state=16
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_via: end of
> >>> header
> >>> > reached, state=5
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers: via
> >>> found,
> >>> > flags=ffffffffffffffff
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers: this is
> >>> > the first via
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:_parse_to: end of
> >>> header
> >>> > reached, state=9
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:_parse_to: display={},
> >>> > ruri={sip:sip.pstnhub.microsoft.com}
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:get_hdr_field: <To>
> >>> [31];
> >>> > uri=[sip:sip.pstnhub.microsoft.com]
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:get_hdr_field: to body
> >>> > [sip:sip.pstnhub.microsoft.com#015#012
> >>> <http://sip.pstnhub.microsoft.com#015%23012>]
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:get_hdr_field: cseq
> >>> > <CSeq>: <14> <OPTIONS>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:get_hdr_field:
> >>> > content_length=0
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:get_hdr_field: found
> >>> end
> >>> > of header
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> > flags=ffffffffffffffff
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers: flags=78
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> > flags=ffffffffffffffff
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:tm:run_local_route: Change
> >>> in
> >>> > local route -> rebuilding buffer
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> flags=2000
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> > flags=ffffffffffffffff
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:extract_ftc_hdrs: flags
> >>> = 15
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:extract_ftc_hdrs: hdr 2
> >>> > extracted as <To:
> sip:sip.pstnhub.microsoft.com#015#012
> >>> <http://sip.pstnhub.microsoft.com#015%23012>>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:extract_ftc_hdrs: hdr 1
> >>> > extracted as <From:
> >>> > <sip:prober at localhost
> >>> >;tag=a665d66adab06c7308a33b8567de92d6-f627#015#012>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:extract_ftc_hdrs: hdr 8
> >>> > extracted as <Call-ID:
> 12e30be047c27077-1020 at 212.13.249.132#015#012
> >>>
> <http://12e30be047c27077-1020@212.13.249.132#015%23012>>
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:proto_tls:proto_tls_send: no
> >>> > open tcp connection found, opening new one
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:probe_max_sock_buff:
> >>> > getsockopt: snd is initially 16384
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:probe_max_sock_buff:
> >>> > using snd buffer of 416 kb
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:init_sock_keepalive:
> >>> TCP
> >>> > keepalive enabled on socket 5
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:print_ip: tcpconn_new:
> >>> > new tcp connection to: 52.114.75.24
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:tcpconn_new: on port
> >>> > 5061, proto 3
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:proto_tls:tls_conn_init:
> >>> > Creating a whole new ssl connection
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:core:tcpconn_destroy:
> >>> > destroying connection 0x7f45d7e08078, flags 0018
> >>> > May 10 08:53:10 mtsbc opensips[1020]:
> DBG:tm:insert_timer_unsafe: [0]:
> >>> > 0x7f45d7e066b0 (1625)
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:timer_routine: timer
> >>> > routine:0,tl=0x7f45d7e066b0 next=(nil),
> timeout=1625
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:final_response_handler:
> >>> > Cancel sent out, sending 408 (0x7f45d7e06460)
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:t_should_relay_response:
> >>> > T_code=0, new_code=408
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:t_pick_branch: picked
> >>> > branch 0, code 408 (prio=800)
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:is_3263_failure:
> >>> > dns-failover test: branch=0, last_recv=408, flags=0
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:t_should_relay_response:
> >>> > trying DNS-based failover
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:do_dns_failover: new
> >>> > destination available
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> flags=2000
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> >>> > DBG:core:build_req_buf_from_sip_req: id added:
> <;i=0>, rcv proto=3
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:parse_headers:
> >>> > flags=ffffffffffffffff
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:proto_tls:proto_tls_send: no
> >>> > open tcp connection found, opening new one
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:probe_max_sock_buff:
> >>> > getsockopt: snd is initially 16384
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:probe_max_sock_buff:
> >>> > using snd buffer of 416 kb
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:init_sock_keepalive:
> >>> TCP
> >>> > keepalive enabled on socket 5
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:print_ip: tcpconn_new:
> >>> > new tcp connection to: 52.114.132.46
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:tcpconn_new: on port
> >>> > 5061, proto 3
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:proto_tls:tls_conn_init:
> >>> > Creating a whole new ssl connection
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:tcpconn_destroy:
> >>> > destroying connection 0x7f45d7e08078, flags 0018
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:proto_tls:proto_tls_send: no
> >>> > open tcp connection found, opening new one
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:probe_max_sock_buff:
> >>> > getsockopt: snd is initially 16384
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:probe_max_sock_buff:
> >>> > using snd buffer of 416 kb
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:init_sock_keepalive:
> >>> TCP
> >>> > keepalive enabled on socket 5
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:print_ip: tcpconn_new:
> >>> > new tcp connection to: 52.114.14.70
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:tcpconn_new: on port
> >>> > 5061, proto 3
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:proto_tls:tls_conn_init:
> >>> > Creating a whole new ssl connection
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:core:tcpconn_destroy:
> >>> > destroying connection 0x7f45d7e08078, flags 0018
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:local_reply: branch=0,
> >>> > save=0, winner=0
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:local_reply: local
> >>> > transaction completed
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:run_trans_callbacks:
> >>> > trans=0x7f45d7e06460, callback type 256, id 0
> entered
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:insert_timer_unsafe: [2]:
> >>> > 0x7f45d7e064e0 (1630)
> >>> > May 10 08:53:15 mtsbc opensips[1020]:
> DBG:tm:final_response_handler:
> >>> done
> >>> >
> >>> >
> >>> >
> >>> > Thank you
> >>> > miha
> >>> >
> >>> >
> >>> > _______________________________________________
> >>> > Users mailing list
> >>> > Users at lists.opensips.org
> >>> >
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> >>> >
> >>>
> >>> _______________________________________________
> >>> Users mailing list
> >>> Users at lists.opensips.org
> >>>
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> >>>
> >>
> >>
> >> --
> >> *Carlos E. Wagner*
> >> *Tecnólogo em Telecomunicações, Opensips Certified
> Professional*
> >>
> >> *Fone: +55 48 99981-0894*
> >> *E-mail:* kaduww at gmail.com
> >> *LinkedIn:*
>
https://www.linkedin.com/in/carlos-eduardo-wagner-96bbb433/
> >> _______________________________________________
> >> Users mailing list
> >> Users at lists.opensips.org
> >>
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> >>
> > _______________________________________________
> > Users mailing list
> > Users at lists.opensips.org
> >
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> >
>
>
> --
> *Carlos E. Wagner*
> *Tecnólogo em Telecomunicações, Opensips Certified
> Professional*
>
> *Fone: +55 48 99981-0894*
> *E-mail:* kaduww at gmail.com
> *LinkedIn:*
>
https://www.linkedin.com/in/carlos-eduardo-wagner-96bbb433/
More information about the Users
mailing list