Re: [OpenSIPS-Users] Opensips 3.2.8 does not send message with opensips-cli command

2022-10-10 Thread Bogdan-Andrei Iancu 

Hi,

On 3.2, are you sure you actually have the ongoing connection? Try 
running the list_tcp_conns MI cmd just before trying to push the MESSAGE 
out. Be sure that the remote point (proto:ip:port) of the connection 
matches the destination of your MESSAGE (so the connection gets re-used).


https://www.opensips.org/Documentation/Interface-CoreMI-3-2#toc4

Regards,

Bogdan-Andrei Iancu

OpenSIPS Founder and Developer
  https://www.opensips-solutions.com
OpenSIPS Summit 27-30 Sept 2022, Athens
  https://www.opensips.org/events/Summit-2022Athens/

On 9/29/22 5:09 PM, jacky z wrote:
Also tried version 3.2.2. The same issue. The existing TCP connection 
can't be found when there is a Message request, either from msilo dump 
or opensips-cli command. A message sent directly is normal when the 
receiver side registers with a living TCP socket. Guess this would 
also affect other behavior where an existing TCP connection needs to 
be found. From the log, the connection ID is zero. Very strange 
behavior. I would like to debug, but not familiar with the source code 
structure. For example how a TCP connection is looked for and which 
file handles this. Guess it is not difficult to fix, hope the Opensips 
team can help. Thank you!


On Tue, Sep 27, 2022 at 10:56 PM jacky z > wrote:


Who can help on this? It is difficult to understand why the live
tcp connection can't be found with opensips 3.2. It works well
with opensips 3.1. Thanks!

On Mon, Sep 26, 2022 at 3:54 PM jacky z mailto:zjack0...@gmail.com>> wrote:

Hi Team,

We use MI command to send messages to a user successfully with
opensips 3.1, but after we upgraded to 3.2.8, the message
can't be sent with opensips-cli command.

We compared the logs and found that when the command was run
on 3.2.8, the tcp connection couldn't be found though we can
confirm there was a tcp connection. Another strange behavior
is that it did not lookup the location table for the ruri and
it seems the message route was not called. On 3.2.8, if we
specify the ruri in the command with the actual ip address and
port we manually found in the location table, the message can
be sent. We also found the msilo module can't send messages on
3.2.8 but it works well on 3.1.

Here is the command we used:

opensips-cli -x mi t_uac_dlg method=MESSAGE
ruri="sip:12...@sip.domain.com:5061;transport=TLS"
headers="From:
sip:6...@sip.domain.com:5061;transport=tls\r\nTo:
sip:12...@sip.domain.com:5061;transport=TLS\r\nContact:
sip:6...@sip.domain.com:5061;transport=tls\r\nContent-Type:
text/plain\r\n" body="this is a message"

Here are the logs on 3.1 and 3.2.8 respectively,

Logs for OPENSIPS 3.2

Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg: SIP Request:
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  method: 

Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  uri:
 
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  version:

Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
flags=
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via_param:
found param type 232,  = ; state=16
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via: end of
header reached, state=5
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: via
found, flags=
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: this
is the first via
Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: end of
header reached, state=9
Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to:
display={}, ruri={sip:6989229...@sip.domain.com:5061
}
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: 
[37]; uri=[sip:6989229...@sip.domain.com:5061
]
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: to
body [sip:6989229...@sip.domain.com:5061#015#012
]
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: cseq
: <10> 
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field:
content_length=28
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: found
end of header
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
flags=
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: flags=78
Sep 26 07:21:13 opensips[3477]: DBG:proto_tls:proto_tls_send:
no open tcp connection found, opening new one, async = 0
Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff:
getsockopt: snd is initially 163

Re: [OpenSIPS-Users] Opensips 3.2.8 does not send message with opensips-cli command

