sr-users March 2010

sr-users@lists.kamailio.org

60 participants
118 discussions

[Kamailio-Users] get warning when sip client is not online
by s.maertens＠telenet.be 30 Mar '10

30 Mar '10

Hello, I have a kamailio setup running for several SIP devices. I would like to be warned whenever one of those devices is not reacheable anymore. That means when they go offline or are not anymore registered to the kamailio server. (timeout, unregister, ...). I am using the location table so we would be able to write a script that just at specific times checks the difference between the subscriber table and the location table but maybe there is a much better and more realtime solution. So basically the question is : how to execute a script whenever a host gets removed fom the location table. I am running Kamailio 3.0.1 All hints are very much appreciated :)

3 2

[Kamailio-Users] GSoC 2010 Student Registration is Open
by Daniel-Constantin Mierla 30 Mar '10

30 Mar '10

Hello, if you are a student (or know one) interested in working with SIP and Presence over the summer, earn some money and experience, you have the choice of Kamailio - SIP Router project within SIP Communicator organization: http://www.kamailio.org/w/gsoc-2010/ Registration is now open, up to April 9, more details in above link. If you have further questions, drop an email. Cheers, Daniel -- Daniel-Constantin Mierla * http://www.asipto.com/ * http://twitter.com/miconda * http://www.linkedin.com/in/danielconstantinmierla

1 0

ser avp question
by jh＠tutpro.com 29 Mar '10

29 Mar '10

modules_s/domain domain_lookup() function can be used to assign domain attributes to avps. for example, lookup_domain("$fd", "foo.bar"), assigns attributes of domain foo.bar to avps $fd.x, where x is name of attribute. my question is, how can i index these avps if there is more than one with the same name? statement $var(attr) = $fd.attr[]; does not give syntax errors, but $var(attr) = $fd.attr[$var(i)]; produces 0(7368) : <core> [cfg.y:3379]: parse error in config file /etc/sip-proxy/sip-proxy.cfg, line 3174, column 24-30: syntax error 0(7368) : <core> [cfg.y:3379]: parse error in config file /etc/sip-proxy/sip-proxy.cfg, line 3174, column 24-30: bad command 0(7368) : <core> [cfg.y:3382]: parse error in config file /etc/sip-proxy/sip-proxy.cfg, line 3174, column 31: bad command 0(7368) : <core> [cfg.y:3382]: parse error in config file /etc/sip-proxy/sip-proxy.cfg, line 3174, column 31: bad command -- juha

3 5

weird dp_translate() behavior
by jh＠tutpro.com 29 Mar '10

29 Mar '10

