Hi Bogdan_Andrei, You are right. The actual content is not attached. Here is the log.
Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:m_dump: user <[email protected]> online - expires=300 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:parse_headers: flags=ffffffffffffffff Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:check_message_support: Allow message: 256 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:check_message_support: MESSAGE found in Allow Header Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f0fc515e718 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: 6 columns returned from the query Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_allocate_columns: allocate 168 bytes for result columns at 0x7f0fc5149760 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0fc5149790)[0]=[id] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0fc51497a0)[1]=[src_addr] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0fc51497b0)[2]=[dst_addr] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0fc51497c0)[3]=[body] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: use DB_BLOB result type Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0fc51497d0)[4]=[ctype] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f0fc51497e0)[5]=[inc_time] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_allocate_rows: allocate 416 bytes for result rows and values at 0x7f0fc5148600 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting INT [73] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:[email protected]] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:[email protected]] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting BLOB [this is a message] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting STRING [text/plain] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting INT [1634193408] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting INT [74] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:[email protected]] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting STRING [sip:[email protected]] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting BLOB [this is another message] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting STRING [text/plain] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:db_mysql:db_mysql_str2val: converting INT [1634193408] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:m_dump: dumping [2] messages for <[email protected]>!!! Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:msg_list_check_msg: checking msgid=73 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:msg_list_check_msg: msg already in sent list. Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:m_dump: message[0] mid=73 already sent. Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:msg_list_check_msg: checking msgid=74 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:msg_list_check_msg: msg already in sent list. Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:msilo:m_dump: message[1] mid=74 already sent. Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_free_columns: freeing result columns at 0x7f0fc5149760 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_free_rows: freeing 2 rows Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_free_row: freeing row values at 0x7f0fc5148620 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_free_row: freeing row values at 0x7f0fc51486e0 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_free_rows: freeing rows at 0x7f0fc5148600 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:db_free_result: freeing result set at 0x7f0fc515e718 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: MSILO: offline messages dumped - if they were Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:parse_headers: flags=ffffffffffffffff Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:parse_params: Parsing params for:[reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00007e5b9907>"] Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:parse_headers: flags=ffffffffffffffff Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:parse_headers: flags=ffffffffffffffff Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: DBG:core:parse_headers: flags=ffffffffffffffff Oct 18 17:25:19 sipserver /usr/sbin/opensips[18616]: INFO:avpops:ops_print_avp: ----------- All AVPs in this context -------- Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: ERROR:core:tcp_connect_blocking_timeout: poll error: flags 28 - 4 8 16 32 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: ERROR:core:tcp_connect_blocking_timeout: failed to retrieve SO_ERROR [server=1.2.3.4:38351] (111) Connection refused Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: ERROR:proto_tls:tls_sync_connect: tcp_blocking_connect failed Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: ERROR:proto_tls:proto_tls_send: connect failed Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: ERROR:tm:msg_send: send() to 1.2.3.4:38351 for proto tls/3 failed Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: ERROR:tm:t_forward_nonack: sending request failed Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:core:tcp_conn_get: con found in state 0 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:core:tcp_conn_get: tcp connection found (0x7f0fc18f7040), acquiring fd Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:core:tcp_conn_get: c= 0x7f0fc18f7040, n=16, Usock=87 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18624]: DBG:core:handle_worker: read response= 7f0fc18f7040, 1, fd -1 from 8 (18617) Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:core:tcp_conn_get: after receive_fd: c= 0x7f0fc18f7040 n=8 fd=119 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:proto_tls:proto_tls_send: sending via fd 119... Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:proto_tls:tls_update_fd: New fd is 119 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:proto_tls:tls_write: write was successful (768 bytes) Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:proto_tls:proto_tls_send: after write: c= 0x7f0fc18f7040 n=768 fd=119 Oct 18 17:25:19 sipserver /usr/sbin/opensips[18617]: DBG:proto_tls:proto_tls_send: buf=#012MESSAGE sip:[email protected]:38250;transport=TLS;ob;push-type=apple;push-app=com.domain.anapp;push-tok=d26762bc904e92c7c7257b16d01c0306743842283890fbf3fc283f888a151dd1 SIP/2.0#015#012Via: SIP/2.0/TLS 5.6.7.8:5061;branch=z9hG4bKa4f6.a67d16b5.1;i=d08d52a7#015#012Via: SIP/2.0/TLS 5.6.7.8:5061;branch=z9hG4bKa4f6.967d16b5.0#015#012To: sip:[email protected]#015#012From: <sip:[email protected]>;tag=9afce3b8fbcf13cb78dc600ec9e7e602-19db#015#012CSeq: 10 MESSAGE#015#012Call-ID: [email protected]#015#012Max-Forwards: 69#015#012Content-Length: 51#015#012User-Agent: OpenSIPS (3.1.2 (x86_64/linux))#015#012Date: Thu, 14 Oct 2021 06:36:48 GMT#015#012Content-Type: text/plain#015#012Contact: <sip:[email protected]>;msilo=yes#015#012#015#012[Offline message - Thu Jan 1 08:00:00 1970#012 Hi, > > So the actual content of the message is not attached to the MSG? Could you > send me (maybe off list) the opensips logs (level 4) for a m_dump() ? > > Best regards, > > Bogdan-Andrei Iancu > > OpenSIPS Founder and Developer > https://www.opensips-solutions.com > OpenSIPS eBootcamp 2021 > https://opensips.org/training/OpenSIPS_eBootcamp_2021/ > > On 10/15/21 11:02 AM, jacky z wrote: > > Hi Bogdan-Andrei, > > Did you also noticed the msilo module still can't send the dumped message, > but send "[Offline message - Thu Jan 1 00:00:00 1970" no matter what the > message is? or just the setting I used? > > > :+1: >> >> Regards, >> >> Bogdan-Andrei Iancu >> >> OpenSIPS Founder and Developer >> https://www.opensips-solutions.com >> OpenSIPS eBootcamp 2021 >> https://opensips.org/training/OpenSIPS_eBootcamp_2021/ >> >> On 10/14/21 5:03 AM, jacky z wrote: >> >> Hi Bogdan-Andrei, >> >> Finally made it send offline message by setting >> >> modparam("msilo", "outbound_proxy", >> "sip:name.domain.com:5061;transport=tls") >> modparam("tls_mgm", "match_sip_domain", "[dom]*") >> >> It seems the port number needs to be included and the match_sip_domain >> needs to *. If the domain name is included, the error happens. Hope this >> info is helpful for others who may be interested. >> >> However, it still can't send the dumped message, but send "[Offline >> message - Thu Jan 1 08:00:00 1970" no matter what the message is. It seems >> the message was truncated. Based on the source code of the msilo module, >> the message should be something like "[Offline message - Thu Jan 1 >> 08:00:00 1970] message here". >> >> In the log, I can see the correct message was read out from the silo >> table. Here is the log that shows the correct offline message that should >> be sent: >> >> DBG:db_mysql:db_mysql_str2val: converting BLOB [{"type":"1","cont":"the >> right message"}] >> >> Thanks! >> >> >> Hi Jacky, >>> >>> The m_dump() sends the MESSAGE to the AOR of the user, so, ideally, you >>> should do take care of the "lookup(location)" in order to the get it >>> properly routed. >>> >>> For the TLS part, do you use it between the end-point and opensips? if >>> so, I guess the MESSAGE sent by m_dump() and looping back to opensips (for >>> doing the lookup(location)) is via UDP ? >>> >>> I'm asking as from the TLS perspective the most important think to know >>> is where (in the routing logic) the TLS connection gets used/opened, as >>> you need to be sure and correlate the destination IP (at the moment) with >>> the IPs/mask you have in the TLS client domain. >>> >>> Best regards, >>> >>> Bogdan-Andrei Iancu >>> >>> OpenSIPS Founder and Developer >>> https://www.opensips-solutions.com >>> OpenSIPS eBootcamp 2021 >>> https://opensips.org/training/OpenSIPS_eBootcamp_2021/ >>> >>> On 9/28/21 3:03 AM, jacky z wrote: >>> >>> Hi Team, >>> >>> I want to use MSILO to forward offline messages. I use TLS connections >>> and have set up both server domain and client domains. If we don't >>> use outbound_proxy, the logs show no error, but the message just was not >>> sent. I searched online and it was said that the outbound proxy needs to be >>> used. However, if we use outbound_proxy, there will be errors- no TLS >>> client domain found. Actually, I have set up the client domain. It >>> seems the MSILO module can't recognize the client domain. I have checked >>> the messages were all in the database table silo. Have you ever encountered >>> such issues? Any clue to debug? Thanks! >>> >>> Here are the scripts and logs >>> >>> When m_dump() is called in "REGISTER": >>> >>> if (m_dump()) { >>> xlog("MSILO: offline messages dumped - if they were"); >>> }else{ >>> xlog("MSILO: no offline messages dumped"); >>> }; >>> >>> It can dump the message from the database but can't send the message. >>> Here is the log: >>> >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:parse_msg: >>> method: >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:parse_msg: >>> uri: sip:[email protected]:5061;transport=tls >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:parse_msg: >>> version: <SIP/2.0> >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_headers: flags=ffffffffffffffff >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_via_param: found param type 232, = <z9hG4bKe0c6.787dad54.0>; >>> state=16 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:parse_via: >>> end of header reached, state=5 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_headers: via found, flags=ffffffffffffffff >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_headers: this is the first via >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_to_param: transport=tls >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:_parse_to: >>> end of header reached, state=29 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:_parse_to: >>> display={}, ruri={sip:[email protected]:5061} >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:get_hdr_field: [50]; uri=[sip:[email protected]:5061] >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:get_hdr_field: to body [sip:[email protected]:5061] >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:get_hdr_field: cseq : <10> >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:get_hdr_field: content_length=78 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:get_hdr_field: found end of header >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_headers: flags=ffffffffffffffff >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:parse_headers: flags=78 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:proto_tls:proto_tls_send: no open tcp connection found, opening new one >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:probe_max_sock_buff: getsockopt: snd is initially 16384 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:probe_max_sock_buff: using snd buffer of 416 kb >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:init_sock_keepalive: TCP keepalive enabled on socket 119 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: DBG:core:print_ip: >>> tcpconn_new: new tcp connection to: 142.107.16.203 >>> <http://142.107.16.203:5061/> >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:tcpconn_new: on port 5061, proto 3 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:proto_tls:tls_conn_init: Creating a whole new ssl connection >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> ERROR:proto_tls:tls_conn_init: no TLS client domain found >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> ERROR:core:tcp_conn_new: failed to do proto 3 specific init for conn >>> 0x7f0559e116b8 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> DBG:core:tcpconn_destroy: destroying connection 0x7f0559e116b8, flags 0018 >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> ERROR:proto_tls:tls_sync_connect: tcp_conn_create failed, closing the socket >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: >>> ERROR:proto_tls:proto_tls_send: connect failed >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: ERROR™️msg_send: >>> send() to 142.107.16.203:5061 for proto tls/3 failed >>> Sep 18 17:29:55 sipserver /usr/sbin/opensips[9794]: ERROR™️t_uac: >>> attempt to send to 'sip:[email protected]:5061;transport=tls' failed >>> >>> _______________________________________________ >>> Users mailing >>> [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
