[OpenSIPS-Users] TLS handling
Vlad Paiu
vladpaiu at opensips.org
Fri Mar 6 10:42:49 CET 2015
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, "Чалков Артём" <achalkov at ya.ru>:
>> 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:achalkov1 at x.x.x.x: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:achalkov1 at x.x.x.x:3631;transport=TCP}
>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:get_hdr_field: <To> [51]; uri=[sip:achalkov1 at x.x.x.x:3631;transport=TCP]
>> Mar 5 16:07:46 cs17792 /usr/sbin/opensips[19012]: DBG:core:get_hdr_field: to body [<sip:achalkov1 at x.x.x.x: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:achalkov at x.x.x.x: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:achalkov1 at 192.168.1.210: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:achalkov1 at 192.168.1.210: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" <vladpaiu at opensips.org>:
>>> 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
>>>> 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
>> _______________________________________________
>> 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
More information about the Users
mailing list