while playing with dp_translate(), i noticed the following weird behavior. i have a rule with dpid=11, where match_exp='^\+' and subst_exp and repl_exp are empty. my test goes like this: $rU = "+35892345670"; if (dp_translate("11", $rU/$rU")) { xlog("ruri user is '$rU'\n"); }; $var(test) = "+35892345670"; if (dp_translate("11", "$var(test)/$var(test)")) { xlog("var(test) is '$var(test)'\n"); }; and this is produced to syslog: Mar 29 20:01:39 localhost /usr/sbin/sip-proxy[20533]: ERROR: ruri user is '+35892345670' Mar 29 20:01:39 localhost /usr/sbin/sip-proxy[20533]: ERROR: var(test) is '' that is, $rU is not translated to empty string, but $var(test) is. can someone provide an explanation for this? what should the expected behavior be, when subst_exp and repl_exp are empty? original author of dialplan module is Andreea-Ancuta Onofrei, but i don't know if he is still around. -- juha

1 1

@msg.%s syntax
by jh＠tutpro.com 29 Mar '10

29 Mar '10

first section of page http://sip-router.org/wiki/cookbooks/selects/devel had example @msg.["P-anyheader-youwant"]) that, however, produced syntax error. i removed the dot and got rid of the error. i then went and fixed the wiki page too. however, later on the page there still is @msg.%s and many more like that. are they generated automatically? if so, then fixing them on the wiki page would not help. also, is there somewhere a summary of pv syntax of s and k flavors? -- juha

2 5

Re: [Kamailio-Users] Problem with secure TLS call
by Hemanshu Patel 29 Mar '10

29 Mar '10

With TLS it still is not working Mar 27 11:39:16 [4421] INFO:core:probe_max_receive_buffer: using a UDP receive buffer of 255 kb Mar 27 11:39:16 [4425] WARNING:usrloc:dbrow2info: non-local socket <tcp:172.16.16.218:5091>...ignoring Mar 27 11:39:18 [4431] INFO:core:tls_accept: client did not present a certificate Mar 27 11:39:55 [4432] INFO:core:tls_accept: client did not present a certificate Mar 27 11:40:01 [4431] ERROR:rr:w_record_route: Double attempt to record-route Mar 27 11:40:01 [4426] ERROR:core:tls_connect: SSL_ERROR_SYSCALL err=Connection reset by peer(104) Mar 27 11:40:01 [4426] ERROR:core:tls_connect: something wrong in SSL: 5 (ret=-1) err=Connection reset by peer(104) Mar 27 11:40:01 [4426] ERROR:core:tcp_send: failed to send Mar 27 11:40:01 [4426] ERROR:core:msg_send: tcp_send failed Mar 27 11:40:01 [4425] WARNING:core:run_actions: null action list (rec_level=1) my doubt is that if somethings wrong with SSL certificates that i created myself (i.e my own root CA, and self signed certificates), then how come registration is working like charm? if there is some problem with Certificates then registration should also not work. am i right? ---- Regards, Hemanshu Patel Sr. Software Engg SIS,Ahmedabad Mo:09601295238 On Sat 27/03/10 9:50 AM , "Hemanshu Patel" <hemanshu.patel(a)saicare.com> wrote: > I havent tested over TCP, let me check it > but hardphone, i mean hardware based phones from grandstream gvx3140 > works > fine with same implementation on TLS. > -- > Regards, > Hemanshu Patel > M: 09601295238 > > Does eyebeam with SIP over TCP is working? > > > > Am 26.03.2010 13:43, schrieb Hemanshu Patel: > >> > >> i am still having this problem. > >> when i use two grandstream phone everything works fine, > >> i can make calls on TLS and users can talk to each other. > >> > >> But when i use two eyebream phone, it doesnt work, gives > following error > >> > >> :33 [2875] WARNING:core:init_ssl_ctx_behavior: server > verification NOT > >> activated. Weaker security. > >> [ panreg-tls]$ > >> [ panreg-tls]$ > >> [ panreg-tls]$ Mar 26 18:11:59 [2889] > >> ERROR:rr:w_record_route: Double attempt to record-route > >> Mar 26 18:12:09 [2884] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:09 [2884] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:09 [2884] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:09 [2884] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:10 [2883] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:10 [2883] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:10 [2883] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:10 [2883] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:10 [2883] WARNING:core:run_actions: null action list > >> (rec_level=1) > >> Mar 26 18:12:11 [2881] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:11 [2881] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:11 [2881] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:11 [2881] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:13 [2882] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:13 [2882] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:13 [2882] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:13 [2882] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:19 [2884] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:19 [2884] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:19 [2884] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:19 [2884] ERROR:core:msg_send: tcp_send failed > >> > >> > >> > >> Any idea? Same configuration works with grandstream, while they > cant in > >> softphone? and gives 477 errot code. > >> > >> my asterisk log is as below: > >> > >> 26 18:08:09] WARNING[2833]: chan_sip.c:1648 setup_crypto: > Hemanshu: > >> local_key641 jhbAJ7jFE1p/Ngn4kVxy7qTTmkJpeBiN6W98+gmM len 40 > >> -- Called kamailio/1003 > >> -- Got SIP response 477 "Send failed (477/SL)" back from > >> 172.16.16.218 > >> -- No one is available to answer at this time (1:0/0/0) > >> -- Executing [_default:4] Hangup("SIP/5091-8c001430", "") > >> in > >> new stack > >> == Spawn extension (hemu_default, 1003, 4) exited non-zero on > >> 'SIP/5091-8c001430' > >> > ::Disconnected form Oracle, trying to connect again.. > >> > ::Tried a lot, not getting connected.. > >> -- Got SIP response 477 "Send failed (477/SL)" back from > >> 172.16.16.218 > >> > >> > >> Any idea what could be the problem? > >> > > > _______________________________________________ > Kamailio (OpenSER) - Users mailing list > http://lists.kamailio.org/cgi-bin/mailman/listinfo/users > http://lists.openser-project.org/cgi-bin/mailman/listinfo/users > > ---- SIS Blade Server, Desktop & Thin Client is now available on DGS & D rate contract. For more detail kindly visit our website http://www.saicare.com

2 4

Re: [Kamailio-Users] Problem with secure TLS call
by Hemanshu Patel 29 Mar '10

29 Mar '10

Here is the complete call log for One call from two clients eyebream and bria running on single PC. Mar 27 12:36:36 [5492] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:36 [5492] DBG:core:receive_msg: cleaning up Mar 27 12:36:42 [5492] DBG:core:tcp_receive_timeout: 0x7fd335f04798 expired (50, 51) lt=0 Mar 27 12:36:42 [5492] DBG:core:io_watch_del: io_watch_del (0x74efe0, 18, -1, 0x10) fd_no=2 called Mar 27 12:36:42 [5492] DBG:core:release_tcpconn: releasing con 0x7fd335f04798, state 0, fd=18, id=3 Mar 27 12:36:42 [5492] DBG:core:release_tcpconn: extra_data 0x7fd335f017b8 Mar 27 12:36:42 [5499] DBG:core:handle_tcp_child: reader response= 7fd335f04798, 0 from 0 Mar 27 12:36:42 [5499] DBG:core:io_watch_add: io_watch_add(0x74ee80, 24, 2, 0x7fd335f04798), fd_no=17 Mar 27 12:36:42 [5499] DBG:core:handle_tcp_child: cmd CONN_RELEASE 0x7fd335f04798 refcnt= 0 Mar 27 12:36:45 [5499] DBG:core:handle_tcpconn_ev: data available on 0x7fd335eddc18 23 Mar 27 12:36:45 [5499] DBG:core:io_watch_del: io_watch_del (0x74ee80, 23, -1, 0x0) fd_no=18 called Mar 27 12:36:45 [5499] DBG:core:send2child: to tcp child 0 0(5492), 0x7fd335eddc18 Mar 27 12:36:45 [5492] DBG:core:handle_io: received n=8 con=0x7fd335eddc18, fd=18 Mar 27 12:36:45 [5492] DBG:core:io_watch_add: io_watch_add(0x74efe0, 18, 2, 0x7fd335eddc18), fd_no=1 Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 18 Mar 27 12:36:45 [5492] DBG:core:_tls_read: 1109 bytes read Mar 27 12:36:45 [5492] DBG:core:tcp_read_req: content-length= 512 Mar 27 12:36:45 [5492] DBG:core:parse_msg: SIP Request: Mar 27 12:36:45 [5492] DBG:core:parse_msg: method: <INVITE> Mar 27 12:36:45 [5492] DBG:core:parse_msg: uri: <sip:1002@172.16.16.218:5091;transport=tls> Mar 27 12:36:45 [5492] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-e333132001727d6d-1---d8754z->; state=6 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 Mar 27 12:36:45 [5492] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5492] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5492] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5492] DBG:core:receive_msg: preparing to run routing scripts... Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=100 Mar 27 12:36:45 [5492] DBG:maxfwd:is_maxfwd_present: value = 70 Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5492] DBG:core:parse_to: end of header reached, state=10 Mar 27 12:36:45 [5492] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: <To> [31]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091> ] Mar 27 12:36:45 [5492] DBG:siputils:has_totag: no totag Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=78 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE> Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: start searching: hash=44320, isACK=0 Mar 27 12:36:45 [5492] DBG:tm:matching_3261: RFC3261 transaction matching failed Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: no transaction found Mar 27 12:36:45 [5492] DBG:core:parse_to_param: tag=9f574228 Mar 27 12:36:45 [5492] DBG:core:parse_to: end of header reached, state=29 Mar 27 12:36:45 [5492] DBG:core:parse_to: display={"1003"}, ruri={sip:1003@172.16.16.218:5091} Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if host==us: 13==13 && [172.16.16.218] == [172.16.16.218] Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if port 5090 matches port 5091 Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if host==us: 13==13 && [172.16.16.218] == [172.16.16.218] Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if port 5092 matches port 5091 Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if host==us: 13==13 && [172.16.16.218] == [172.16.16.218] Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if port 5091 matches port 5091 Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: match found for: [172.16.16.218:5091] Mar 27 12:36:45 [5492] DBG:core:check_self: host == me Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=10000 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: content_length=512 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: found end of header Mar 27 12:36:45 [5492] DBG:auth:pre_auth: credentials with given realm not found Mar 27 12:36:45 [5492] DBG:auth:reserve_nonce_index: second= 22, sec_monit= -1, index= 3 Mar 27 12:36:45 [5492] DBG:auth:build_auth_hf: nonce index= 3 Mar 27 12:36:45 [5492] DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="172.16.16.218", nonce="4badaea30000000316e854bb0194116d66618a39dcd9340c" ' Mar 27 12:36:45 [5492] DBG:sl:send_reply: reply in stateless mode (sl) Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=ffffffffffffffff Mar 27 12:36:45 [5492] DBG:core:check_via_address: params 172.16.17.85, 172.16.17.85, 0 Mar 27 12:36:45 [5492] DBG:core:tcp_send: tcp connection found (0x7fd335eddc18), acquiring fd Mar 27 12:36:45 [5492] DBG:core:tcp_send: c= 0x7fd335eddc18, n=16 Mar 27 12:36:45 [5499] DBG:core:handle_ser_child: read response= 7fd335eddc18, 1, fd -1 from 7 (5492) Mar 27 12:36:45 [5492] DBG:core:tcp_send: after receive_fd: c= 0x7fd335eddc18 n=8 fd=19 Mar 27 12:36:45 [5492] DBG:core:tcp_send: sending... Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 19 Mar 27 12:36:45 [5492] DBG:core:tls_write: write was successful (519 bytes) Mar 27 12:36:45 [5492] DBG:core:tcp_send: after write: c= 0x7fd335eddc18 n=519 fd=19 Mar 27 12:36:45 [5492] DBG:core:tcp_send: buf= SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/TLS 172.16.17.85:4403;branch=z9hG4bK-d8754z-e333132001727d6d-1---d8754z-;rport=1301 To: <sip:1002@172.16.16.218:5091>;tag=2cf7f9a22b6374f465182a893bba7dec.5636 From: "1003"<sip:1003@172.16.16.218:5091>;tag=9f574228 Call-ID: M2Y2OThmYmYwZjM4ODhhYzk4Mjc0MGFhMDQyNDUzZWU. CSeq: 1 INVITE Proxy-Authenticate: Digest realm="172.16.16.218", nonce="4badaea30000000316e854bb0194116d66618a39dcd9340c" Server: Kamailio (1.5.4-tls (x86_64/linux)) Content-Length: 0 Mar 27 12:36:45 [5492] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5492] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 18 Mar 27 12:36:45 [5492] DBG:core:_tls_read: 370 bytes read Mar 27 12:36:45 [5492] DBG:core:tcp_read_req: content-length= 0 Mar 27 12:36:45 [5492] DBG:core:parse_msg: SIP Request: Mar 27 12:36:45 [5492] DBG:core:parse_msg: method: <ACK> Mar 27 12:36:45 [5492] DBG:core:parse_msg: uri: <sip:1002@172.16.16.218:5091;transport=tls> Mar 27 12:36:45 [5492] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-e333132001727d6d-1---d8754z->; state=6 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 Mar 27 12:36:45 [5492] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5492] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5492] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5492] DBG:core:receive_msg: preparing to run routing scripts... Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5492] DBG:core:parse_to_param: tag=2cf7f9a22b6374f465182a893bba7dec.5636 Mar 27 12:36:45 [5492] DBG:core:parse_to: end of header reached, state=29 Mar 27 12:36:45 [5492] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: <To> [73]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091>] Mar 27 12:36:45 [5492] DBG:sl:sl_filter_ACK: local ACK found -> dropping it! Mar 27 12:36:45 [5492] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5492] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 18 Mar 27 12:36:45 [5492] DBG:core:_tls_read: 1339 bytes read Mar 27 12:36:45 [5492] DBG:core:tcp_read_req: content-length= 512 Mar 27 12:36:45 [5492] DBG:core:parse_msg: SIP Request: Mar 27 12:36:45 [5492] DBG:core:parse_msg: method: <INVITE> Mar 27 12:36:45 [5492] DBG:core:parse_msg: uri: <sip:1002@172.16.16.218:5091;transport=tls> Mar 27 12:36:45 [5492] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-863b295f961d253f-1---d8754z->; state=6 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 Mar 27 12:36:45 [5492] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5492] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5492] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5492] DBG:core:receive_msg: preparing to run routing scripts... Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=100 Mar 27 12:36:45 [5492] DBG:maxfwd:is_maxfwd_present: value = 70 Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5492] DBG:core:parse_to: end of header reached, state=10 Mar 27 12:36:45 [5492] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: <To> [31]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091> ] Mar 27 12:36:45 [5492] DBG:siputils:has_totag: no totag Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=78 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE> Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: start searching: hash=44317, isACK=0 Mar 27 12:36:45 [5492] DBG:tm:matching_3261: RFC3261 transaction matching failed Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: no transaction found Mar 27 12:36:45 [5492] DBG:core:parse_to_param: tag=9f574228 Mar 27 12:36:45 [5492] DBG:core:parse_to: end of header reached, state=29 Mar 27 12:36:45 [5492] DBG:core:parse_to: display={"1003"}, ruri={sip:1003@172.16.16.218:5091} Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if host==us: 13==13 && [172.16.16.218] == [172.16.16.218] Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if port 5090 matches port 5091 Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if host==us: 13==13 && [172.16.16.218] == [172.16.16.218] Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if port 5092 matches port 5091 Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if host==us: 13==13 && [172.16.16.218] == [172.16.16.218] Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: checking if port 5091 matches port 5091 Mar 27 12:36:45 [5492] DBG:core:grep_sock_info: match found for: [172.16.16.218:5091] Mar 27 12:36:45 [5492] DBG:core:check_self: host == me Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=10000 Mar 27 12:36:45 [5492] DBG:auth:check_nonce: comparing [4badaea30000000316e854bb0194116d66618a39dcd9340c] and [4badaea30000000316e854bb0194116d66618a39dcd9340c] Mar 27 12:36:45 [5492] DBG:core:db_new_result: allocate 48 bytes for result set at 0x78d6c8 Mar 27 12:36:45 [5492] DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query Mar 27 12:36:45 [5492] DBG:core:db_allocate_columns: allocate 8 bytes for result names at 0x78aab8 Mar 27 12:36:45 [5492] DBG:core:db_allocate_columns: allocate 4 bytes for result types at 0x79ea58 Mar 27 12:36:45 [5492] DBG:db_mysql:db_mysql_get_columns: allocate 16 bytes for RES_NAMES[0] at 0x78d010 Mar 27 12:36:45 [5492] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x78d010)[0]=[password] Mar 27 12:36:45 [5492] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type Mar 27 12:36:45 [5492] DBG:core:db_allocate_rows: allocate 16 bytes for rows at 0x79ea38 Mar 27 12:36:45 [5492] DBG:core:db_allocate_row: allocate 32 bytes for row values at 0x79ea78 Mar 27 12:36:45 [5492] DBG:core:db_str2val: converting STRING [1234] Mar 27 12:36:45 [5492] DBG:auth_db:get_ha1: HA1 string calculated: 6650a5aab1d658b465ee304e21b8db36 Mar 27 12:36:45 [5492] DBG:auth:check_response: our result = '19406efa15546eb60e105c164a1feb3d' Mar 27 12:36:45 [5492] DBG:auth:check_response: authorization is OK Mar 27 12:36:45 [5492] DBG:auth:post_auth: nonce index= 3 Mar 27 12:36:45 [5492] DBG:core:db_free_columns: freeing 1 columns Mar 27 12:36:45 [5492] DBG:core:db_free_columns: freeing RES_NAMES[0] at 0x78d010 Mar 27 12:36:45 [5492] DBG:core:db_free_columns: freeing result names at 0x78aab8 Mar 27 12:36:45 [5492] DBG:core:db_free_columns: freeing result types at 0x79ea58 Mar 27 12:36:45 [5492] DBG:core:db_free_rows: freeing 1 rows Mar 27 12:36:45 [5492] DBG:core:db_free_row: freeing row values at 0x79ea78 Mar 27 12:36:45 [5492] DBG:core:db_free_rows: freeing rows at 0x79ea38 Mar 27 12:36:45 [5492] DBG:core:db_free_result: freeing result set at 0x78d6c8 Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=14000 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: content_length=512 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: found end of header Mar 27 12:36:45 [5492] DBG:core:comp_scriptvar: str 29 : 1003 ---- Invite ---- Mar 27 12:36:45 [5492] DBG:core:comp_scriptvar: str 29 : 1003 Mar 27 12:36:45 [5492] ERROR:rr:w_record_route: Double attempt to record-route Mar 27 12:36:45 [5492] DBG:dispatcher:ds_select_dst: set [1] Mar 27 12:36:45 [5492] DBG:dispatcher:ds_select_dst: alg hash [789753065] Mar 27 12:36:45 [5492] DBG:dispatcher:ds_select_dst: selected [0-1/0] <sip:172.16.16.218:5070> Mar 27 12:36:45 [5492] DBG:tm:t_newtran: transaction on entrance=(nil) Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=ffffffffffffffff Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=78 Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: start searching: hash=44317, isACK=0 Mar 27 12:36:45 [5492] DBG:tm:matching_3261: RFC3261 transaction matching failed Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: no transaction found Mar 27 12:36:45 [5492] DBG:tm:run_reqin_callbacks: trans=0x7fd335eee6b0, callback type 1, id 0 entered Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=ffffffffffffffff Mar 27 12:36:45 [5492] DBG:core:check_via_address: params 172.16.17.85, 172.16.17.85, 0 Mar 27 12:36:45 [5492] DBG:core:_shm_resize: resize(0) called Mar 27 12:36:45 [5492] DBG:core:tcp_send: tcp connection found (0x7fd335eddc18), acquiring fd Mar 27 12:36:45 [5492] DBG:core:tcp_send: c= 0x7fd335eddc18, n=16 Mar 27 12:36:45 [5499] DBG:core:handle_ser_child: read response= 7fd335eddc18, 1, fd -1 from 7 (5492) Mar 27 12:36:45 [5492] DBG:core:tcp_send: after receive_fd: c= 0x7fd335eddc18 n=8 fd=19 Mar 27 12:36:45 [5492] DBG:core:tcp_send: sending... Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 19 Mar 27 12:36:45 [5492] DBG:core:tls_write: write was successful (352 bytes) Mar 27 12:36:45 [5492] DBG:core:tcp_send: after write: c= 0x7fd335eddc18 n=352 fd=19 Mar 27 12:36:45 [5492] DBG:core:tcp_send: buf= SIP/2.0 100 Giving a try Via: SIP/2.0/TLS 172.16.17.85:4403;branch=z9hG4bK-d8754z-863b295f961d253f-1---d8754z-;rport=1301 To: <sip:1002@172.16.16.218:5091> From: "1003"<sip:1003@172.16.16.218:5091>;tag=9f574228 Call-ID: M2Y2OThmYmYwZjM4ODhhYzk4Mjc0MGFhMDQyNDUzZWU. CSeq: 2 INVITE Server: Kamailio (1.5.4-tls (x86_64/linux)) Content-Length: 0 Mar 27 12:36:45 [5492] DBG:tm:_reply_light: reply sent out. buf=0x79f5e8: SIP/2.0 1..., shmem=0x7fd335f007a8: SIP/2.0 1 Mar 27 12:36:45 [5492] DBG:tm:_reply_light: finished Mar 27 12:36:45 [5492] DBG:core:mk_proxy: doing DNS lookup... Mar 27 12:36:45 [5492] DBG:core:build_req_buf_from_sip_req: id added: <;i=1>, rcv proto=3 Mar 27 12:36:45 [5492] DBG:tm:set_timer: relative timeout is 500000 Mar 27 12:36:45 [5492] DBG:tm:insert_timer_unsafe: [4]: 0x7fd335eee8d0 (54200000) Mar 27 12:36:45 [5492] DBG:tm:set_timer: relative timeout is 30 Mar 27 12:36:45 [5492] DBG:tm:insert_timer_unsafe: [0]: 0x7fd335eee900 (83) Mar 27 12:36:45 [5492] DBG:tm:t_relay_to: new transaction fwd'ed Mar 27 12:36:45 [5492] DBG:tm:t_unref: UNREF_UNSAFE: after is 0 Mar 27 12:36:45 [5492] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5492] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5487] DBG:core:parse_msg: SIP Reply (status): Mar 27 12:36:45 [5487] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5487] DBG:core:parse_msg: status: <100> Mar 27 12:36:45 [5487] DBG:core:parse_msg: reason: <Trying> Mar 27 12:36:45 [5487] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5487] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd1da.1a6f9b73.0>; state=6 Mar 27 12:36:45 [5487] DBG:core:parse_via_param: found param type 236, <i> = <1>; state=6 Mar 27 12:36:45 [5487] DBG:core:parse_via_param: found param type 234, <received> = <172.16.16.218>; state=16 Mar 27 12:36:45 [5487] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5487] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5487] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5487] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5487] DBG:core:forward_reply: found module tm, passing reply to it Mar 27 12:36:45 [5487] DBG:tm:t_check: start=0xffffffffffffffff Mar 27 12:36:45 [5487] DBG:core:parse_headers: flags=22 Mar 27 12:36:45 [5487] DBG:core:parse_via_param: found param type 234, <received> = <172.16.17.85>; state=6 Mar 27 12:36:45 [5487] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-863b295f961d253f-1---d8754z->; state=6 Mar 27 12:36:45 [5487] DBG:core:parse_via_param: found param type 235, <rport> = <1301>; state=16 Mar 27 12:36:45 [5487] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5487] DBG:core:parse_headers: via found, flags=22 Mar 27 12:36:45 [5487] DBG:core:parse_headers: parse_headers: this is the second via Mar 27 12:36:45 [5487] DBG:core:parse_to: end of header reached, state=10 Mar 27 12:36:45 [5487] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5487] DBG:core:get_hdr_field: <To> [31]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5487] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091> ] Mar 27 12:36:45 [5487] DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE> Mar 27 12:36:45 [5487] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5487] DBG:tm:t_reply_matching: hash 44317 label 934934177 branch 0 Mar 27 12:36:45 [5487] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1 Mar 27 12:36:45 [5487] DBG:tm:t_reply_matching: reply matched (T=0x7fd335eee6b0)! Mar 27 12:36:45 [5487] DBG:tm:t_check: end=0x7fd335eee6b0 Mar 27 12:36:45 [5487] DBG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) Mar 27 12:36:45 [5487] DBG:tm:t_should_relay_response: T_code=100, new_code=100 Mar 27 12:36:45 [5487] DBG:tm:relay_reply: branch=0, save=0, relay=-1 Mar 27 12:36:45 [5487] DBG:tm:set_timer: relative timeout is 120 Mar 27 12:36:45 [5487] DBG:tm:insert_timer_unsafe: [1]: 0x7fd335eee900 (173) Mar 27 12:36:45 [5487] DBG:tm:t_unref: UNREF_UNSAFE: after is 0 Mar 27 12:36:45 [5487] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5487] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5489] DBG:core:parse_msg: SIP Request: Mar 27 12:36:45 [5489] DBG:core:parse_msg: method: <INVITE> Mar 27 12:36:45 [5489] DBG:core:parse_msg: uri: <sip:1002@172.16.16.218:5090> Mar 27 12:36:45 [5489] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5489] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5489] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK7f71d414>; state=6 Mar 27 12:36:45 [5489] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 Mar 27 12:36:45 [5489] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5489] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5489] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5489] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5489] DBG:core:receive_msg: preparing to run routing scripts... Mar 27 12:36:45 [5489] DBG:core:parse_headers: flags=100 Mar 27 12:36:45 [5489] DBG:core:parse_to: end of header reached, state=10 Mar 27 12:36:45 [5489] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5090} Mar 27 12:36:45 [5489] DBG:core:get_hdr_field: <To> [31]; uri=[sip:1002@172.16.16.218:5090] Mar 27 12:36:45 [5489] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5090> ] Mar 27 12:36:45 [5489] DBG:core:get_hdr_field: cseq <CSeq>: <102> <INVITE> Mar 27 12:36:45 [5489] DBG:maxfwd:is_maxfwd_present: value = 70 ---- From SC/MS/IC ---- Mar 27 12:36:45 [5489] DBG:core:rewrite_uri: rewriting Request-URI with 'sip:1002@172.16.17.85:25923;rinstance=133b23266b1f2e83;transport=TLS' Mar 27 12:36:45 [5489] DBG:core:mk_proxy: doing DNS lookup... Mar 27 12:36:45 [5489] DBG:core:parse_headers: flags=2000 Mar 27 12:36:45 [5489] DBG:core:get_hdr_field: content_length=394 Mar 27 12:36:45 [5489] DBG:core:forward_request: sending: INVITE sip:1002@172.16.17.85:25923;rinstance=133b23266b1f2e83;transport=TLS SIP/2.0 Record-Route: <sip:172.16.16.218:5091;transport=tls;r2=on;lr=on> Record-Route: <sip:172.16.16.218:5090;r2=on;lr=on> Via: SIP/2.0/TLS 172.16.16.218:5091;branch=z9hG4bK7f71d414 Via: SIP/2.0/UDP 172.16.16.218:5070;received=172.16.16.218;branch=z9hG4bK7f71d414;rport=5070 From: "1003" <sip:1003@172.16.16.218:5070>;tag=as7351a581 To: <sip:1002@172.16.16.218:5090> Contact: <sip:1003@172.16.16.218:5070> Call-ID: 7c10eaf0305d3dff6dac07db404d5a60(a)172.16.16.218 CSeq: 102 INVITE User-Agent: PANTHER-SC Max-Forwards: 69 Date: Sat, 27 Mar 2010 07:06:45 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 394 v=0 o=root 2434 2434 IN IP4 172.16.17.85 s=session c=IN IP4 172.16.17.85 t=0 0 m=audio 54168 RTP/SAVP 0 18 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv AES_CM_128_HMAC_SHA1_80 inline:qGi2zArgAgHDiUoqc0wbBofpBISpZINZxrqDoa7W . Mar 27 12:36:45 [5489] DBG:core:forward_request: orig. len=935, new_len=1182, proto=3 Mar 27 12:36:45 [5489] DBG:core:tcp_send: no open tcp connection found, opening new one Mar 27 12:36:45 [5489] DBG:core:print_ip: tcpconn_new: new tcp connection to: 172.16.17.85 Mar 27 12:36:45 [5489] DBG:core:tcpconn_new: on port 25923, type 3 Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: entered: Creating a whole new ssl connection Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: name based TLS client domains are disabled Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: no TLS client domain AVP set, looking for socket based TLS client domain Mar 27 12:36:45 [5489] DBG:core:tls_find_client_domain: virtual TLS client domain not found, Using default TLS client domain settings Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: found socket based TLS client domain [0.0.0.0:0] Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: Setting in CONNECT mode (client) Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: TLS server extension is not activated Mar 27 12:36:45 [5489] DBG:core:tls_tcpconn_init: TLS server name is not set, sending ClientHello without server_name Mar 27 12:36:45 [5489] DBG:core:tcp_send: sending... Mar 27 12:36:45 [5489] DBG:core:tls_update_fd: New fd is 12 Mar 27 12:36:45 [5499] DBG:core:handle_ser_child: read response= 7fd335f23098, 2, fd 25 from 4 (5489) Mar 27 12:36:45 [5499] DBG:core:tcpconn_add: hashes: 495, 4 Mar 27 12:36:45 [5499] DBG:core:io_watch_add: io_watch_add(0x74ee80, 25, 2, 0x7fd335f23098), fd_no=17 Mar 27 12:36:45 [5499] DBG:core:handle_tcpconn_ev: data available on 0x7fd335f23098 25 Mar 27 12:36:45 [5489] ERROR:core:tls_connect: SSL_ERROR_SYSCALL err=Connection reset by peer(104) Mar 27 12:36:45 [5499] DBG:core:io_watch_del: io_watch_del (0x74ee80, 25, -1, 0x0) fd_no=18 called Mar 27 12:36:45 [5489] ERROR:core:tls_connect: something wrong in SSL: 5 (ret=-1) err=Connection reset by peer(104) Mar 27 12:36:45 [5499] DBG:core:send2child: to tcp child 1 0(5494), 0x7fd335f23098 Mar 27 12:36:45 [5489] DBG:core:tcp_send: after write: c= 0x7fd335f23098 n=-1 fd=12 Mar 27 12:36:45 [5489] DBG:core:tcp_send: buf= INVITE sip:1002@172.16.17.85:25923;rinstance=133b23266b1f2e83;transport=TLS SIP/2.0 Record-Route: <sip:172.16.16.218:5091;transport=tls;r2=on;lr=on> Record-Route: <sip:172.16.16.218:5090;r2=on;lr=on> Via: SIP/2.0/TLS 172.16.16.218:5091;branch=z9hG4bK7f71d414 Via: SIP/2.0/UDP 172.16.16.218:5070;received=172.16.16.218;branch=z9hG4bK7f71d414;rport=5070 From: "1003" <sip:1003@172.16.16.218:5070>;tag=as7351a581 To: <sip:1002@172.16.16.218:5090> Contact: <sip:1003@172.16.16.218:5070> Call-ID: 7c10eaf0305d3dff6dac07db404d5a60(a)172.16.16.218 CSeq: 102 INVITE User-Agent: PANTHER-SC Max-Forwards: 69 Date: Sat, 27 Mar 2010 07:06:45 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 394 v=0 o=root 2434 2434 IN IP4 172.16.17.85 s=session c=IN IP4 172.16.17.85 t=0 0 m=audio 54168 RTP/SAVP 0 18 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv AES_CM_128_HMAC_SHA1_80 inline:qGi2zArgAgHDiUoqc0wbBofpBISpZINZxrqDoa7W Mar 27 12:36:45 [5494] DBG:core:handle_io: received n=8 con=0x7fd335f23098, fd=20 Mar 27 12:36:45 [5489] ERROR:core:tcp_send: failed to send Mar 27 12:36:45 [5494] DBG:core:io_watch_add: io_watch_add(0x74efe0, 20, 2, 0x7fd335f23098), fd_no=1 Mar 27 12:36:45 [5489] ERROR:core:msg_send: tcp_send failed Mar 27 12:36:45 [5494] DBG:core:io_watch_del: io_watch_del (0x74efe0, 20, -1, 0x10) fd_no=2 called Mar 27 12:36:45 [5494] DBG:core:release_tcpconn: releasing con 0x7fd335f23098, state -2, fd=20, id=4 Mar 27 12:36:45 [5494] DBG:core:release_tcpconn: extra_data 0x7fd335f00ef8 Mar 27 12:36:45 [5489] DBG:sl:sl_reply_error: error text is Send failed (477/SL) Mar 27 12:36:45 [5499] DBG:core:handle_tcp_child: reader response= 7fd335f23098, -2 from 1 Mar 27 12:36:45 [5499] DBG:core:tcpconn_destroy: delaying (0x7fd335f23098, flags 0002) ... Mar 27 12:36:45 [5489] DBG:core:parse_headers: flags=ffffffffffffffff Mar 27 12:36:45 [5489] DBG:core:get_hdr_field: found end of header Mar 27 12:36:45 [5499] DBG:core:handle_ser_child: read response= 7fd335f23098, -2, fd -1 from 4 (5489) Mar 27 12:36:45 [5499] DBG:core:tcpconn_destroy: destroying connection 0x7fd335f23098, flags 0002 Mar 27 12:36:45 [5489] DBG:core:check_via_address: params 172.16.16.218, 172.16.16.218, 0 Mar 27 12:36:45 [5499] DBG:core:tls_close: closing SSL connection Mar 27 12:36:45 [5499] DBG:core:tls_update_fd: New fd is 25 Mar 27 12:36:45 [5499] DBG:core:tls_shutdown: shutdown successful Mar 27 12:36:45 [5499] DBG:core:tls_tcpconn_clean: Cleanup function entered Mar 27 12:36:45 [5486] DBG:core:parse_msg: SIP Request: Mar 27 12:36:45 [5486] DBG:core:parse_msg: method: <ACK> Mar 27 12:36:45 [5486] DBG:core:parse_msg: uri: <sip:1002@172.16.16.218:5090> Mar 27 12:36:45 [5486] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5486] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5486] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK7f71d414>; state=6 Mar 27 12:36:45 [5486] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 Mar 27 12:36:45 [5486] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5486] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5486] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5486] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5486] DBG:core:receive_msg: preparing to run routing scripts... Mar 27 12:36:45 [5486] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5486] DBG:core:parse_to_param: tag=2cf7f9a22b6374f465182a893bba7dec.adb6 Mar 27 12:36:45 [5486] DBG:core:parse_to: end of header reached, state=29 Mar 27 12:36:45 [5486] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5090} Mar 27 12:36:45 [5486] DBG:core:get_hdr_field: <To> [73]; uri=[sip:1002@172.16.16.218:5090] Mar 27 12:36:45 [5486] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5090>] Mar 27 12:36:45 [5486] DBG:sl:sl_filter_ACK: local ACK found -> dropping it! Mar 27 12:36:45 [5486] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5486] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5489] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5489] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5485] DBG:core:parse_msg: SIP Reply (status): Mar 27 12:36:45 [5485] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5485] DBG:core:parse_msg: status: <404> Mar 27 12:36:45 [5485] DBG:core:parse_msg: reason: <Not Found> Mar 27 12:36:45 [5485] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd1da.1a6f9b73.0>; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 236, <i> = <1>; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 234, <received> = <172.16.16.218>; state=16 Mar 27 12:36:45 [5485] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5485] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5485] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5485] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5485] DBG:core:forward_reply: found module tm, passing reply to it Mar 27 12:36:45 [5485] DBG:tm:t_check: start=0xffffffffffffffff Mar 27 12:36:45 [5485] DBG:core:parse_headers: flags=22 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 234, <received> = <172.16.17.85>; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-863b295f961d253f-1---d8754z->; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 235, <rport> = <1301>; state=16 Mar 27 12:36:45 [5485] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5485] DBG:core:parse_headers: via found, flags=22 Mar 27 12:36:45 [5485] DBG:core:parse_headers: parse_headers: this is the second via Mar 27 12:36:45 [5485] DBG:core:parse_to_param: tag=as06cb485b Mar 27 12:36:45 [5485] DBG:core:parse_to: end of header reached, state=29 Mar 27 12:36:45 [5485] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: <To> [46]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091>] Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE> Mar 27 12:36:45 [5485] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5485] DBG:tm:t_reply_matching: hash 44317 label 934934177 branch 0 Mar 27 12:36:45 [5485] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1 Mar 27 12:36:45 [5485] DBG:tm:t_reply_matching: reply matched (T=0x7fd335eee6b0)! Mar 27 12:36:45 [5485] DBG:tm:t_check: end=0x7fd335eee6b0 Mar 27 12:36:45 [5485] DBG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1) Mar 27 12:36:45 [5485] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5485] DBG:tm:build_local: using FROM=<From: "1003"<sip:1003@172.16.16.218:5091>;tag=9f574228 >, TO=<To: <sip:1002@172.16.16.218:5091>;tag=as06cb485b >, CSEQ_N=<CSeq: 2> Mar 27 12:36:45 [5485] DBG:tm:extract_parsed_hdrs: ----parsing the buf req - first line Mar 27 12:36:45 [5485] DBG:core:parse_headers: flags=ffffffffffffffff Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd1da.1a6f9b73.0>; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 236, <i> = <1>; state=16 Mar 27 12:36:45 [5485] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5485] DBG:core:parse_headers: via found, flags=ffffffffffffffff Mar 27 12:36:45 [5485] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 234, <received> = <172.16.17.85>; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-863b295f961d253f-1---d8754z->; state=6 Mar 27 12:36:45 [5485] DBG:core:parse_via_param: found param type 235, <rport> = <1301>; state=16 Mar 27 12:36:45 [5485] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5485] DBG:core:parse_headers: via found, flags=ffffffffffffffff Mar 27 12:36:45 [5485] DBG:core:parse_headers: parse_headers: this is the second via Mar 27 12:36:45 [5485] DBG:core:parse_to: end of header reached, state=10 Mar 27 12:36:45 [5485] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: <To> [31]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091> ] Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE> Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: content_length=512 Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: found end of header Mar 27 12:36:45 [5485] DBG:tm:t_should_relay_response: T_code=100, new_code=404 Mar 27 12:36:45 [5485] DBG:tm:t_pick_branch: picked branch 0, code 404 Mar 27 12:36:45 [5485] DBG:tm:is_3263_failure: dns-failover test: branch=0, last_recv=404, flags=2 Mar 27 12:36:45 [5485] WARNING:core:run_actions: null action list (rec_level=1) Mar 27 12:36:45 [5485] DBG:tm:relay_reply: branch=0, save=0, relay=0 Mar 27 12:36:45 [5485] DBG:core:parse_headers: flags=2000 Mar 27 12:36:45 [5485] DBG:core:get_hdr_field: content_length=0 Mar 27 12:36:45 [5485] DBG:core:build_res_buf_from_sip_res: old size: 548, new size: 454 Mar 27 12:36:45 [5485] DBG:core:build_res_buf_from_sip_res: copied size: orig:117, new: 23, rest: 431 msg= SIP/2.0 404 Not Found Via: SIP/2.0/TLS 172.16.17.85:4403;received=172.16.17.85;branch=z9hG4bK-d8754z-863b295f961d253f-1---d8754z-;rport=1301 From: "1003"<sip:1003@172.16.16.218:5091>;tag=9f574228 To: <sip:1002@172.16.16.218:5091>;tag=as06cb485b Call-ID: M2Y2OThmYmYwZjM4ODhhYzk4Mjc0MGFhMDQyNDUzZWU. CSeq: 2 INVITE User-Agent: PANTHER-SC Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 Mar 27 12:36:45 [5485] DBG:tm:set_timer: relative timeout is 30 Mar 27 12:36:45 [5485] DBG:tm:insert_timer_unsafe: [0]: 0x7fd335eee828 (83) Mar 27 12:36:45 [5485] DBG:core:tcp_send: tcp connection found (0x7fd335eddc18), acquiring fd Mar 27 12:36:45 [5485] DBG:core:tcp_send: c= 0x7fd335eddc18, n=16 Mar 27 12:36:45 [5499] DBG:core:handle_ser_child: read response= 7fd335eddc18, 1, fd -1 from 1 (5485) Mar 27 12:36:45 [5485] DBG:core:tcp_send: after receive_fd: c= 0x7fd335eddc18 n=8 fd=9 Mar 27 12:36:45 [5485] DBG:core:tcp_send: sending... Mar 27 12:36:45 [5485] DBG:core:tls_update_fd: New fd is 9 Mar 27 12:36:45 [5485] DBG:core:tls_write: write was successful (454 bytes) Mar 27 12:36:45 [5485] DBG:core:tcp_send: after write: c= 0x7fd335eddc18 n=454 fd=9 Mar 27 12:36:45 [5485] DBG:core:tcp_send: buf= SIP/2.0 404 Not Found Via: SIP/2.0/TLS 172.16.17.85:4403;received=172.16.17.85;branch=z9hG4bK-d8754z-863b295f961d253f-1---d8754z-;rport=1301 From: "1003"<sip:1003@172.16.16.218:5091>;tag=9f574228 To: <sip:1002@172.16.16.218:5091>;tag=as06cb485b Call-ID: M2Y2OThmYmYwZjM4ODhhYzk4Mjc0MGFhMDQyNDUzZWU. CSeq: 2 INVITE User-Agent: PANTHER-SC Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 Mar 27 12:36:45 [5485] DBG:tm:relay_reply: sent buf=0x7916f0: SIP/2.0 4..., shmem=0x7fd335f007a8: SIP/2.0 4 Mar 27 12:36:45 [5485] DBG:tm:cleanup_uac_timers: RETR/FR timers reset Mar 27 12:36:45 [5485] DBG:tm:t_unref: UNREF_UNSAFE: after is 0 Mar 27 12:36:45 [5485] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5485] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 18 Mar 27 12:36:45 [5492] DBG:core:_tls_read: 343 bytes read Mar 27 12:36:45 [5492] DBG:core:tcp_read_req: content-length= 0 Mar 27 12:36:45 [5492] DBG:core:parse_msg: SIP Request: Mar 27 12:36:45 [5492] DBG:core:parse_msg: method: <ACK> Mar 27 12:36:45 [5492] DBG:core:parse_msg: uri: <sip:1002@172.16.16.218:5091;transport=tls> Mar 27 12:36:45 [5492] DBG:core:parse_msg: version: <SIP/2.0> Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-d8754z-863b295f961d253f-1---d8754z->; state=6 Mar 27 12:36:45 [5492] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17 Mar 27 12:36:45 [5492] DBG:core:parse_via: end of header reached, state=5 Mar 27 12:36:45 [5492] DBG:core:parse_headers: via found, flags=2 Mar 27 12:36:45 [5492] DBG:core:parse_headers: this is the first via Mar 27 12:36:45 [5492] DBG:core:receive_msg: After parse_msg... Mar 27 12:36:45 [5492] DBG:core:receive_msg: preparing to run routing scripts... Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=8 Mar 27 12:36:45 [5492] DBG:core:parse_to_param: tag=as06cb485b Mar 27 12:36:45 [5492] DBG:core:parse_to: end of header reached, state=29 Mar 27 12:36:45 [5492] DBG:core:parse_to: display={}, ruri={sip:1002@172.16.16.218:5091} Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: <To> [46]; uri=[sip:1002@172.16.16.218:5091] Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: to body [<sip:1002@172.16.16.218:5091>] Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=100 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: cseq <CSeq>: <2> <ACK> Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: content_length=0 Mar 27 12:36:45 [5492] DBG:core:get_hdr_field: found end of header Mar 27 12:36:45 [5492] DBG:maxfwd:is_maxfwd_present: max_forwards header not found! Mar 27 12:36:45 [5492] DBG:siputils:has_totag: totag found Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=200 Mar 27 12:36:45 [5492] DBG:rr:find_first_route: No Route headers found Mar 27 12:36:45 [5492] DBG:rr:loose_route: There is no Route HF Mar 27 12:36:45 [5492] DBG:core:parse_headers: flags=78 Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: start searching: hash=44317, isACK=1 Mar 27 12:36:45 [5492] DBG:tm:matching_3261: RFC3261 transaction matched, tid=-d8754z-863b295f961d253f-1---d8754z- Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1 Mar 27 12:36:45 [5492] DBG:tm:t_lookup_request: transaction found (T=0x7fd335eee6b0) Mar 27 12:36:45 [5492] DBG:tm:cleanup_uac_timers: RETR/FR timers reset Mar 27 12:36:45 [5492] DBG:tm:insert_timer_unsafe: [2]: 0x7fd335eee730 (58) Mar 27 12:36:45 [5492] DBG:tm:t_unref: UNREF_UNSAFE: after is 0 Mar 27 12:36:45 [5492] DBG:core:destroy_avp_list: destroying list (nil) Mar 27 12:36:45 [5492] DBG:core:receive_msg: cleaning up Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 18 Mar 27 12:36:45 [5492] DBG:core:_tls_read: 4 bytes read Mar 27 12:36:45 [5492] DBG:core:tcp_read_req: content-length= 0 Mar 27 12:36:45 [5492] DBG:core:tcp_send: tcp connection found (0x7fd335eddc18), acquiring fd Mar 27 12:36:45 [5492] DBG:core:tcp_send: c= 0x7fd335eddc18, n=16 Mar 27 12:36:45 [5499] DBG:core:handle_ser_child: read response= 7fd335eddc18, 1, fd -1 from 7 (5492) Mar 27 12:36:45 [5492] DBG:core:tcp_send: after receive_fd: c= 0x7fd335eddc18 n=8 fd=19 Mar 27 12:36:45 [5492] DBG:core:tcp_send: sending... Mar 27 12:36:45 [5492] DBG:core:tls_update_fd: New fd is 19 Mar 27 12:36:45 [5492] DBG:core:tls_write: write was successful (2 bytes) Mar 27 12:36:45 [5492] DBG:core:tcp_send: after write: c= 0x7fd335eddc18 n=2 fd=19 Mar 27 12:36:45 [5492] DBG:core:tcp_send: buf= one more thing, i have got two clients from one PC, still look at netstat result hemanshu@localhost user]$ netstat -antp | grep kamailio (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) tcp 0 0 172.16.16.218:5091 0.0.0.0:* LISTEN 4947/kamailio tcp 0 0 172.16.16.218:5092 0.0.0.0:* LISTEN 4947/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1295 ESTABLISHED 4964/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1296 ESTABLISHED 4964/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1289 ESTABLISHED 4964/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1293 ESTABLISHED 4964/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1291 ESTABLISHED 4964/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1286 ESTABLISHED 4964/kamailio tcp 0 0 172.16.16.218:5091 172.16.17.85:1285 ESTABLISHED 4964/kamailio Both clients keep creating new connection, and not reusing the already connected connection. i this this si the problem ---- Regards, Hemanshu Patel Sr. Software Engg Mo:09601295238 On Sat 27/03/10 11:37 AM , Hemanshu Patel <hemanshu.patel(a)saicare.com> wrote: > With TLS it still is not working > Mar 27 11:39:16 [4421] INFO:core:probe_max_receive_buffer: using a > UDP receive buffer of 255 kb > Mar 27 11:39:16 [4425] WARNING:usrloc:dbrow2info: non-local socket > ...ignoring > Mar 27 11:39:18 [4431] INFO:core:tls_accept: client did not present > a certificate > Mar 27 11:39:55 [4432] INFO:core:tls_accept: client did not present > a certificate > Mar 27 11:40:01 [4431] ERROR:rr:w_record_route: Double attempt to > record-route > Mar 27 11:40:01 [4426] ERROR:core:tls_connect: SSL_ERROR_SYSCALL > err=Connection reset by peer(104) > Mar 27 11:40:01 [4426] ERROR:core:tls_connect: something wrong in > SSL: 5 (ret=-1) err=Connection reset by peer(104) > Mar 27 11:40:01 [4426] ERROR:core:tcp_send: failed to send > Mar 27 11:40:01 [4426] ERROR:core:msg_send: tcp_send failed > Mar 27 11:40:01 [4425] WARNING:core:run_actions: null action list > (rec_level=1) > my doubt is that if somethings wrong with SSL certificates that i > created myself (i.e my own root CA, and self signed certificates), > then how come registration is working like charm? > if there is some problem with Certificates then registration should > also not work. > am i right? > ---- > Regards, > Hemanshu Patel > Sr. Software Engg > SIS,Ahmedabad > Mo:09601295238 > On Sat 27/03/10 9:50 AM , "Hemanshu Patel" wrote: > > I havent tested over TCP, let me check it > > but hardphone, i mean hardware based phones from grandstream > gvx3140 > > works > > fine with same implementation on TLS. > > -- > > Regards, > > Hemanshu Patel > > M: 09601295238 > > > Does eyebeam with SIP over TCP is working? > > > > > > Am 26.03.2010 13:43, schrieb Hemanshu Patel: > > >> > > >> i am still having this problem. > > >> when i use two grandstream phone everything works fine, > > >> i can make calls on TLS and users can talk to each other. > > >> > > >> But when i use two eyebream phone, it doesnt work, gives > > following error > > >> > > >> :33 [2875] WARNING:core:init_ssl_ctx_behavior: server > > verification NOT > > >> activated. Weaker security. > > >> [ panreg-tls]$ > > >> [ panreg-tls]$ > > >> [ panreg-tls]$ Mar 26 18:11:59 [2889] > > >> ERROR:rr:w_record_route: Double attempt to record-route > > >> Mar 26 18:12:09 [2884] ERROR:core:tcp_blocking_connect: timeout > > 10 s > > >> elapsed from 10 s > > >> Mar 26 18:12:09 [2884] ERROR:core:tcpconn_connect: > > tcp_blocking_connect > > >> failed > > >> Mar 26 18:12:09 [2884] ERROR:core:tcp_send: connect failed > > >> Mar 26 18:12:09 [2884] ERROR:core:msg_send: tcp_send failed > > >> Mar 26 18:12:10 [2883] ERROR:core:tcp_blocking_connect: timeout > > 10 s > > >> elapsed from 10 s > > >> Mar 26 18:12:10 [2883] ERROR:core:tcpconn_connect: > > tcp_blocking_connect > > >> failed > > >> Mar 26 18:12:10 [2883] ERROR:core:tcp_send: connect failed > > >> Mar 26 18:12:10 [2883] ERROR:core:msg_send: tcp_send failed > > >> Mar 26 18:12:10 [2883] WARNING:core:run_actions: null action > list > > >> (rec_level=1) > > >> Mar 26 18:12:11 [2881] ERROR:core:tcp_blocking_connect: timeout > > 10 s > > >> elapsed from 10 s > > >> Mar 26 18:12:11 [2881] ERROR:core:tcpconn_connect: > > tcp_blocking_connect > > >> failed > > >> Mar 26 18:12:11 [2881] ERROR:core:tcp_send: connect failed > > >> Mar 26 18:12:11 [2881] ERROR:core:msg_send: tcp_send failed > > >> Mar 26 18:12:13 [2882] ERROR:core:tcp_blocking_connect: timeout > > 10 s > > >> elapsed from 10 s > > >> Mar 26 18:12:13 [2882] ERROR:core:tcpconn_connect: > > tcp_blocking_connect > > >> failed > > >> Mar 26 18:12:13 [2882] ERROR:core:tcp_send: connect failed > > >> Mar 26 18:12:13 [2882] ERROR:core:msg_send: tcp_send failed > > >> Mar 26 18:12:19 [2884] ERROR:core:tcp_blocking_connect: timeout > > 10 s > > >> elapsed from 10 s > > >> Mar 26 18:12:19 [2884] ERROR:core:tcpconn_connect: > > tcp_blocking_connect > > >> failed > > >> Mar 26 18:12:19 [2884] ERROR:core:tcp_send: connect failed > > >> Mar 26 18:12:19 [2884] ERROR:core:msg_send: tcp_send failed > > >> > > >> > > >> > > >> Any idea? Same configuration works with grandstream, while they > > cant in > > >> softphone? and gives 477 errot code. > > >> > > >> my asterisk log is as below: > > >> > > >> 26 18:08:09] WARNING[2833]: chan_sip.c:1648 setup_crypto: > > Hemanshu: > > >> local_key641 jhbAJ7jFE1p/Ngn4kVxy7qTTmkJpeBiN6W98+gmM len 40 > > >> -- Called kamailio/1003 > > >> -- Got SIP response 477 "Send failed (477/SL)" back from > > >> 172.16.16.218 > > >> -- No one is available to answer at this time (1:0/0/0) > > >> -- Executing [_default:4] Hangup("SIP/5091-8c001430", "") > > >> in > > >> new stack > > >> == Spawn extension (hemu_default, 1003, 4) exited non-zero > on > > >> 'SIP/5091-8c001430' > > >> > ::Disconnected form Oracle, trying to connect > again.. > > >> > ::Tried a lot, not getting connected.. > > >> -- Got SIP response 477 "Send failed (477/SL)" back from > > >> 172.16.16.218 > > >> > > >> > > >> Any idea what could be the problem? > > >> > > > > > _______________________________________________ > > Kamailio (OpenSER) - Users mailing list > > http://lists.kamailio.org/cgi-bin/mailman/listinfo/users > > http://lists.openser-project.org/cgi-bin/mailman/listinfo/users > > > > > ---- SIS Blade Server, Desktop & Thin Client is now available on DGS > & D rate contract. For more detail kindly visit our website > http://www.saicare.com > > ---- SIS Blade Server, Desktop & Thin Client is now available on DGS & D rate contract. For more detail kindly visit our website http://www.saicare.com