2022-09-29 Thread jacky z 
Also tried version 3.2.2. The same issue. The existing TCP connection can't
be found when there is a Message request, either from msilo dump or
opensips-cli command. A message sent directly is normal when the receiver
side registers with a living TCP socket. Guess this would also affect other
behavior where an existing TCP connection needs to be found. From the log,
the connection ID is zero. Very strange behavior. I would like to debug,
but not familiar with the source code structure. For example how a TCP
connection is looked for and which file handles this. Guess it is not
difficult to fix, hope the Opensips team can help. Thank you!

On Tue, Sep 27, 2022 at 10:56 PM jacky z  wrote:

> Who can help on this? It is difficult to understand why the live tcp
> connection can't be found with opensips 3.2. It works well with opensips
> 3.1. Thanks!
>
> On Mon, Sep 26, 2022 at 3:54 PM jacky z  wrote:
>
>> Hi Team,
>>
>> We use MI command to send messages to a user successfully with opensips
>> 3.1, but after we upgraded to 3.2.8, the message can't be sent with
>> opensips-cli command.
>>
>> We compared the logs and found that when the command was run on 3.2.8,
>> the tcp connection couldn't be found though we can confirm there was a tcp
>> connection. Another strange behavior is that it did not lookup the location
>> table for the ruri and it seems the message route was not called. On 3.2.8,
>> if we specify the ruri in the command with the actual ip address and port
>> we manually found in the location table, the message can be sent. We also
>> found the msilo module can't send messages on 3.2.8 but it works well on
>> 3.1.
>>
>> Here is the command we used:
>>
>> opensips-cli -x mi t_uac_dlg method=MESSAGE
>> ruri="sip:12...@sip.domain.com:5061;transport=TLS" headers="From:
>> sip:6...@sip.domain.com:5061;transport=tls\r\nTo:
>> sip:12...@sip.domain.com:5061;transport=TLS\r\nContact:
>> sip:6...@sip.domain.com:5061;transport=tls\r\nContent-Type:
>> text/plain\r\n" body="this is a message"
>>
>> Here are the logs on 3.1 and 3.2.8 respectively,
>>
>> Logs for OPENSIPS 3.2
>>
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg: SIP Request:
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  method:  
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  uri:
>>  
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  version: 
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
>> flags=
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via_param: found param
>> type 232,  = ; state=16
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via: end of header
>> reached, state=5
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: via found,
>> flags=
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: this is the first
>> via
>> Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: end of header
>> reached, state=9
>> Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: display={}, ruri={
>> sip:6989229...@sip.domain.com:5061}
>> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field:  [37]; uri=[
>> sip:6989229...@sip.domain.com:5061]
>> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: to body [
>> sip:6989229...@sip.domain.com:5061#015#012
>> ]
>> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: cseq : <10>
>> 
>> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: content_length=28
>> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: found end of
>> header
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
>> flags=
>> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: flags=78
>> Sep 26 07:21:13 opensips[3477]: DBG:proto_tls:proto_tls_send: no open tcp
>> connection found, opening new one, async = 0
>> Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff: getsockopt:
>> snd is initially 16384
>> Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff: using snd
>> buffer of 416 kb
>> Sep 26 07:21:13 opensips[3477]: DBG:core:init_sock_keepalive: TCP
>> keepalive enabled on socket 103
>> Sep 26 07:21:14 opensips[3477]: ERROR:core:tcp_connect_blocking_timeout:
>> connect timed out, 179 us elapsed out of 100 us
>> Sep 26 07:21:14 opensips[3477]: ERROR:core:tcp_sync_connect_fd:
>> tcp_blocking_connect failed
>> Sep 26 07:21:14 opensips[3477]: ERROR:proto_tls:proto_tls_send: connect
>> failed
>> Sep 26 07:21:14 opensips[3477]: ERROR:tm:msg_send: send() to
>> 12.34.56.78:5061 for proto tls/3 failed
>> Sep 26 07:21:14 opensips[3477]: ERROR:tm:t_uac: attempt to send to
>> 'sip:6989229...@sip.domain.com:5061;transport=TLS' failed
>>
>> Logs for OPENSIPS 3.1
>>
>> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
>> DBG:core:parse_msg: SIP Request:
>> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
>> DBG:core:parse_msg:  method:  
>> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
>> DBG:core:parse_msg:  ur

