-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Hi,
I've managed minisip to connect to tls enabled openser. The tls connection is established fine, but when i try to register or try to call i get errors. See attached ser debug output.
Anybody knows what that means? Is the SIP Request from minisip not correct? Or is it a failure in my openser.cfg?
Any help would be nice.
chris...
7(11894) tcpconn_new: new tcp connection to: 192.168.20.130 7(11894) tcpconn_new: on port 35957, type 3 7(11894) tls_tcpconn_init: Entered: Creating a whole new ssl connection 7(11894) tls_tcpconn_init: Looking up tls domain [192.168.20.156:5061] 7(11894) tls_tcpconn_init: Using default tls settings 7(11894) tls_tcpconn_init: Setting in ACCEPT mode (server) 7(11894) tcpconn_add: hashes: 181, 2 7(11894) tcp_main_loop: new connection: 0x405b4b90 19 7(11894) send2child: to tcp child 0 3(11880), 0x405b4b90 3(11880) received n=4 con=0x405b4b90, fd=14 3(11880) tls_update_fd: New fd is 14 3(11880) tls_update_fd: New fd is 14 3(11880) tls_accept: TLS handshake successful 3(11880) tls_update_fd: New fd is 14 3(11880) tls_update_fd: New fd is 14 3(11880) _tls_read: 403 bytes read 3(11880) tcp_read_req: content-length= 0 3(11880) SIP Request: 3(11880) method: <REGISTER> 3(11880) uri: sip:192.168.20.156 3(11880) version: <SIP/2.0> 3(11880) parse_headers: flags=2 3(11880) DEBUG:parse_to:end of header reached, state=9 3(11880) DEBUG: get_hdr_field: <To> [28]; uri=[sip:chris@192.168.20.156] 3(11880) DEBUG: to body [sip:chris@192.168.20.156 ] 3(11880) get_hdr_field: cseq <CSeq>: <601> <REGISTER> 3(11880) Found param type 232, <branch> = <z9hG4bK1327458630>; state=16 3(11880) end of header reached, state=5 3(11880) parse_headers: Via found, flags=2 3(11880) parse_headers: this is the first via 3(11880) After parse_msg... 3(11880) preparing to run routing scripts... 3(11880) DEBUG:maxfwd:is_maxfwd_present: value = 70 3(11880) parse_headers: flags=200 3(11880) is_preloaded: Yes 3(11880) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 3(11880) grep_sock_info - checking if port 5061 matches port 5061 3(11880) after_loose: Topmost route URI: 'sip:192.168.20.156:5061;transport=TLS;lr' is me 3(11880) parse_headers: flags=200 3(11880) DEBUG: get_hdr_body : content_length=0 3(11880) found end of header 3(11880) find_next_route: No next Route HF found 3(11880) after_loose: No next URI found 3(11880) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 3(11880) grep_sock_info - checking if port 5061 matches port 5060 3(11880) check_self: host != me 3(11880) parse_headers: flags=ffffffffffffffff 3(11880) DEBUG: t_newtran: msg id=3 , global msg id=2 , T on entrance=0xffffffff 3(11880) parse_headers: flags=ffffffffffffffff 3(11880) parse_headers: flags=78 3(11880) t_lookup_request: start searching: hash=19221, isACK=0 3(11880) DEBUG: RFC3261 transaction matching failed 3(11880) DEBUG: t_lookup_request: no transaction found 3(11880) DEBUG: mk_proxy: doing DNS lookup... 3(11880) ERROR:tm:add_uac: can't fwd to af 2, proto 1 (no corresponding listening socket) 3(11880) ERROR:tm:t_forward_nonack: failure to add branches 3(11880) ERROR:tm:t_relay_to: t_forward_nonack returned error 3(11880) parse_headers: flags=ffffffffffffffff 3(11880) check_via_address(192.168.20.130, 192.168.20.130, 3) 3(11880) WARNING:vqm_resize: resize(0) called 3(11880) DEBUG: cleanup_uac_timers: RETR/FR timers reset 3(11880) DEBUG: add_to_tail_of_timer[2]: 0x405dc5c0 3(11880) tcp_send: tcp connection found (0x405b4b90), acquiring fd 3(11880) tcp_send, c= 0x405b4b90, n=8 7(11894) tcp_main_loop: read response= 405b4b90, 1 from 3 (11880) 3(11880) tcp_send: after receive_fd: c= 0x405b4b90 n=4 fd=15 3(11880) tcp_send: sending... 3(11880) tls_update_fd: New fd is 15 3(11880) tls_write: Write was successful (530 bytes) 3(11880) tcp_send: after write: c= 0x405b4b90 n=530 fd=15 3(11880) tcp_send: buf= SIP/2.0 500 I'm terribly sorry, server error occurred (7/TM) From: sip:chris@192.168.20.156 To: sip:chris@192.168.20.156;tag=ddf051b13744e2e8329237e95d7a9ade-7b3d Call-ID: 407398382@192.168.20.130 CSeq: 601 REGISTER Via: SIP/2.0/TLS 192.168.20.130:15061;branch=z9hG4bK1327458630 Server: OpenSer (1.0.0-tls (i386/linux)) Content-Length: 0 Warning: 392 192.168.20.156:5061 "Noisy feedback tells: pid=11880 req_src_ip=192.168.20.130 req_src_port=35957 in_uri=sip:192.168.20.156 out_uri=sip:192.168.20.156 via_cnt==1"
3(11880) DEBUG:tm:_reply_light: reply sent out. buf=0x811a978: SIP/2.0 5..., shmem=0x405d9750: SIP/2.0 5 3(11880) DEBUG:tm:_reply_light: finished 3(11880) ERROR: generation of a stateful reply on error succeeded 3(11880) DEBUG:destroy_avp_list: destroying list (nil) 3(11880) receive_msg: cleaning up 2(11878) DEBUG: timer routine:2,tl=0x405dc5c0 next=(nil) 2(11878) DEBUG: wait_handler : removing 0x405dc578 from table 2(11878) DEBUG: delete transaction 0x405dc578 2(11878) DEBUG: wait_handler : done 3(11880) tcp_receive_loop: 0x405b4b90 expired (172, 173) 3(11880) releasing con 0x405b4b90, state 0, fd=14, id=2 3(11880) extra_data 0x4042fd70 7(11894) tcp_main_loop: reader response= 405b4b90, 0 from 0 7(11894) tcp_main_loop: CONN_RELEASE 0x405b4b90 refcnt= 0
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Hi Bogdan,
I think I found a way to connect minisip to SER. I had to open up a UDP Port (5060) as well. Then minisip is registering imidiatly. (didn't changed a think in openser.cfg). But why do I have to do that? I captured all the traffic, but there is nothing transmitted in cleartext (sip) everything is encypted. I also upgraded to the lates cvs version. (tried this with/without the UDP Port)
The only thing i'm checking in the cfg is authentication against mysql db. Nothing more.
chris...
chris... Bogdan-Andrei Iancu schrieb:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Hi Bogdan, I still get the same 'error' with another phone. A snom 190. If I connect it to an TLS only SER I get thd "500 I'm terribly sorry, server error occurred (7/TM)". If I open up UDP as well the phone registeres fine with SER.
I read another posting which sayes: " If I remember correctly the RFC, UDP is mandatory for a SIP server" Is this correct? I don't know it.
I attached my cfg. It's the one coming with tls-openSER and i think you wrote it : )
chris... Bogdan-Andrei Iancu schrieb:
# # $Id: openser.cfg,v 1.6 2006/02/15 18:23:46 bogdan_iancu Exp $ # # simple quick-start config script #
# ----------- global configuration parameters ------------------------
debug=10 # debug level (cmd line: -dddddddddd) fork=yes log_stderror=yes # (cmd line: -E)
/* Uncomment these lines to enter debugging mode fork=no log_stderror=yes */
check_via=no # (cmd. line: -v) dns=no # (cmd. line: -r) rev_dns=no # (cmd. line: -R) #port=5060 children=4 fifo="/tmp/openser_fifo"
# # uncomment the following lines for TLS support disable_tls = 0 listen = udp:192.168.20.156:5060 listen = tls:192.168.6820.156:5061 #tls_verify = 1 tls_require_certificate = 0 tls_method = SSLv23 #TLSv1 tls_certificate = "/home/chris/DA/testcenter-cert.pem" tls_private_key = "/home/chris/DA/testcenter-key.pem" tls_ca_list = "/home/chris/DA/tcs_ca-cacert.pem"
# ------------------ module loading ----------------------------------
# Uncomment this if you want to use SQL database loadmodule "/usr/local/lib/openser/modules/mysql.so"
loadmodule "/usr/local/lib/openser/modules/sl.so" loadmodule "/usr/local/lib/openser/modules/tm.so" loadmodule "/usr/local/lib/openser/modules/rr.so" loadmodule "/usr/local/lib/openser/modules/maxfwd.so" loadmodule "/usr/local/lib/openser/modules/usrloc.so" loadmodule "/usr/local/lib/openser/modules/registrar.so" loadmodule "/usr/local/lib/openser/modules/textops.so"
# Uncomment this if you want digest authentication # mysql.so must be loaded ! loadmodule "/usr/local/lib/openser/modules/auth.so" loadmodule "/usr/local/lib/openser/modules/auth_db.so"
# ----------------- setting module-specific parameters ---------------
# -- usrloc params --
#modparam("usrloc", "db_mode", 0)
# Uncomment this if you want to use SQL database # for persistent storage and comment the previous line modparam("usrloc", "db_mode", 2)
# -- auth params -- # Uncomment if you are using auth module # modparam("auth_db", "calculate_ha1", yes) # # If you set "calculate_ha1" parameter to yes (which true in this config), # uncomment also the following parameter) # modparam("auth_db", "password_column", "password")
# -- rr params -- # add value to ;lr param to make some broken UAs happy modparam("rr", "enable_full_lr", 1)
# ------------------------- request routing logic -------------------
# main routing logic
route{
# initial sanity checks -- messages with # max_forwards==0, or excessively long requests if (!mf_process_maxfwd_header("10")) { sl_send_reply("483","Too Many Hops"); exit; };
if (msg:len >= 2048 ) { sl_send_reply("513", "Message too big"); exit; };
# we record-route all messages -- to make sure that # subsequent messages will go through our proxy; that's # particularly good if upstream and downstream entities # use different transport protocol if (!method=="REGISTER") record_route();
# subsequent messages withing a dialog should take the # path determined by record-routing if (loose_route()) { # mark routing logic in request append_hf("P-hint: rr-enforced\r\n"); route(1); };
if (!uri==myself) { # mark routing logic in request append_hf("P-hint: outbound\r\n"); # if you have some interdomain connections via TLS #if(uri=~"@tls_domain1.net") { # t_relay("tls:domain1.net"); # exit; #} else if(uri=~"@tls_domain2.net") { # t_relay("tls:domain2.net"); # exit; #} route(1); };
# if the request is for other domain use UsrLoc # (in case, it does not work, use the following command # with proper names and addresses in it) if (uri==myself) {
if (method=="REGISTER") {
# Uncomment this if you want to use digest authenticatio n if (!www_authorize("192.168.20.156", "subscriber")) { www_challenge("192.168.20.156", "0"); exit; };
save("location"); exit; };
lookup("aliases"); if (!uri==myself) { append_hf("P-hint: outbound alias\r\n"); route(1); };
# native SIP destinations are handled using our USRLOC DB if (!lookup("location")) { sl_send_reply("404", "Not Found"); exit; }; append_hf("P-hint: usrloc applied\r\n"); };
route(1); }
route[1] { # send it out now; use stateful forwarding as it works reliably # even for UDP2TCP if (!t_relay()) { sl_reply_error(); }; exit; }
Hi Cris,
thanks for you info
Christoph Fürstaller wrote:
yes, UDP is mandatory as protocol.
I attached my cfg. It's the one coming with tls-openSER and i think you wrote it : )
ok - I will take a look, but please give me also the RURI sent by the SNOM (it is essential) - I will try to locate the problem
regards, bogdan
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Hi Bogdan,
Ok, if UDP is needed by this protocol then it shouldn't function without it.
I attached the debuging output from openSER when the snom tries to login.
What are the Contact entries? Are they because the phone didn't unregistered correctly? I just pluged it off and an again to see the login output. All this entries are in the location table in my db.
chris...
Bogdan-Andrei Iancu wrote:
11(26780) tcpconn_new: new tcp connection to: 192.168.20.187 11(26780) tcpconn_new: on port 2049, type 3 11(26780) tls_tcpconn_init: Entered: Creating a whole new ssl connection 11(26780) tls_tcpconn_init: Looking up tls domain [192.168.20.156:5061] 11(26780) tls_tcpconn_init: Using default tls server settings 11(26780) tls_tcpconn_init: Setting in ACCEPT mode (server) 11(26780) tcpconn_add: hashes: 193, 209 11(26780) handle_new_connect: new connection: 0x4060b6c8 25 flags: 0002 11(26780) send2child: to tcp child 0 7(26766), 0x4060b6c8 7(26766) received n=4 con=0x4060b6c8, fd=20 7(26766) DBG: io_watch_add(0x80f17c0, 20, 2, 0x4060b6c8), fd_no=1 7(26766) tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20 7(26766) tls_accept: TLS handshake successful 7(26766) tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20 7(26766) _tls_read: 866 bytes read 7(26766) tcp_read_req: content-length= 0 7(26766) SIP Request: 7(26766) method: <REGISTER> 7(26766) uri: sip:192.168.20.156:5061;transport=tls 7(26766) version: <SIP/2.0> 7(26766) parse_headers: flags=2 7(26766) Found param type 232, <branch> = <z9hG4bK-xwuy1h54dryy>; state=6 7(26766) Found param type 235, <rport> = <n/a>; state=17 7(26766) end of header reached, state=5 7(26766) parse_headers: Via found, flags=2 7(26766) parse_headers: this is the first via 7(26766) After parse_msg... 7(26766) preparing to run routing scripts... 7(26766) parse_headers: flags=100 7(26766) DEBUG:parse_to:end of header reached, state=9 7(26766) DEBUG: get_hdr_field: <To> [53]; uri=[sip:test@192.168.20.156:5061;transport=tls] 7(26766) DEBUG: to body ["test" sip:test@192.168.20.156:5061;transport=tls ] 7(26766) get_hdr_field: cseq <CSeq>: <1> <REGISTER> 7(26766) DEBUG:maxfwd:is_maxfwd_present: value = 70 7(26766) parse_headers: flags=200 7(26766) DEBUG: get_hdr_body : content_length=0 7(26766) found end of header 7(26766) find_first_route: No Route headers found 7(26766) loose_route: There is no Route HF 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060 matches port 5061 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5061 matches port 5061 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060 matches port 5061 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5061 matches port 5061 7(26766) parse_headers: flags=4000 7(26766) pre_auth(): Credentials with given realm not found 7(26766) build_auth_hf(): 'WWW-Authenticate: Digest realm="192.168.20.156", nonce="4423cd4c884708795300456efae3cc8121e7155c" ' 7(26766) parse_headers: flags=ffffffffffffffff 7(26766) check_via_address(192.168.20.187, 192.168.20.187, 0) 7(26766) tcp_send: tcp connection found (0x4060b6c8), acquiring fd 7(26766) tcp_send, c= 0x4060b6c8, n=8 11(26780) handle_ser_child: read response= 4060b6c8, 1, fd -1 from 7 (26766) 7(26766) tcp_send: after receive_fd: c= 0x4060b6c8 n=4 fd=21 7(26766) tcp_send: sending... 7(26766) tls_update_fd: New fd is 21 7(26766) tls_write: Write was successful (722 bytes) 7(26766) tcp_send: after write: c= 0x4060b6c8 n=722 fd=21 7(26766) tcp_send: buf= SIP/2.0 401 Unauthorized Via: SIP/2.0/TLS 192.168.20.187:2049;branch=z9hG4bK-xwuy1h54dryy;rport=2049 From: "test" sip:test@192.168.20.156:5061;transport=tls;tag=3ntprlhika To: "test" sip:test@192.168.20.156:5061;transport=tls;tag=010b4fa55c4d08d1039c6a916bb5ecdc.9c39 Call-ID: 3c26700a0c35-l9lq3hhij6ml@snom190 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="192.168.20.156", nonce="4423cd4c884708795300456efae3cc8121e7155c" Server: OpenSer (1.1.0-dev16 -tls (i386/linux)) Content-Length: 0 Warning: 392 192.168.20.156:5061 "Noisy feedback tells: pid=26766 req_src_ip=192.168.20.187 req_src_port=2049 in_uri=sip:192.168.20.156:5061;transport=tls out_uri=sip:192.168.20.156:5061;transport=tls via_cnt==1"
7(26766) DEBUG:destroy_avp_list: destroying list (nil) 7(26766) receive_msg: cleaning up 7(26766) tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20 7(26766) _tls_read: 1079 bytes read 7(26766) tcp_read_req: content-length= 0 7(26766) SIP Request: 7(26766) method: <REGISTER> 7(26766) uri: sip:192.168.20.156:5061;transport=tls 7(26766) version: <SIP/2.0> 7(26766) parse_headers: flags=2 7(26766) Found param type 232, <branch> = <z9hG4bK-6fjbha0qxrtw>; state=6 7(26766) Found param type 235, <rport> = <n/a>; state=17 7(26766) end of header reached, state=5 7(26766) parse_headers: Via found, flags=2 7(26766) parse_headers: this is the first via 7(26766) After parse_msg... 7(26766) preparing to run routing scripts... 7(26766) parse_headers: flags=100 7(26766) DEBUG:parse_to:end of header reached, state=9 7(26766) DEBUG: get_hdr_field: <To> [53]; uri=[sip:test@192.168.20.156:5061;transport=tls] 7(26766) DEBUG: to body ["test" sip:test@192.168.20.156:5061;transport=tls ] 7(26766) get_hdr_field: cseq <CSeq>: <2> <REGISTER> 7(26766) DEBUG:maxfwd:is_maxfwd_present: value = 70 7(26766) parse_headers: flags=200 7(26766) DEBUG: get_hdr_body : content_length=0 7(26766) found end of header 7(26766) find_first_route: No Route headers found 7(26766) loose_route: There is no Route HF 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060 matches port 5061 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5061 matches port 5061 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060 matches port 5061 7(26766) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5061 matches port 5061 7(26766) check_nonce(): comparing [4423cd4c884708795300456efae3cc8121e7155c] and [4423cd4c884708795300456efae3cc8121e7155c] 7(26766) HA1 string calculated: 53ee6c16b5102c59afa23cbd21a6d936 7(26766) check_response(): Our result = '5eea837512ca0655ce1369c41b5185b6' 7(26766) check_response(): Authorization is OK 7(26766) parse_headers: flags=ffffffffffffffff 7(26766) parse_headers: flags=8000000 7(26766) build_contact(): Created Contact HF: Contact: sip:test@192.168.20.187:2253;transport=tls;line=4f5o4cc1;q=1;expires=246, sip:test@192.168.20.187:2254;transport=tls;line=4f5o4cc1;q=1;expires=759, sip:test@192.168.20.187:2255;transport=tls;line=4f5o4cc1;q=1;expires=1073, sip:test@192.168.20.187:2256;transport=tls;line=4f5o4cc1;q=1;expires=1538, sip:test@192.168.20.187:2257;transport=tls;line=4f5o4cc1;q=1;expires=1849, sip:test@192.168.20.187:2258;transport=tls;line=4f5o4cc1;q=1;expires=2150, sip:test@192.168.20.187:2259;transport=tls;line=4f5o4cc1;q=1;expires=2637, sip:test@192.168.20.187:2260;transport=tls;line=4f5o4cc1;q=1;expires=3022, sip:test@192.168.20.187:2261;transport=tls;line=4f5o4cc1;q=1;expires=3323, sip:test@192.168.20.187:2049;transport=tls;line=xxzpplzh;q=1;expires=3442, sip:test@192.168.20.187:2049;transport=tls;line=kshlnn3b;q=1;expires=3600
7(26766) parse_headers: flags=ffffffffffffffff 7(26766) check_via_address(192.168.20.187, 192.168.20.187, 0) 7(26766) tcp_send: tcp connection found (0x4060b6c8), acquiring fd 7(26766) tcp_send, c= 0x4060b6c8, n=8 11(26780) handle_ser_child: read response= 4060b6c8, 1, fd -1 from 7 (26766) 7(26766) tcp_send: after receive_fd: c= 0x4060b6c8 n=4 fd=21 7(26766) tcp_send: sending... 7(26766) tls_update_fd: New fd is 21 7(26766) tls_write: Write was successful (1467 bytes) 7(26766) tcp_send: after write: c= 0x4060b6c8 n=1467 fd=21 7(26766) tcp_send: buf= SIP/2.0 200 OK Via: SIP/2.0/TLS 192.168.20.187:2049;branch=z9hG4bK-6fjbha0qxrtw;rport=2049 From: "test" sip:test@192.168.20.156:5061;transport=tls;tag=3ntprlhika To: "test" sip:test@192.168.20.156:5061;transport=tls;tag=010b4fa55c4d08d1039c6a916bb5ecdc.a59e Call-ID: 3c26700a0c35-l9lq3hhij6ml@snom190 CSeq: 2 REGISTER Contact: sip:test@192.168.20.187:2253;transport=tls;line=4f5o4cc1;q=1;expires=246, sip:test@192.168.20.187:2254;transport=tls;line=4f5o4cc1;q=1;expires=759, sip:test@192.168.20.187:2255;transport=tls;line=4f5o4cc1;q=1;expires=1073, sip:test@192.168.20.187:2256;transport=tls;line=4f5o4cc1;q=1;expires=1538, sip:test@192.168.20.187:2257;transport=tls;line=4f5o4cc1;q=1;expires=1849, sip:test@192.168.20.187:2258;transport=tls;line=4f5o4cc1;q=1;expires=2150, sip:test@192.168.20.187:2259;transport=tls;line=4f5o4cc1;q=1;expires=2637, sip:test@192.168.20.187:2260;transport=tls;line=4f5o4cc1;q=1;expires=3022, sip:test@192.168.20.187:2261;transport=tls;line=4f5o4cc1;q=1;expires=3323, sip:test@192.168.20.187:2049;transport=tls;line=xxzpplzh;q=1;expires=3442, sip:test@192.168.20.187:2049;transport=tls;line=kshlnn3b;q=1;expires=3600 Server: OpenSer (1.1.0-dev16 -tls (i386/linux)) Content-Length: 0 Warning: 392 192.168.20.156:5061 "Noisy feedback tells: pid=26766 req_src_ip=192.168.20.187 req_src_port=2049 in_uri=sip:192.168.20.156:5061;transport=tls out_uri=sip:192.168.20.156:5061;transport=tls via_cnt==1"
7(26766) DEBUG:destroy_avp_list: destroying list (nil) 7(26766) receive_msg: cleaning up 7(26766) tcp_receive_loop: 0x4060b6c8 expired (81329, 81330) 7(26766) DBG: io_watch_del (0x80f17c0, 20, -1, 0x10) fd_no=2 called 7(26766) releasing con 0x4060b6c8, state 0, fd=20, id=209 7(26766) extra_data 0x405dad88 11(26780) handle_tcp_child: reader response= 4060b6c8, 0 from 0 11(26780) DBG: io_watch_add(0x80f14a0, 25, 2, 0x4060b6c8), fd_no=15 11(26780) handle_tcp_child: CONN_RELEASE 0x4060b6c8 refcnt= 0
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Hi Bogdan,
Sry, didn't thought when I sent the logs. Here is the debug output with an error 500.
chris...
Bogdan-Andrei Iancu schrieb:
7(18696) tcpconn_new: new tcp connection to: 192.168.20.130 7(18696) tcpconn_new: on port 53605, type 3 7(18696) tls_tcpconn_init: Entered: Creating a whole new ssl connection 7(18696) tls_tcpconn_init: Looking up tls domain [192.168.20.156:5061] 7(18696) tls_tcpconn_init: Using default tls server settings 7(18696) tls_tcpconn_init: Setting in ACCEPT mode (server) 7(18696) tcpconn_add: hashes: 421, 1 7(18696) handle_new_connect: new connection: 0x405ca688 20 flags: 0002 7(18696) send2child: to tcp child 0 3(18691), 0x405ca688 3(18691) received n=4 con=0x405ca688, fd=15 3(18691) DBG: io_watch_add(0x80f17c0, 15, 2, 0x405ca688), fd_no=1 3(18691) tls_update_fd: New fd is 15 3(18691) tls_update_fd: New fd is 15 3(18691) tls_accept: TLS handshake successful 3(18691) tls_update_fd: New fd is 15 3(18691) tls_update_fd: New fd is 15 3(18691) _tls_read: 394 bytes read 3(18691) tcp_read_req: content-length= 0 3(18691) SIP Request: 3(18691) method: <REGISTER> 3(18691) uri: sip:192.168.20.156 3(18691) version: <SIP/2.0> 3(18691) parse_headers: flags=2 3(18691) DEBUG:parse_to:end of header reached, state=9 3(18691) DEBUG: get_hdr_field: <To> [25]; uri=[sip:10@192.168.20.156] 3(18691) DEBUG: to body [sip:10@192.168.20.156] 3(18691) get_hdr_field: cseq <CSeq>: <301> <REGISTER> 3(18691) Found param type 232, <branch> = <z9hG4bK1474748722>; state=16 3(18691) end of header reached, state=5 3(18691) parse_headers: Via found, flags=2 3(18691) parse_headers: this is the first via 3(18691) After parse_msg... 3(18691) preparing to run routing scripts... 3(18691) DEBUG:maxfwd:is_maxfwd_present: value = 70 3(18691) parse_headers: flags=200 3(18691) is_preloaded: Yes 3(18691) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 3(18691) grep_sock_info - checking if port 5061 matches port 5061 3(18691) after_loose: Topmost route URI: 'sip:192.168.20.156:5061;transport=TLS;lr' is me 3(18691) parse_headers: flags=200 3(18691) DEBUG: get_hdr_body : content_length=0 3(18691) found end of header 3(18691) find_next_route: No next Route HF found 3(18691) after_loose: No next URI found 3(18691) grep_sock_info - checking if host==us: 14==14 && [192.168.20.156] == [192.168.20.156] 3(18691) grep_sock_info - checking if port 5061 matches port 5060 3(18691) check_self: host != me 3(18691) parse_headers: flags=ffffffffffffffff 3(18691) DEBUG: t_newtran: msg id=1 , global msg id=0 , T on entrance=0xffffffff 3(18691) parse_headers: flags=ffffffffffffffff 3(18691) parse_headers: flags=78 3(18691) t_lookup_request: start searching: hash=58053, isACK=0 3(18691) DEBUG: RFC3261 transaction matching failed 3(18691) DEBUG: t_lookup_request: no transaction found 3(18691) DEBUG: mk_proxy: doing DNS lookup... 3(18691) ERROR:tm:add_uac: can't fwd to af 2, proto 1 (no corresponding listening socket) 3(18691) ERROR:tm:t_forward_nonack: failure to add branches 3(18691) ERROR:tm:t_relay_to: t_forward_nonack returned error 3(18691) parse_headers: flags=ffffffffffffffff 3(18691) check_via_address(192.168.20.130, 192.168.20.130, 0) 3(18691) WARNING:vqm_resize: resize(0) called 3(18691) DEBUG: cleanup_uac_timers: RETR/FR timers reset 3(18691) DEBUG: add_to_tail_of_timer[2]: 0x405ee610 3(18691) tcp_send: tcp connection found (0x405ca688), acquiring fd 3(18691) tcp_send, c= 0x405ca688, n=8 7(18696) handle_ser_child: read response= 405ca688, 1, fd -1 from 3 (18691) 3(18691) tcp_send: after receive_fd: c= 0x405ca688 n=4 fd=16 3(18691) tcp_send: sending... 3(18691) tls_update_fd: New fd is 16 3(18691) tls_write: Write was successful (531 bytes) 3(18691) tcp_send: after write: c= 0x405ca688 n=531 fd=16 3(18691) tcp_send: buf= SIP/2.0 500 I'm terribly sorry, server error occurred (7/TM) From: sip:10@192.168.20.156 To: sip:10@192.168.20.156;tag=ddf051b13744e2e8329237e95d7a9ade-5806 Call-ID: 532272529@192.168.20.130 CSeq: 301 REGISTER Via: SIP/2.0/TLS 192.168.20.130:34820;branch=z9hG4bK1474748722 Server: OpenSer (1.1.0-dev16 -tls (i386/linux)) Content-Length: 0 Warning: 392 192.168.20.156:5061 "Noisy feedback tells: pid=18691 req_src_ip=19 2.168.20.130 req_src_port=53605 in_uri=sip:192.168.20.156 out_uri=sip:192.168.20.156 via_cnt==1"
3(18691) DEBUG:tm:_reply_light: reply sent out. buf=0x812e300: SIP/2.0 5..., sh mem=0x405ef8c0: SIP/2.0 5 3(18691) DEBUG:tm:_reply_light: finished 3(18691) ERROR: generation of a stateful reply on error succeeded 3(18691) DEBUG:destroy_avp_list: destroying list (nil) 3(18691) receive_msg: cleaning up 2(18689) DEBUG: timer routine:2,tl=0x405ee610 next=(nil) 2(18689) DEBUG: wait_handler : removing 0x405ee5c8 from table 2(18689) DEBUG: delete transaction 0x405ee5c8 2(18689) DEBUG: wait_handler : done 3(18691) tcp_receive_loop: 0x405ca688 expired (22, 23) 3(18691) DBG: io_watch_del (0x80f17c0, 15, -1, 0x10) fd_no=2 called 3(18691) releasing con 0x405ca688, state 0, fd=15, id=1 3(18691) extra_data 0x405da7a0 7(18696) handle_tcp_child: reader response= 405ca688, 0 from 0 7(18696) DBG: io_watch_add(0x80f14a0, 20, 2, 0x405ca688), fd_no=11 7(18696) handle_tcp_child: CONN_RELEASE 0x405ca688 refcnt= 0 7(18696) handle_tcpconn_ev: data available on 0x405ca688 20 7(18696) DBG: io_watch_del (0x80f14a0, 20, -1, 0x0) fd_no=12 called 7(18696) send2child: to tcp child 0 3(18691), 0x405ca688 3(18691) received n=4 con=0x405ca688, fd=15 3(18691) DBG: io_watch_add(0x80f17c0, 15, 2, 0x405ca688), fd_no=1 3(18691) tls_update_fd: New fd is 15 3(18691) _tls_read: Error in SSL: 3(18691) ERROR: tcp_read_req: error reading 3(18691) DBG: io_watch_del (0x80f17c0, 15, -1, 0x10) fd_no=2 called 3(18691) releasing con 0x405ca688, state -2, fd=15, id=1 3(18691) extra_data 0x405da7a0 7(18696) handle_tcp_child: reader response= 405ca688, -2 from 0 7(18696) tcpconn_destroy: destroying connection 0x405ca688, flags 0002 7(18696) tls_close: Closing SSL connection 7(18696) tls_update_fd: New fd is 20 7(18696) tls_shutdown: First phase of 2-way handshake completed succesfuly 7(18696) tls_tcpconn_clean: Entered