2 1

INVITE timers
by Alex Hermann 27 Mar '10

27 Mar '10

Hello, I'm trying to create a scenarion which was very simple with Kamailio 1.x, but seems impossible with sr3.0. I need to do failover for INVITE's and also limit the call setup time per-branch, so I defined the problem in 2 parts that need to work separately, but also combined into 1 proxy. 1) Fast failover. After t_relay, the destination should be tried for max 2 sec per host. No maximum for the whole set. Thus, if a destination has 4 SRV records, and each host fails after 2 secs, a 408 will be sent back after a total of 8 secs. If a (proivisional) response arrives within 2 sec, a 408 MUST NOT be sent. The exact value of the timer should be configurable per t_relay call. In kamailio this is accomplished by setting the fr_timer(_avp) to 2000ms. In sr3.0 I have yet to find a combination of timer settings that work. 2) Call setup duration. If a destination host returns a response, I want to limit the attempt to 80 secs (default, should be configurable per t_relay call) of ringing/progress/whatever. After that a failure route will take care to route to a different destination, at this time this timer should be restarted. At no other time after the _first_ provisional reponse after the t_relay call should the timer be restarted. In Kamailio this was accomplished by just setting fr_inv_timer(_avp) to the desired value before t_relay(). In sr3.0 this timer will be restarted after additional provisional responses and will not be resetted after a new t_relay call (from failure_route). Any suggestions on how to get the desired behaviours are welcomed (at the moment scenario 1 is more important than 2). -- Greetings, Alex Hermann