Re: [OpenSIPS-Users] Opensips 3.2.8 does not send message with opensips-cli command

2022-09-27 Thread jacky z 
Who can help on this? It is difficult to understand why the live tcp
connection can't be found with opensips 3.2. It works well with opensips
3.1. Thanks!

On Mon, Sep 26, 2022 at 3:54 PM jacky z  wrote:

> Hi Team,
>
> We use MI command to send messages to a user successfully with opensips
> 3.1, but after we upgraded to 3.2.8, the message can't be sent with
> opensips-cli command.
>
> We compared the logs and found that when the command was run on 3.2.8, the
> tcp connection couldn't be found though we can confirm there was a tcp
> connection. Another strange behavior is that it did not lookup the location
> table for the ruri and it seems the message route was not called. On 3.2.8,
> if we specify the ruri in the command with the actual ip address and port
> we manually found in the location table, the message can be sent. We also
> found the msilo module can't send messages on 3.2.8 but it works well on
> 3.1.
>
> Here is the command we used:
>
> opensips-cli -x mi t_uac_dlg method=MESSAGE
> ruri="sip:12...@sip.domain.com:5061;transport=TLS" headers="From:
> sip:6...@sip.domain.com:5061;transport=tls\r\nTo:
> sip:12...@sip.domain.com:5061;transport=TLS\r\nContact:
> sip:6...@sip.domain.com:5061;transport=tls\r\nContent-Type:
> text/plain\r\n" body="this is a message"
>
> Here are the logs on 3.1 and 3.2.8 respectively,
>
> Logs for OPENSIPS 3.2
>
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg: SIP Request:
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  method:  
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  uri:
>  
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  version: 
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
> flags=
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via_param: found param type
> 232,  = ; state=16
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via: end of header reached,
> state=5
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: via found,
> flags=
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: this is the first
> via
> Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: end of header reached,
> state=9
> Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: display={}, ruri={
> sip:6989229...@sip.domain.com:5061}
> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field:  [37]; uri=[
> sip:6989229...@sip.domain.com:5061]
> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: to body [
> sip:6989229...@sip.domain.com:5061#015#012
> ]
> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: cseq : <10>
> 
> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: content_length=28
> Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: found end of header
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
> flags=
> Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: flags=78
> Sep 26 07:21:13 opensips[3477]: DBG:proto_tls:proto_tls_send: no open tcp
> connection found, opening new one, async = 0
> Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff: getsockopt:
> snd is initially 16384
> Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff: using snd
> buffer of 416 kb
> Sep 26 07:21:13 opensips[3477]: DBG:core:init_sock_keepalive: TCP
> keepalive enabled on socket 103
> Sep 26 07:21:14 opensips[3477]: ERROR:core:tcp_connect_blocking_timeout:
> connect timed out, 179 us elapsed out of 100 us
> Sep 26 07:21:14 opensips[3477]: ERROR:core:tcp_sync_connect_fd:
> tcp_blocking_connect failed
> Sep 26 07:21:14 opensips[3477]: ERROR:proto_tls:proto_tls_send: connect
> failed
> Sep 26 07:21:14 opensips[3477]: ERROR:tm:msg_send: send() to
> 12.34.56.78:5061 for proto tls/3 failed
> Sep 26 07:21:14 opensips[3477]: ERROR:tm:t_uac: attempt to send to
> 'sip:6989229...@sip.domain.com:5061;transport=TLS' failed
>
> Logs for OPENSIPS 3.1
>
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_msg: SIP Request:
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_msg:  method:  
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_msg:  uri:  ;transport=TLS>
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_msg:  version: 
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_headers: flags=
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_via_param: found param type 232,  =
> ; state=16
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_via: end of header reached, state=5
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_headers: via found, flags=
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:parse_headers: this is the first via
> Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
> DBG:core:_parse_to: end of

[OpenSIPS-Users] Opensips 3.2.8 does not send message with opensips-cli command

