Jan 11 11:05:21 [7160] DBG:core:print_ip: tcpconn_new: new tcp connection to: 10.11.57.192
Jan 11 11:05:21 [7160] DBG:core:tcpconn_new: on port 1365, type 3
Jan 11 11:05:21 [7160] DBG:core:tls_tcpconn_init: entered: Creating a whole new ssl connection
Jan 11 11:05:21 [7160] DBG:core:tls_tcpconn_init: looking up socket based TLS server domain [10.11.57.197:5061]
Jan 11 11:05:21 [7160] DBG:core:tls_find_server_domain: virtual TLS server domain not found, Using default TLS server domain settings
Jan 11 11:05:21 [7160] DBG:core:tls_tcpconn_init: found socket based TLS server domain [0.0.0.0:0]
Jan 11 11:05:21 [7160] DBG:core:tls_tcpconn_init: Setting in ACCEPT mode (server)
Jan 11 11:05:21 [7160] DBG:core:tcpconn_add: hashes: 607, 1
Jan 11 11:05:21 [7160] DBG:core:handle_new_connect: new connection: 0xb5daf208 15 flags: 0002
Jan 11 11:05:21 [7160] DBG:core:send2child: to tcp child 0 0(7156), 0xb5daf208
Jan 11 11:05:21 [7156] DBG:core:handle_io: received n=4 con=0xb5daf208, fd=10
Jan 11 11:05:21 [7156] DBG:core:io_watch_add: io_watch_add(0x8163f60, 10, 2, 0xb5daf208), fd_no=1
Jan 11 11:05:23 [7156] DBG:core:tls_update_fd: New fd is 10
Jan 11 11:05:23 [7156] DBG:core:tls_update_fd: New fd is 10
Jan 11 11:05:23 [7156] NOTICE:core:verify_callback: depth = 1
Jan 11 11:05:23 [7156] NOTICE:core:verify_callback: preverify is good: verify return: 1
Jan 11 11:05:23 [7156] NOTICE:core:verify_callback: depth = 0
Jan 11 11:05:23 [7156] NOTICE:core:verify_callback: preverify is good: verify return: 1
Jan 11 11:05:23 [7156] DBG:core:tls_accept: TLS handshake successful
Jan 11 11:05:23 [7156] DBG:core:tls_accept: new connection from 10.11.57.192:1365 using TLSv1/SSLv3 AES256-SHA 256
Jan 11 11:05:23 [7156] DBG:core:tls_accept: local socket: 10.11.57.197:5061
Jan 11 11:05:23 [7156] DBG:core:tls_dump_cert_info: tls_accept: client certificate subject:/C=CN/ST=beijing/O=THOMSON/OU=APDG/CN=dongfb.thomson.com/emailAddress=feng-bin.dong@thomson.com
Jan 11 11:05:23 [7156] DBG:core:tls_dump_cert_info: tls_accept: client certificate issuer: /CN=openserca/ST=beijing/C=CN/emailAddress=opencaadmin@openserca.org/O=OPENSERCA
Jan 11 11:05:23 [7156] DBG:core:tls_dump_cert_info: tls_accept: local (server) certificate subject:/C=CN/ST=beijing/O=THOMSON/OU=APDG/CN=dongfb.thomson.com/emailAddress=feng-bin.dong@thomson.com
Jan 11 11:05:23 [7156] DBG:core:tls_dump_cert_info: tls_accept: local (server) certificate issuer: /CN=openserca/ST=beijing/C=CN/emailAddress=opencaadmin@openserca.org/O=OPENSERCA
Jan 11 11:05:23 [7156] DBG:core:tls_update_fd: New fd is 10
Jan 11 11:05:23 [7156] DBG:core:tls_update_fd: New fd is 10
Jan 11 11:05:23 [7156] DBG:core:_tls_read: 377 bytes read
Jan 11 11:05:23 [7156] DBG:core:tcp_read_req: content-length= 0
Jan 11 11:05:23 [7156] DBG:core:parse_msg: SIP Request:
Jan 11 11:05:23 [7156] DBG:core:parse_msg:  method:  <REGISTER>
Jan 11 11:05:23 [7156] DBG:core:parse_msg:  uri:     <sip:10.11.57.197>
Jan 11 11:05:23 [7156] DBG:core:parse_msg:  version: <SIP/2.0>
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=2
Jan 11 11:05:23 [7156] DBG:core:parse_to: end of header reached, state=10
Jan 11 11:05:23 [7156] DBG:core:parse_to: display={}, ruri={sip:888@10.11.57.197}
Jan 11 11:05:23 [7156] DBG:core:get_hdr_field: <To> [24]; uri=[sip:888@10.11.57.197] 
Jan 11 11:05:23 [7156] DBG:core:get_hdr_field: to body [<sip:888@10.11.57.197>]
Jan 11 11:05:23 [7156] DBG:core:get_hdr_field: cseq <CSeq>: <901> <REGISTER>
Jan 11 11:05:23 [7156] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Jan 11 11:05:23 [7156] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK26500>; state=16
Jan 11 11:05:23 [7156] DBG:core:parse_via: end of header reached, state=5
Jan 11 11:05:23 [7156] DBG:core:parse_headers: via found, flags=2
Jan 11 11:05:23 [7156] DBG:core:parse_headers: this is the first via
Jan 11 11:05:23 [7156] DBG:core:receive_msg: After parse_msg...
Jan 11 11:05:23 [7156] DBG:core:receive_msg: preparing to run routing scripts...
Jan 11 11:05:23 [7156] DBG:maxfwd:is_maxfwd_present: value = 70 
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=200
Jan 11 11:05:23 [7156] DBG:rr:is_preloaded: is_preloaded: Yes
Jan 11 11:05:23 [7156] DBG:core:grep_sock_info: checking if host==us: 12==12 &&  [10.11.57.197] == [10.11.57.197]
Jan 11 11:05:23 [7156] DBG:core:grep_sock_info: checking if port 5061 matches port 5061
Jan 11 11:05:23 [7156] DBG:rr:after_loose: Topmost route URI: 'sip:10.11.57.197:5061;transport=TLS;lr' is me
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=200
Jan 11 11:05:23 [7156] DBG:core:get_hdr_field: content_length=0
Jan 11 11:05:23 [7156] DBG:core:get_hdr_field: found end of header
Jan 11 11:05:23 [7156] DBG:rr:find_next_route: No next Route HF found
Jan 11 11:05:23 [7156] DBG:rr:after_loose: No next URI found
Jan 11 11:05:23 [7156] DBG:core:grep_sock_info: checking if host==us: 12==12 &&  [10.11.57.197] == [10.11.57.197]
Jan 11 11:05:23 [7156] DBG:core:grep_sock_info: checking if port 5061 matches port 5060
Jan 11 11:05:23 [7156] DBG:core:check_self: host != me
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 11 11:05:23 [7156] DBG:tm:t_newtran: T on entrance=0xffffffff
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=78
Jan 11 11:05:23 [7156] DBG:tm:t_lookup_request: start searching: hash=58073, isACK=0
Jan 11 11:05:23 [7156] DBG:tm:matching_3261: RFC3261 transaction matching failed
Jan 11 11:05:23 [7156] DBG:tm:t_lookup_request: no transaction found
Jan 11 11:05:23 [7156] DBG:core:mk_proxy: doing DNS lookup...
Jan 11 11:05:23 [7156] ERROR:tm:update_uac_dst: failed to fwd to af 2, proto 1  (no corresponding listening socket)
Jan 11 11:05:23 [7156] ERROR:tm:t_forward_nonack: failure to add branches
Jan 11 11:05:23 [7156] DBG:tm:t_relay_to: t_forward_nonack returned error 
Jan 11 11:05:23 [7156] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 11 11:05:23 [7156] DBG:core:check_via_address: params 10.11.57.192, 10.11.57.192, 0
Jan 11 11:05:23 [7156] DBG:core:_shm_resize: resize(0) called
Jan 11 11:05:23 [7156] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Jan 11 11:05:23 [7156] DBG:tm:insert_timer_unsafe: [2]: 0xb5dd3228 (110)
Jan 11 11:05:23 [7156] DBG:core:tcp_send: tcp connection found (0xb5daf208), acquiring fd
Jan 11 11:05:23 [7156] DBG:core:tcp_send: c= 0xb5daf208, n=8
Jan 11 11:05:23 [7160] DBG:core:handle_ser_child: read response= b5daf208, 1, fd -1 from 2 (7156)
Jan 11 11:05:23 [7156] DBG:core:tcp_send: after receive_fd: c= 0xb5daf208 n=4 fd=11
Jan 11 11:05:23 [7156] DBG:core:tcp_send: sending...
Jan 11 11:05:23 [7156] DBG:core:tls_update_fd: New fd is 11
Jan 11 11:05:23 [7156] DBG:core:tls_write: write was successful (325 bytes)
Jan 11 11:05:23 [7156] DBG:core:tcp_send: after write: c= 0xb5daf208 n=325 fd=11
Jan 11 11:05:23 [7156] DBG:core:tcp_send: buf=
SIP/2.0 500 Server error occurred (7/TM)
  From: <sip:888@10.11.57.197>
  To: <sip:888@10.11.57.197>;tag=6de70244a9439b1a95183831634130e2-feb6
  Call-ID: 6334@10.11.57.192
  CSeq: 901 REGISTER
  Via: SIP/2.0/TLS 10.11.57.192:5061;rport=1365;branch=z9hG4bK26500
  Server: OpenSER (1.3.0-pre1-tls (i386/linux))
  Content-Length: 0