3 6

Re: [Kamailio-Users] Problem with secure TLS call
by Hemanshu Patel 27 Mar '10

27 Mar '10

Yups, it works fine with TCP. All packets are forwarded to other party perfectly and everything work smooth. only with TLS, on softphone it doesnt work. any more suggestions ---- Regards, Hemanshu Patel Sr. Software Engg SIS,Ahmedabad Mo:09601295238 On Sat 27/03/10 9:50 AM , "Hemanshu Patel" <hemanshu.patel(a)saicare.com> wrote: > I havent tested over TCP, let me check it > but hardphone, i mean hardware based phones from grandstream gvx3140 > works > fine with same implementation on TLS. > -- > Regards, > Hemanshu Patel > M: 09601295238 > > Does eyebeam with SIP over TCP is working? > > > > Am 26.03.2010 13:43, schrieb Hemanshu Patel: > >> > >> i am still having this problem. > >> when i use two grandstream phone everything works fine, > >> i can make calls on TLS and users can talk to each other. > >> > >> But when i use two eyebream phone, it doesnt work, gives > following error > >> > >> :33 [2875] WARNING:core:init_ssl_ctx_behavior: server > verification NOT > >> activated. Weaker security. > >> [ panreg-tls]$ > >> [ panreg-tls]$ > >> [ panreg-tls]$ Mar 26 18:11:59 [2889] > >> ERROR:rr:w_record_route: Double attempt to record-route > >> Mar 26 18:12:09 [2884] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:09 [2884] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:09 [2884] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:09 [2884] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:10 [2883] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:10 [2883] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:10 [2883] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:10 [2883] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:10 [2883] WARNING:core:run_actions: null action list > >> (rec_level=1) > >> Mar 26 18:12:11 [2881] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:11 [2881] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:11 [2881] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:11 [2881] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:13 [2882] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:13 [2882] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:13 [2882] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:13 [2882] ERROR:core:msg_send: tcp_send failed > >> Mar 26 18:12:19 [2884] ERROR:core:tcp_blocking_connect: timeout > 10 s > >> elapsed from 10 s > >> Mar 26 18:12:19 [2884] ERROR:core:tcpconn_connect: > tcp_blocking_connect > >> failed > >> Mar 26 18:12:19 [2884] ERROR:core:tcp_send: connect failed > >> Mar 26 18:12:19 [2884] ERROR:core:msg_send: tcp_send failed > >> > >> > >> > >> Any idea? Same configuration works with grandstream, while they > cant in > >> softphone? and gives 477 errot code. > >> > >> my asterisk log is as below: > >> > >> 26 18:08:09] WARNING[2833]: chan_sip.c:1648 setup_crypto: > Hemanshu: > >> local_key641 jhbAJ7jFE1p/Ngn4kVxy7qTTmkJpeBiN6W98+gmM len 40 > >> -- Called kamailio/1003 > >> -- Got SIP response 477 "Send failed (477/SL)" back from > >> 172.16.16.218 > >> -- No one is available to answer at this time (1:0/0/0) > >> -- Executing [_default:4] Hangup("SIP/5091-8c001430", "") > >> in > >> new stack > >> == Spawn extension (hemu_default, 1003, 4) exited non-zero on > >> 'SIP/5091-8c001430' > >> > ::Disconnected form Oracle, trying to connect again.. > >> > ::Tried a lot, not getting connected.. > >> -- Got SIP response 477 "Send failed (477/SL)" back from > >> 172.16.16.218 > >> > >> > >> Any idea what could be the problem? > >> > > > _______________________________________________ > Kamailio (OpenSER) - Users mailing list > http://lists.kamailio.org/cgi-bin/mailman/listinfo/users > http://lists.openser-project.org/cgi-bin/mailman/listinfo/users > > ---- SIS Blade Server, Desktop & Thin Client is now available on DGS & D rate contract. For more detail kindly visit our website http://www.saicare.com