2022-09-26 Thread jacky z 
Hi Team,

We use MI command to send messages to a user successfully with opensips
3.1, but after we upgraded to 3.2.8, the message can't be sent with
opensips-cli command.

We compared the logs and found that when the command was run on 3.2.8, the
tcp connection couldn't be found though we can confirm there was a tcp
connection. Another strange behavior is that it did not lookup the location
table for the ruri and it seems the message route was not called. On 3.2.8,
if we specify the ruri in the command with the actual ip address and port
we manually found in the location table, the message can be sent. We also
found the msilo module can't send messages on 3.2.8 but it works well on
3.1.

Here is the command we used:

opensips-cli -x mi t_uac_dlg method=MESSAGE
ruri="sip:12...@sip.domain.com:5061;transport=TLS" headers="From:
sip:6...@sip.domain.com:5061;transport=tls\r\nTo:
sip:12...@sip.domain.com:5061;transport=TLS\r\nContact:
sip:6...@sip.domain.com:5061;transport=tls\r\nContent-Type: text/plain\r\n"
body="this is a message"

Here are the logs on 3.1 and 3.2.8 respectively,

Logs for OPENSIPS 3.2

Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg: SIP Request:
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  method:  
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  uri:
 
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_msg:  version: 
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
flags=
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via_param: found param type
232,  = ; state=16
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_via: end of header reached,
state=5
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: via found,
flags=
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: this is the first
via
Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: end of header reached,
state=9
Sep 26 07:21:13 opensips[3477]: DBG:core:_parse_to: display={}, ruri={
sip:6989229...@sip.domain.com:5061}
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field:  [37]; uri=[
sip:6989229...@sip.domain.com:5061]
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: to body [
sip:6989229...@sip.domain.com:5061#015#012]
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: cseq : <10>

Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: content_length=28
Sep 26 07:21:13 opensips[3477]: DBG:core:get_hdr_field: found end of header
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers:
flags=
Sep 26 07:21:13 opensips[3477]: DBG:core:parse_headers: flags=78
Sep 26 07:21:13 opensips[3477]: DBG:proto_tls:proto_tls_send: no open tcp
connection found, opening new one, async = 0
Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff: getsockopt:
snd is initially 16384
Sep 26 07:21:13 opensips[3477]: DBG:core:probe_max_sock_buff: using snd
buffer of 416 kb
Sep 26 07:21:13 opensips[3477]: DBG:core:init_sock_keepalive: TCP keepalive
enabled on socket 103
Sep 26 07:21:14 opensips[3477]: ERROR:core:tcp_connect_blocking_timeout:
connect timed out, 179 us elapsed out of 100 us
Sep 26 07:21:14 opensips[3477]: ERROR:core:tcp_sync_connect_fd:
tcp_blocking_connect failed
Sep 26 07:21:14 opensips[3477]: ERROR:proto_tls:proto_tls_send: connect
failed
Sep 26 07:21:14 opensips[3477]: ERROR:tm:msg_send: send() to
12.34.56.78:5061 for proto tls/3 failed
Sep 26 07:21:14 opensips[3477]: ERROR:tm:t_uac: attempt to send to
'sip:6989229...@sip.domain.com:5061;transport=TLS' failed

Logs for OPENSIPS 3.1

Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_msg: SIP Request:
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_msg:  method:  
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_msg:  uri: 
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_msg:  version: 
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_headers: flags=
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_via_param: found param type 232,  =
; state=16
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_via: end of header reached, state=5
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_headers: via found, flags=
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:parse_headers: this is the first via
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:_parse_to: end of header reached, state=9
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:_parse_to: display={}, ruri={sip:3293543...@sip.domain.com:5061}
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:get_hdr_field:  [38]; uri=[sip:3293543...@sip.domain.com:5061]
Sep 26 07:32:00 ip-172-31-14-229 /usr/sbin/opensips[11569]:
DBG:core:get_hdr_field: to body [sip:3293543...@sip.domain.com:5061#015#012]
Sep 26 07:32:00 ip-172-31-14-229 /usr/sb