Vlad, community, still no idea about that? I really need your advice with that.
06.03.2015, 14:14, "Чалков Артём" <[email protected]>: > Yes, i sure. I have only 1 branch because i have only one instance to receive > sent MESSAGE and i dont add branches manually. Actually, that is all MESSAGE > routing: > > ... > if (is_method("MESSAGE")) route(MESSAGE); > ... > route[MESSAGE] { > ... > if (!lookup("location")) { > ... > } else { > t_on_reply("ON_REPLY"); > if ($si != "127.0.0.1") t_on_failure("ON_FAIL_MESSAGE"); > t_relay("0x01"); > $var(retcode) = $retcode; > xlog("L_INFO", "[!!!MESSAGE_DEBUG!!!] t_relay returns > $var(retcode) LOGHDR"); > ifdef(`LOGS', `xlog("L_INFO", "[MESSAGE] Request is leaving > server LOGHDR");') > exit; > } > } > > I have sent to your e-mail ([email protected]) debug=4 log from moment, > when i killed softphone (destination of MESSAGE) without sip unregistering, > but with removing tcp/tls connection. > > 06.03.2015, 12:43, "Vlad Paiu" <[email protected]>: >> Hello, >> >> OpenSIPS complains that there is an error when connecting via TCP to >> that endpoint. >> Now, are you sure you do not have multple branches when relaying that >> SIP MESSAGE,out of which only one fails ? In t_relay(), if you have >> multiple branches and at least one succceeds, you will get a 1 return code. >> >> Please post the complete debug=4 logs for the processing. In the >> previous email, you've truncated the logs to the moment OpenSIPS gets >> blocked in trying to connect to the endpoint - what happens afterwards ( >> after connet timeout ) would also be helpfull. >> >> Best Regards, >> >> Vlad Paiu >> OpenSIPS Developer >> http://www.opensips-solutions.com >> >> On 06.03.2015 11:06, Чалков Артём wrote: >>> do anyone have any idea about how to handle that? >>> >>> 05.03.2015, 16:22, "Чалков Артём" <[email protected]>: >>>> debug=4 >>>> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:tcp_read_req: We're releasing the connection in state 3 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:io_watch_del: io_watch_del op on index -1 36 (0x77dee0, 36, -1, >>>> 0x10,0x1) fd_no=2 called >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:release_tcpconn: releasing con 0x7f2be91663a8, state 0, fd=36, >>>> id=1 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:release_tcpconn: extra_data (nil) >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_msg: >>>> SIP Request: >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_msg: >>>> method: <MESSAGE> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19028]: >>>> DBG:core:handle_tcp_child: reader response= 7f2be91663a8, 0 from 0 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_msg: >>>> uri: <sip:[email protected]:3631;transport=TCP> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19028]: >>>> DBG:core:io_watch_add: io_watch_add op on 52 (0x77dd80, 52, 2, >>>> 0x7f2be91663a8,1), fd_no=38 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_msg: >>>> version: <SIP/2.0> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=2 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_via_param: found param type 232, <branch> = >>>> <z9hG4bK-d8754z-668ef50b1a4c0a31-1---d8754z->; state=6 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_via: >>>> end of header reached, state=5 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: via found, flags=2 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: this is the first via >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:receive_msg: >>>> After parse_msg... >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:receive_msg: >>>> preparing to run routing scripts... >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=8000000 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_to: >>>> end of header reached, state=10 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_to: >>>> display={}, ruri={sip:[email protected]:3631;transport=TCP} >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:get_hdr_field: <To> [51]; >>>> uri=[sip:[email protected]:3631;transport=TCP] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:get_hdr_field: to body >>>> [<sip:[email protected]:3631;transport=TCP>#015#012] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:get_hdr_field: cseq <CSeq>: <3> <MESSAGE> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:maxfwd:is_maxfwd_present: value = 70 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=ffffffffffffffff >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:get_hdr_field: content_length=3 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:get_hdr_field: found end of header >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=ffffffffffffffff >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:decode_mime_type: Decoding MIME type for:[text/plain] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_to_param: tag=b2b91161 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_to: >>>> end of header reached, state=29 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:parse_to: >>>> display={"achalkov"}, ruri={sip:[email protected]:3631;transport=TCP} >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=ffffffffffffffff >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_methods: methods 0x173F >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:uri:has_totag: no >>>> totag >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=78 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:tm:t_lookup_request: start searching: hash=32018, isACK=0 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:tm:matching_3261: >>>> RFC3261 transaction matching failed >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:tm:t_lookup_request: no transaction found >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=200 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:rr:find_first_route: No Route headers found >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:rr:loose_route: >>>> There is no Route HF >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:auth:check_nonce: >>>> comparing [54f85536be0ae02858c2001d58774c222d958f86] and >>>> [54f85536be0ae02858c2001d58774c222d958f86] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:has_stmt_ctx: ctx found for subscriber >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_do_prepared_query: conn=0x7f2bef4e28b0 >>>> (tail=139826675195936) MC=0x7f2bef4e2080 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_val2bind: added val (0): len=8; type=254; is_null=0 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in... >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 2 columns >>>> in result >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f2bef4f5968 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_allocate_columns: allocate 56 bytes for result columns at >>>> 0x7f2bef4f6368 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f2bef4f6378)[0]=[ha1] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_get_columns: >>>> RES_NAMES(0x7f2bef4f6388)[1]=[mediaproxy] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_allocate_rows: allocate 80 bytes for result rows and values at >>>> 0x7f2bef4f6a48 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:db_mysql:db_mysql_str2val: converting STRING >>>> [659cc07a1ab8ccbbc3b5ec2172bc6473] >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:auth:check_response: our result = '06223b730875bf2c01ad98448dd08438' >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:auth:check_response: authorization is OK >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_free_columns: freeing result columns at 0x7f2bef4f6368 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_free_rows: freeing 1 rows >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:db_free_row: >>>> freeing row values at 0x7f2bef4f6a58 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_free_rows: freeing rows at 0x7f2bef4f6a48 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:db_free_result: freeing result set at 0x7f2bef4f5968 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:registrar:lookup: >>>> found a complete match >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:registrar:lookup: >>>> setting as ruri <sip:[email protected]:65062;transport=TLS;ob> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:registrar:lookup: >>>> looking for branches >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:registrar:lookup: >>>> found a complete match >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:registrar:lookup: >>>> setting as ruri <sip:[email protected]:65062;transport=TLS;ob> >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:registrar:lookup: >>>> looking for branches >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:comp_scriptvar: str 29 : 83.149.9.184 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:tm:t_newtran: >>>> transaction on entrance=(nil) >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=ffffffffffffffff >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=78 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:tm:t_lookup_request: start searching: hash=32018, isACK=0 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:tm:matching_3261: >>>> RFC3261 transaction matching failed >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:tm:t_lookup_request: no transaction found >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:tm:run_reqin_callbacks: trans=0x7f2be91669a0, callback type 1, id 1 >>>> entered >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:tm:run_reqin_callbacks: trans=0x7f2be91669a0, callback type 1, id 0 >>>> entered >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:_shm_resize: >>>> resize(0) called >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:mk_proxy: >>>> doing DNS lookup... >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:parse_headers: flags=2000 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:build_req_buf_from_sip_req: id added: <;i=1>, rcv proto=2 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:tcp_send: no >>>> open tcp connection found, opening new one >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: getsockopt: snd is initially 16384 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 32768 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=32768,verify=65536 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 65536 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=65536,verify=131072 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 131072 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=131072,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 262144 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=262144,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting buf has no effect >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 133120 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=133120,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 135168 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=135168,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 137216 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=137216,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 139264 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=139264,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 141312 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=141312,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 143360 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=143360,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 145408 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=145408,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 147456 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=147456,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 149504 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=149504,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 151552 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=151552,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 153600 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=153600,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 155648 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=155648,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 157696 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=157696,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 159744 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=159744,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 161792 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=161792,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 163840 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=163840,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 165888 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=165888,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 167936 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=167936,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: trying : 169984 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: >>>> DBG:core:probe_max_sock_buff: setting snd: set=169984,verify=262142 >>>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19028]: >>>> DBG:core:handle_ser_child: read response= 7f2be91663a8, 1, fd -1 from 17 >>>> (19012) >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:avpops:ops_dbquery_avps: query [SELECT username FROM silo GROUP BY >>>> username HAVING count(*) > 0] >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f2bef4e3aa8 >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:core:db_allocate_columns: allocate 28 bytes for result columns at >>>> 0x7f2bef4e3af0 >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f2bef4e3af8)[0]=[username] >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:avpops:db_query_avp: no result after query >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:avpops:db_close_query: close avp query >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:core:db_free_columns: freeing result columns at 0x7f2bef4e3af0 >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:core:db_free_rows: freeing 0 rows >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:core:db_free_result: freeing result set at 0x7f2bef4e3aa8 >>>> Mar 5 16:07:49 cs17792 /usr/sbin/opensips[19010]: >>>> DBG:core:destroy_avp_list: destroying list (nil) >>>> Mar 5 16:07:52 cs17792 /usr/sbin/opensips[19009]: DBG:tm:timer_routine: >>>> timer routine:2,tl=0x7f2be9166a20 next=(nil), timeout=36 >>>> Mar 5 16:07:52 cs17792 /usr/sbin/opensips[19009]: DBG:tm:wait_handler: >>>> removing 0x7f2be91669a0 from table >>>> Mar 5 16:07:52 cs17792 /usr/sbin/opensips[19009]: DBG:tm:delete_cell: >>>> delete transaction 0x7f2be91669a0 >>>> Mar 5 16:07:52 cs17792 /usr/sbin/opensips[19009]: DBG:tm:wait_handler: >>>> done >>>> >>>> debug=3 with check >>>> >>>> if ($si != "127.0.0.1") t_on_failure("ON_FAIL_MESSAGE"); >>>> t_relay("0x01"); >>>> $var(retcode) = $retcode; >>>> xlog("L_INFO", "[!!!MESSAGE_DEBUG!!!] t_relay returns >>>> $var(retcode)"); >>>> >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: [MAIN] Incoming >>>> request (MESSAGE) >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: >>>> INFO:core:probe_max_sock_buff: using snd buffer of 255 kb >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: >>>> INFO:core:init_sock_keepalive: -- TCP keepalive enabled on socket >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: >>>> ERROR:core:tcp_blocking_connect: poll error: flags 24 - 4 8 16 32 >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: >>>> ERROR:core:tcp_blocking_connect: failed to retrieve SO_ERROR >>>> [server=x.x.x.x:65106] (111) Connection refused >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: >>>> ERROR:core:tcpconn_connect: tcp_blocking_connect failed >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: ERROR:core:tcp_send: >>>> connect failed >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: ERROR:tm:msg_send: >>>> tcp_send failed >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: >>>> ERROR:tm:t_forward_nonack: sending request failed >>>> Mar 5 16:15:01 cs17792 /usr/sbin/opensips[19205]: [!!!MESSAGE_DEBUG!!!] >>>> t_relay returns 1 >>>> >>>> 05.03.2015, 15:39, "Vlad Paiu" <[email protected]>: >>>>> Hello, >>>>> >>>>> Since TLS doesn't support async in 1.11, you should get an error >>>>> straight out of t_relay() >>>>> Can you please post the full debug logs here ? >>>>> >>>>> Best Regards, >>>>> >>>>> Vlad Paiu >>>>> OpenSIPS Developer >>>>> http://www.opensips-solutions.com >>>>> >>>>> On 05.03.2015 13:44, Чалков Артём wrote: >>>>>> Hi all! >>>>>> >>>>>> Can someone help us?. I cannot understand how TLS in opensips 1.11 >>>>>> works. >>>>>> The problem is when we use TLS, i cannot handle connection problems. >>>>>> >>>>>> When i use TCP in async mode, i have 408 in failure route when >>>>>> outgoing TCP connection fails, when i use TCP in sync mode, i have >>>>>> negative status after t_relay(), however, after TLS, i cannot catch >>>>>> neither 408, or negative t_relay() status. So, how to handle TLS >>>>>> connection error? >>>>>> >>>>>> _______________________________________________ >>>>>> 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 >>>> _______________________________________________ >>>> 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 >> _______________________________________________ >> 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 _______________________________________________ Users mailing list [email protected] http://lists.opensips.org/cgi-bin/mailman/listinfo/users