1 0

[Kamailio-Users] Problem with secure TLS call
by Detlef Pilzecker 27 Mar '10

27 Mar '10

Hi, I am using kamailio 3.0.1 (x86_64/linux) 0822a9 flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. and I am using the client "PhonerLite" (http://www.phonerlite.de). The phone is registered on my server with TLS. If I call someone or myself I get an error message. What is wrong with my server? (TLS calls with PhonerLite with the provider antisip.com are possible without problems!) With UDP calling myself I get "486:Busy Here" on the phone, this is OK and normal. With TLS I get "477:Unfortunately error on sending to next hop occurred(477/SL)" on the phone and some ERROR messages like the following on the kamailio.log (you can see the rest of the log in the attached zip): Mar 21 20:24:00 vs208140 /usr/local/sbin/kamailio[20013]: DEBUG: <core> [msg_translator.c:200]: check_via_address(95.90.205.74, 95.90.205.74, 0) Mar 21 20:24:00 vs208140 /usr/local/sbin/kamailio[20013]: DEBUG: <core> [tcp_main.c:1786]: tcp_send: no open tcp connection found, opening new one Mar 21 20:24:10 vs208140 /usr/local/sbin/kamailio[20013]: ERROR: <core> [tcp_main.c:618]: connect 95.90.205.74:5061 failed (timeout) Mar 21 20:24:10 vs208140 /usr/local/sbin/kamailio[20013]: ERROR: <core> [tcp_main.c:621]: ERROR: tcp_blocking_connect 95.90.205.74:5061: timeout 10 s elapsed from 10 s Mar 21 20:24:10 vs208140 /usr/local/sbin/kamailio[20013]: ERROR: <core> [tcp_main.c:1168]: ERROR: tcp_do_connect: tcp_blocking_connect 95.90.205.74:5061 failed Mar 21 20:24:10 vs208140 /usr/local/sbin/kamailio[20013]: ERROR: <core> [tcp_main.c:1237]: ERROR: tcp_do_connect 95.90.205.74:5061: failed (115) Operation now in progress Mar 21 20:24:10 vs208140 /usr/local/sbin/kamailio[20013]: ERROR: <core> [tcp_main.c:1955]: ERROR: tcp_send 95.90.205.74:5061: connect failed Mar 21 20:24:10 vs208140 /usr/local/sbin/kamailio[20013]: ERROR: tm [../../forward.h:191]: msg_send: ERROR: tcp_send failed The kamailio.cfg file is also in the zip attached. The PC is connected with the router (I opened the TCP ports 5060-5062) that is connected to the Internet. The problem also happens if I disable the firewall of the server and of the PC. Can someone give me help? Thanks in advance! Regards Detlef Pilzecker

3 8

← Newer
1
2
3
4
5
6
7
...
12
Older →

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

2005

2004

2003

2002

sr-users March 2010