HI ,<br><br>I am using opensips with TLS enabled.Iam trying to establish a call via TLS,both the clients are able to register,but when a message/call is sent I get the following error<br><br>SIP/2.0 200 OK<br>Via: SIP/2.0/TLS 10.1.1.102:1268;rport=1268;branch=z9hG4bKPj021189d9cdb2430998ee8f0d36cc173d<br>
From: <<a href="mailto:sip%3A2000@20.1.1.2">sip:2000@20.1.1.2</a>>;tag=3f23894087f04dc599171a376667a716<br>To: <<a href="mailto:sip%3A2000@20.1.1.2">sip:2000@20.1.1.2</a>>;tag=e4628f3555f473813fff196cef35ce47.52fc<br>
Call-ID: fc6971a239f14ed6942339b96e5e6985<br>CSeq: 47334 REGISTER<br>Contact: <sip:2000@10.1.1.102:4000;transport=TLS>;expires=300<br>Server: OpenSIPS (1.6.4-2-tls (i386/linux))<br>Content-Length: 0<br><br><br>Apr 17 08:32:38 [29262] DBG:core:destroy_avp_list: destroying list (nil)<br>
Apr 17 08:32:38 [29262] DBG:core:receive_msg: cleaning up<br>Apr 17 08:32:44 [29262] DBG:core:tcp_receive_timeout: 0xb610c728 expired (31, 32) lt=0<br>Apr 17 08:32:44 [29262] DBG:core:io_watch_del: io_watch_del (0x81a2ea0, 13, -1, 0x10) fd_no=2 called<br>
Apr 17 08:32:44 [29262] DBG:core:release_tcpconn: releasing con 0xb610c728, state 0, fd=13, id=2<br>Apr 17 08:32:44 [29262] DBG:core:release_tcpconn: extra_data 0xb6109548<br>Apr 17 08:32:44 [29271] DBG:core:handle_tcp_child: reader response= b610c728, 0 from 0 <br>
Apr 17 08:32:44 [29271] DBG:core:io_watch_add: io_watch_add(0x81a2d40, 19, 2, 0xb610c728), fd_no=13<br>Apr 17 08:32:44 [29271] DBG:core:handle_tcp_child: cmd CONN_RELEASE 0xb610c728 refcnt= 0<br>Apr 17 08:32:46 [29271] DBG:core:handle_tcpconn_ev: data available on 0xb60e26c4 18<br>
Apr 17 08:32:46 [29271] DBG:core:io_watch_del: io_watch_del (0x81a2d40, 18, -1, 0x0) fd_no=14 called<br>Apr 17 08:32:46 [29271] DBG:core:send2child: to tcp child 0 0(29262), 0xb60e26c4<br>Apr 17 08:32:46 [29262] DBG:core:handle_io: received n=4 con=0xb60e26c4, fd=13<br>
Apr 17 08:32:46 [29262] DBG:core:io_watch_add: io_watch_add(0x81a2ea0, 13, 2, 0xb60e26c4), fd_no=1<br>Apr 17 08:32:46 [29262] DBG:core:tls_update_fd: New fd is 13<br>Apr 17 08:32:46 [29262] DBG:core:_tls_read: 4 bytes read<br>
Apr 17 08:32:46 [29262] DBG:core:tcp_read_req: content-length= 0<br>Apr 17 08:32:46 [29262] DBG:core:tcp_send: tcp connection found (0xb60e26c4), acquiring fd<br>Apr 17 08:32:46 [29262] DBG:core:tcp_send: c= 0xb60e26c4, n=8<br>
Apr 17 08:32:46 [29271] DBG:core:handle_ser_child: read response= b60e26c4, 1, fd -1 from 4 (29262)<br>Apr 17 08:32:46 [29262] DBG:core:tcp_send: after receive_fd: c= 0xb60e26c4 n=4 fd=14<br>Apr 17 08:32:46 [29262] DBG:core:tcp_send: sending...<br>
Apr 17 08:32:46 [29262] DBG:core:tls_update_fd: New fd is 14<br>Apr 17 08:32:46 [29262] DBG:core:tls_write: write was successful (2 bytes)<br>Apr 17 08:32:46 [29262] DBG:core:tcp_send: after write: c= 0xb60e26c4 n=2 fd=14<br>
Apr 17 08:32:46 [29262] DBG:core:tcp_send: buf=<br><br><br>Apr 17 08:32:52 [29262] DBG:core:tls_update_fd: New fd is 13<br>Apr 17 08:32:52 [29262] DBG:core:_tls_read: 543 bytes read<br>Apr 17 08:32:52 [29262] DBG:core:tcp_read_req: content-length= 2<br>
Apr 17 08:32:52 [29262] DBG:core:parse_msg: SIP Request:<br>Apr 17 08:32:52 [29262] DBG:core:parse_msg: method: <MESSAGE><br>Apr 17 08:32:52 [29262] DBG:core:parse_msg: uri: <<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>><br>
Apr 17 08:32:52 [29262] DBG:core:parse_msg: version: <SIP/2.0><br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=2<br>Apr 17 08:32:52 [29262] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6<br>
Apr 17 08:32:52 [29262] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPja09ec884d91f4b0faea630f9fbc156bf>; state=16<br>Apr 17 08:32:52 [29262] DBG:core:parse_via: end of header reached, state=5<br>
Apr 17 08:32:52 [29262] DBG:core:parse_headers: via found, flags=2<br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: this is the first via<br>Apr 17 08:32:52 [29262] DBG:core:receive_msg: After parse_msg...<br>Apr 17 08:32:52 [29262] DBG:core:receive_msg: preparing to run routing scripts...<br>
Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=100<br>Apr 17 08:32:52 [29262] DBG:maxfwd:is_maxfwd_present: value = 70 <br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=8<br>Apr 17 08:32:52 [29262] DBG:core:parse_to: end of header reached, state=10<br>
Apr 17 08:32:52 [29262] DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>}<br>Apr 17 08:32:52 [29262] DBG:core:get_hdr_field: <To> [21]; uri=[<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>] <br>
Apr 17 08:32:52 [29262] DBG:core:get_hdr_field: to body [<<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>><br>]<br>Apr 17 08:32:52 [29262] DBG:uri:has_totag: no totag<br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=78<br>
Apr 17 08:32:52 [29262] DBG:core:get_hdr_field: cseq <CSeq>: <15905> <MESSAGE><br>Apr 17 08:32:52 [29262] DBG:tm:t_lookup_request: start searching: hash=15450, isACK=0<br>Apr 17 08:32:52 [29262] DBG:tm:matching_3261: RFC3261 transaction matching failed<br>
Apr 17 08:32:52 [29262] DBG:tm:t_lookup_request: no transaction found<br>Apr 17 08:32:52 [29262] DBG:core:parse_to_param: tag=d5b6699b53424475b7588a272b462a3f<br>Apr 17 08:32:52 [29262] DBG:core:parse_to: end of header reached, state=29<br>
Apr 17 08:32:52 [29262] DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>}<br>Apr 17 08:32:52 [29262] DBG:core:grep_sock_info: checking if host==us: 8==8 && [20.1.1.2] == [20.1.1.2]<br>
Apr 17 08:32:52 [29262] DBG:core:grep_sock_info: checking if port 5061 matches port 5060<br>Apr 17 08:32:52 [29262] DBG:core:check_self: host != me<br>Apr 17 08:32:52 [29262] DBG:core:grep_sock_info: checking if host==us: 8==8 && [20.1.1.2] == [20.1.1.2]<br>
Apr 17 08:32:52 [29262] DBG:core:grep_sock_info: checking if port 5061 matches port 5060<br>Apr 17 08:32:52 [29262] DBG:core:check_self: host != me<br>Apr 17 08:32:52 [29262] DBG:registrar:lookup: setting as ruri <sip:1000@10.1.1.203:3000;transport=TLS><br>
Apr 17 08:32:52 [29262] DBG:registrar:lookup: looking for branches<br>Apr 17 08:32:52 [29262] DBG:tm:t_newtran: transaction on entrance=(nil)<br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=ffffffffffffffff<br>Apr 17 08:32:52 [29262] DBG:core:get_hdr_field: content_length=2<br>
Apr 17 08:32:52 [29262] DBG:core:get_hdr_field: found end of header<br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=78<br>Apr 17 08:32:52 [29262] DBG:tm:t_lookup_request: start searching: hash=15450, isACK=0<br>Apr 17 08:32:52 [29262] DBG:tm:matching_3261: RFC3261 transaction matching failed<br>
Apr 17 08:32:52 [29262] DBG:tm:t_lookup_request: no transaction found<br>Apr 17 08:32:52 [29262] DBG:tm:run_reqin_callbacks: trans=0xb61056f8, callback type 1, id 0 entered<br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=78<br>
Apr 17 08:32:52 [29262] DBG:core:mk_proxy: doing DNS lookup...<br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=2000<br>Apr 17 08:32:52 [29262] DBG:core:build_req_buf_from_sip_req: id added: <;i=1>, rcv proto=3<br>
Apr 17 08:32:52 [29262] DBG:core:tcp_send: no open tcp connection found, opening new one<br>Apr 17 08:32:52 [29262] DBG:core:print_ip: tcpconn_new: new tcp connection to: 10.1.1.203<br>Apr 17 08:32:52 [29262] DBG:core:tcpconn_new: on port 3000, type 3<br>
Apr 17 08:32:52 [29262] DBG:core:tls_tcpconn_init: entered: Creating a whole new ssl connection<br>Apr 17 08:32:52 [29262] DBG:core:tls_tcpconn_init: name based TLS client domains are disabled<br>Apr 17 08:32:52 [29262] DBG:core:tls_tcpconn_init: no TLS client doman AVP set, looking for socket based TLS client domain<br>
Apr 17 08:32:52 [29262] DBG:core:tls_find_client_domain: virtual TLS client domain not found, Using default TLS client domain settings<br>Apr 17 08:32:52 [29262] DBG:core:tls_tcpconn_init: found socket based TLS client domain [<a href="http://0.0.0.0:0">0.0.0.0:0</a>]<br>
Apr 17 08:32:52 [29262] DBG:core:tls_tcpconn_init: Setting in CONNECT mode (client)<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: sending...<br>Apr 17 08:32:52 [29262] DBG:core:tls_update_fd: New fd is 14<br>Apr 17 08:32:52 [29271] DBG:core:handle_ser_child: read response= b612b9c0, 2, fd 20 from 4 (29262)<br>
Apr 17 08:32:52 [29271] DBG:core:tcpconn_add: hashes: 690, 3<br>Apr 17 08:32:52 [29271] DBG:core:io_watch_add: io_watch_add(0x81a2d40, 20, 2, 0xb612b9c0), fd_no=13<br>Apr 17 08:32:52 [29271] DBG:core:handle_tcpconn_ev: data available on 0xb612b9c0 20<br>
Apr 17 08:32:52 [29271] DBG:core:io_watch_del: io_watch_del (0x81a2d40, 20, -1, 0x0) fd_no=14 called<br>Apr 17 08:32:52 [29271] DBG:core:send2child: to tcp child 1 0(29263), 0xb612b9c0<br>Apr 17 08:32:52 [29262] ERROR:core:tls_connect: SSL_ERROR_SYSCALL err=Success(0)<br>
Apr 17 08:32:52 [29262] ERROR:core:tls_connect: something wrong in SSL: 5 (ret=0) err=Success(0)<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: after write: c= 0xb612b9c0 n=-1 fd=14<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: buf=<br>
MESSAGE sip:1000@10.1.1.203:3000;transport=TLS SIP/2.0<br>Via: SIP/2.0/TLS 20.1.1.2:5061;branch=z9hG4bKa5c3.13a1e574.0;i=1<br>Via: SIP/2.0/TLS 10.1.1.203:1788;received=10.1.1.203;rport=1788;branch=z9hG4bKPja09ec884d91f4b0faea630f9fbc156bf<br>
Max-Forwards: 69<br>From: <<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>>;tag=d5b6699b53424475b7588a272b462a3f<br>To: <<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>><br>Call-ID: 51c2a37a3a914ccb9189f2b9b2e4870a<br>
CSeq: 15905 MESSAGE<br>Accept: text/plain, application/im-iscomposing+xml<br>Contact: <sip:1000@10.1.1.203:3000;transport=TLS><br>User-Agent: QjSimple 0.6.5 (pjproject 1.5.5/win32)<br>Route: <sip:20.1.1.2;transport=tls;lr><br>
Content-Type: text/plain<br>Content-Length: 2<br><br>ds<br>Apr 17 08:32:52 [29262] ERROR:core:tcp_send: failed to send<br>Apr 17 08:32:52 [29262] ERROR:tm:msg_send: tcp_send failed<br>Apr 17 08:32:52 [29262] ERROR:tm:t_forward_nonack: sending request failed<br>
Apr 17 08:32:52 [29262] DBG:tm:t_relay_to: t_forward_nonack returned error <br>Apr 17 08:32:52 [29262] DBG:core:parse_headers: flags=ffffffffffffffff<br>Apr 17 08:32:52 [29262] DBG:core:check_ip_address: params 10.1.1.203, 10.1.1.203, 0<br>
Apr 17 08:32:52 [29262] DBG:core:_shm_resize: resize(0) called<br>Apr 17 08:32:52 [29262] DBG:tm:cleanup_uac_timers: RETR/FR timers reset<br>Apr 17 08:32:52 [29262] DBG:tm:insert_timer_unsafe: [2]: 0xb6105740 (45)<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: tcp connection found (0xb60e26c4), acquiring fd<br>
Apr 17 08:32:52 [29262] DBG:core:tcp_send: c= 0xb60e26c4, n=8<br>Apr 17 08:32:52 [29271] DBG:core:handle_ser_child: read response= b612b9c0, -2, fd -1 from 4 (29262)<br>Apr 17 08:32:52 [29271] DBG:core:tcpconn_destroy: delaying (0xb612b9c0, flags 0002) ...<br>
Apr 17 08:32:52 [29271] DBG:core:handle_ser_child: read response= b60e26c4, 1, fd -1 from 4 (29262)<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: after receive_fd: c= 0xb60e26c4 n=4 fd=14<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: sending...<br>
Apr 17 08:32:52 [29262] DBG:core:tls_update_fd: New fd is 14<br>Apr 17 08:32:52 [29262] DBG:core:tls_write: write was successful (389 bytes)<br>Apr 17 08:32:52 [29262] DBG:core:tcp_send: after write: c= 0xb60e26c4 n=389 fd=14<br>
Apr 17 08:32:52 [29262] DBG:core:tcp_send: buf=<br>SIP/2.0 477 Send failed (477/TM)<br>Via: SIP/2.0/TLS 10.1.1.203:1788;rport=1788;branch=z9hG4bKPja09ec884d91f4b0faea630f9fbc156bf<br>From: <<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>>;tag=d5b6699b53424475b7588a272b462a3f<br>
To: <<a href="mailto:sip%3A1000@20.1.1.2">sip:1000@20.1.1.2</a>>;tag=a8259f3b076366b731c5bbc891fa8843-4ced<br>Call-ID: 51c2a37a3a914ccb9189f2b9b2e4870a<br>CSeq: 15905 MESSAGE<br>Server: OpenSIPS (1.6.4-2-tls (i386/linux))<br>
Content-Length: 0<br><br><br>both the clients are directly connected to the server and there is no NAT.This is the first time I am trying opensips with TLS(I am using version 1.6) any help would be appreciated.I am also attaching my config file<br>
<br>Regards<br>Chandra Shekar S<br><pre><br></pre>