sr-users

sr-users@lists.kamailio.org

19 participants
37571 discussions

[Kamailio-Users] acc doesn't write to database and to a log file
by Koffedor 13 Aug '09

13 Aug '09

Hello to all I enabled the acc module but it isn't writing to "acc" or "missed_calls" table in mysql, and to a log file too. my config: (...) loadmodule "db_mysql.so" loadmodule "tm.so" loadmodule "rr.so" (...) # ----- acc params ----- /* what sepcial events should be accounted ? */ modparam("acc", "early_media", 1) modparam("acc", "report_ack", 1) modparam("acc", "report_cancels", 1) /* by default ww do not adjust the direct of the sequential requests. if you enable this parameter, be sure the enable "append_fromtag" in "rr" module */ modparam("acc", "detect_direction", 0) /* account triggers (flags) */ modparam("acc", "failed_transaction_flag", 3) modparam("acc", "log_flag", 1) modparam("acc", "log_missed_flag", 2) modparam("acc", "log_extra","src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") /* uncomment the following lines to enable DB accounting also */ modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) modparam("acc", "db_url", "mysql://xxx:xxxx@localhost/kamailio") modparam("acc", "db_extra", "src_user=$fU;src_domain=$fd;dst_ouser=$tU;dst_user=$rU;dst_domain=$rd") Flags 1 and 2 set just like in a sample configuration file. (...) if (loose_route()) { if (is_method("BYE")) { setflag(1); # do accounting ... setflag(3); # ... even if the transaction fails } route(1); (...) # account only INVITEs if (is_method("INVITE")) { setflag(1); # do accounting } Mysql tables are created: | acc | CREATE TABLE `acc` ( `id` int(10) unsigned NOT NULL auto_increment, `method` varchar(16) NOT NULL default '', `from_tag` varchar(64) NOT NULL default '', `to_tag` varchar(64) NOT NULL default '', `callid` varchar(128) NOT NULL default '', `sip_code` char(3) NOT NULL default '', `sip_reason` varchar(32) NOT NULL default '', `time` datetime NOT NULL default '0000-00-00 00:00:00', `src_ip` varchar(64) NOT NULL default '', `dst_user` varchar(64) NOT NULL default '', `dst_domain` varchar(128) NOT NULL default '', `src_user` varchar(64) NOT NULL default '', `src_domain` varchar(128) NOT NULL default '', `cdr_id` int(11) NOT NULL default '0', `dst_ouser` varchar(64) NOT NULL default '', PRIMARY KEY (`id`), KEY `acc_callid` (`callid`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 | | missed_calls | CREATE TABLE `missed_calls` ( `id` int(10) unsigned NOT NULL auto_increment, `method` varchar(16) NOT NULL default '', `from_tag` varchar(64) NOT NULL default '', `to_tag` varchar(64) NOT NULL default '', `callid` varchar(128) NOT NULL default '', `sip_code` char(3) NOT NULL default '', `sip_reason` varchar(32) NOT NULL default '', `time` datetime NOT NULL default '0000-00-00 00:00:00', `src_ip` varchar(64) NOT NULL default '', `dst_user` varchar(64) NOT NULL default '', `dst_domain` varchar(128) NOT NULL default '', `src_user` varchar(64) NOT NULL default '', `src_domain` varchar(128) NOT NULL default '', `cdr_id` int(11) NOT NULL default '0', `dst_ouser` varchar(64) NOT NULL default '', PRIMARY KEY (`id`), KEY `mc_callid` (`callid`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 There are no errors in log, and nothing about acc module in debug mode. Cant get where is my mistake.

2 3

BUG: tls [tls_server.c:98]: Invalid connection state (bug in TCP code)
by MÉSZÁROS Mihály 12 Aug '09

12 Aug '09

Hello! Another problem I am using sip-router git version with the attached configuration files. I am getting the error mentioned in subject. Please see the debug log and my configuration files. Can anyone help me figure out what i a configured wrong? Misi Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 517 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <PUBLISH> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:alice@atlanta.test> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-260c1648321add52-1---d8754z->; state=6 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:127]: After parse_msg... Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:166]: preparing to run routing scripts... Aug 11 20:38:38 a1 /usr/sbin/ser[390]: ERROR: <script>: Misi: PUBLISH sip:alice@atlanta.test SIP/2.0#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-260c1648321add52-1---d8754z-;rport#015#012Max-Forwards: 70#015#012Contact: <sip:alice@92.249.143.13:2783;transport=TLS>#015#012To: "alice"<sip:alice@atlanta.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=6470be16#015#012Call-ID: MTM5NDE0YjRjMmU2ZWNlOThjNDI1MGM2ZjAzMDBjZjA.#015#012CSeq: 16 PUBLISH#015#012Expires: 1200#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/pidf+xml#015#012Proxy-Authorization: Digest username="alice",realm="atlanta.test",nonce="4a81babd0000000bdc0c130f92356ce11fc7ea51a926c644",uri="sip:alice@atlanta.test",response="527ee7c53e6f621ef9ee161426da4afd",cnonce="9f418c76f9b91cd9c3d71fbb4d36f415",nc=00000002,qop=auth,algorithm=MD5#015#012SIP-If-Match: a.1250015022.397.2.8#015#012Supported: replaces#015#012User-Agent: Bria Professional release 2.4 stamp 49381#015#012Event: presence#015#012Content-Length: 517#015#012#015#012<?xml version='1.0' encoding='UTF-8'?><presence xmlns='urn:ietf:params:xml:ns:pidf' xmlns:dm='urn:ietf:params:xml:ns:pidf:data-model' xmlns:rpid='urn:ietf:params:xml:ns:pidf:rpid' xmlns:c='urn:ietf:params:xml:ns:pidf:cipid' xmlns:lt='urn:ietf:params:xml:ns:location-type' entity='sip:alice@atlanta.test'><tuple id='tae2c271a'><status><basic>open</basic></status></tuple><dm:person id='p7a66b539'><rpid:activities><rpid:busy/><rpid:on-the-phone/></rpid:activities><dm:note>On the phone</dm:note></dm:person></presence> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=9 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:173]: DEBUG: get_hdr_field: <To> [33]; uri=[sip:alice@atlanta.test] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:175]: DEBUG: to body ["alice"<sip:alice@atlanta.test>#015#012] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: siputils [checks.c:65]: no totag Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=3 global id=2 T start=0xffffffff Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field: cseq <CSeq>: <16> <PUBLISH> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_hname2.c:182]: beginning of SIP-If-Match: yet=0x2d706973 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_hname2.c:182]: middle of SIP-If-Match: yet=0x6d2d6669 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_hname2.c:182]: end of SIP-If-Match Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: get_hdr_body : content_length=517 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:89]: found end of header Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=3518, isACK=0 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1149]: DEBUG: t_check_msg: msg id=3 global id=3 T end=(nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=6470be16 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=29 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [nonce.c:186]: comparing [4a81babd0000000bdc0c130f92356ce11fc7ea51a926c644] and [4a81babd0000000bdc0c130f92356ce11fc7ea51a926c644] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:116]: allocate 28 bytes for result set at 0x82bd628 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:68]: 3 columns returned from the query Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:153]: allocate 12 bytes for result names at 0x82f55d8 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:163]: allocate 12 bytes for result types at 0x82f52fc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[0] at 0x82f4e4c Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f4e4c)[0]=[password] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[1] at 0x82dbf88 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82dbf88)[1]=[email_address] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[2] at 0x82f5768 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f5768)[2]=[rpid] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:182]: allocate 8 bytes for rows at 0x82f4ebc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:119]: allocate 60 bytes for row values at 0x82f5390 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [bakker] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [sip:003631001001@atlanta.test] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth_db [authorize.c:123]: HA1 string calculated: 67bb4b4b59a70b7f246682dfdd188df2 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:239]: our result = '527ee7c53e6f621ef9ee161426da4afd' Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:246]: authorization is OK Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:194]: nonce index= 11 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [index.c:187]: nonce already used Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:198]: nonce index not valid Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:79]: freeing 3 columns Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[0] at 0x82f4e4c Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[1] at 0x82dbf88 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[2] at 0x82f5768 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:92]: freeing result names at 0x82f55d8 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:97]: freeing result types at 0x82f52fc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:52]: freeing 1 rows Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x82f5390 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:60]: freeing rows at 0x82f4ebc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:134]: freeing result set at 0x82bd628 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [index.c:128]: second= 16, sec_monit= 8, index= 12 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [challenge.c:107]: nonce index= 12 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [challenge.c:151]: 'Proxy-Authenticate: Digest realm="atlanta.test", nonce="4a81bacc0000000cc8f1349a189042236344c2b25f33aeb2", qop="auth"#015#012' Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: sl [sl.c:314]: reply in stateless mode (sl) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1998]: tcp_send: send from reader (390 (36)), reusing fd Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tls [tls_server.c:738]: write finished, 742 bytes written Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb584b448 n=742 fd=8 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012SIP/2.0 407 Proxy Authentication Required#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-260c1648321add52-1---d8754z-;rport=2783;received=92.249.143.13#015#012To: "alice"<sip:alice@atlanta.test>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.a62c#015#012From: "alice"<sip:alice@atlanta.test>;tag=6470be16#015#012Call-ID: MTM5NDE0YjRjMmU2ZWNlOThjNDI1MGM2ZjAzMDBjZjA.#015#012CSeq: 16 PUBLISH#015#012Proxy-Authenticate: Digest realm="atlanta.test", nonce="4a81bacc0000000cc8f1349a189042236344c2b25f33aeb2", qop="auth"#015#012Server: SIP Router (2.99.0-dev01-serk (i386/linux))#015#012Content-Length: 0#015#012Warning: 392 195.111.158.41:5061 "Noisy feedback tells: pid=390 req_src_ip=92.249.143.13 req_src_port=2783 in_uri=sip:alice@atlanta.test out_uri=sip:alice@atlanta.test via_cnt==1"#015#012#015#012 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:254]: receive_msg: cleaning up Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 517 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <PUBLISH> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:alice@atlanta.test> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-8b6841568301eb55-1---d8754z->; state=6 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:127]: After parse_msg... Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:166]: preparing to run routing scripts... Aug 11 20:38:38 a1 /usr/sbin/ser[390]: ERROR: <script>: Misi: PUBLISH sip:alice@atlanta.test SIP/2.0#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-8b6841568301eb55-1---d8754z-;rport#015#012Max-Forwards: 70#015#012Contact: <sip:alice@92.249.143.13:2783;transport=TLS>#015#012To: "alice"<sip:alice@atlanta.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=6470be16#015#012Call-ID: MTM5NDE0YjRjMmU2ZWNlOThjNDI1MGM2ZjAzMDBjZjA.#015#012CSeq: 17 PUBLISH#015#012Expires: 1200#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/pidf+xml#015#012Proxy-Authorization: Digest username="alice",realm="atlanta.test",nonce="4a81bacc0000000cc8f1349a189042236344c2b25f33aeb2",uri="sip:alice@atlanta.test",response="cc8d63baac587662386d887e507bf60b",cnonce="1eeeeb8bf845982d90f185276c67bc78",nc=00000001,qop=auth,algorithm=MD5#015#012SIP-If-Match: a.1250015022.397.2.8#015#012Supported: replaces#015#012User-Agent: Bria Professional release 2.4 stamp 49381#015#012Event: presence#015#012Content-Length: 517#015#012#015#012<?xml version='1.0' encoding='UTF-8'?><presence xmlns='urn:ietf:params:xml:ns:pidf' xmlns:dm='urn:ietf:params:xml:ns:pidf:data-model' xmlns:rpid='urn:ietf:params:xml:ns:pidf:rpid' xmlns:c='urn:ietf:params:xml:ns:pidf:cipid' xmlns:lt='urn:ietf:params:xml:ns:location-type' entity='sip:alice@atlanta.test'><tuple id='tae2c271a'><status><basic>open</basic></status></tuple><dm:person id='p7a66b539'><rpid:activities><rpid:busy/><rpid:on-the-phone/></rpid:activities><dm:note>On the phone</dm:note></dm:person></presence> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=9 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:173]: DEBUG: get_hdr_field: <To> [33]; uri=[sip:alice@atlanta.test] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:175]: DEBUG: to body ["alice"<sip:alice@atlanta.test>#015#012] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: siputils [checks.c:65]: no totag Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=4 global id=3 T start=(nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field: cseq <CSeq>: <17> <PUBLISH> Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_hname2.c:182]: beginning of SIP-If-Match: yet=0x2d706973 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_hname2.c:182]: middle of SIP-If-Match: yet=0x6d2d6669 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_hname2.c:182]: end of SIP-If-Match Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: get_hdr_body : content_length=517 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:89]: found end of header Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=3519, isACK=0 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1149]: DEBUG: t_check_msg: msg id=4 global id=4 T end=(nil) Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=6470be16 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=29 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [nonce.c:186]: comparing [4a81bacc0000000cc8f1349a189042236344c2b25f33aeb2] and [4a81bacc0000000cc8f1349a189042236344c2b25f33aeb2] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:116]: allocate 28 bytes for result set at 0x82bd628 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:68]: 3 columns returned from the query Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:153]: allocate 12 bytes for result names at 0x82f55d8 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:163]: allocate 12 bytes for result types at 0x82f52fc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[0] at 0x82f4ebc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f4ebc)[0]=[password] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[1] at 0x82f5768 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f5768)[1]=[email_address] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[2] at 0x82dbf88 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82dbf88)[2]=[rpid] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:182]: allocate 8 bytes for rows at 0x82f4e4c Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:119]: allocate 60 bytes for row values at 0x82f5390 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [bakker] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [sip:003631001001@atlanta.test] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth_db [authorize.c:123]: HA1 string calculated: 67bb4b4b59a70b7f246682dfdd188df2 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:239]: our result = 'cc8d63baac587662386d887e507bf60b' Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:246]: authorization is OK Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:194]: nonce index= 12 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: auth_db [authorize.c:176]: set string AVP ""/13 = "sip:003631001001@atlanta.test" Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:79]: freeing 3 columns Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[0] at 0x82f4ebc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[1] at 0x82f5768 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[2] at 0x82dbf88 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:92]: freeing result names at 0x82f55d8 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:97]: freeing result types at 0x82f52fc Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:52]: freeing 1 rows Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x82f5390 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:60]: freeing rows at 0x82f4e4c Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:134]: freeing result set at 0x82bd628 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: uri_db [checks.c:137]: Digest username and URI username match Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: rr [loose.c:108]: No Route headers found Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: rr [loose.c:907]: There is no Route HF Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:38 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1383]: DEBUG: t_newtran: msg id=4 , global msg id=4 , T on entrance=(nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=3519, isACK=0 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb585090c, callback type 1, id 0 entered Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [event_list.c:349]: start event= [presence/1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [publish.c:369]: SIP-If-Match header found Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [publish.c:378]: existing etag = a.1250015022.397.2.8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [publish.c:390]: Expires header found, value= 1200 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:116]: allocate 28 bytes for result set at 0x82f56e4 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:68]: 2 columns returned from the query Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:153]: allocate 8 bytes for result names at 0x82f5768 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:163]: allocate 8 bytes for result types at 0x82f4ebc Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[0] at 0x82f4e84 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f4e84)[0]=[body] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:121]: use DB1_BLOB result type Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[1] at 0x82f5730 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f5730)[1]=[sender] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:182]: allocate 8 bytes for rows at 0x82f4e10 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:119]: allocate 40 bytes for row values at 0x82f5960 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:168]: converting BLOB [<?xml version='1.0' encoding='UTF-8'?><presence xmlns='urn:ietf:params:xml:ns:pidf' xmlns:dm='urn:ietf:params:xml:ns:pidf:data-model' xmlns:rpid='urn:ietf:params:xml:ns:pidf:rpid' xmlns:c='urn:ietf:params:xml:ns:pidf:cipid' xmlns:lt='urn:ietf:params:xml:ns:location-type' entity='sip:alice@atlanta.test'><tuple id='tae2c271a'><status><basic>open</basic></status></tuple><dm:person id='p7a66b539'><dm:note>Available</dm:note></dm:person></presence>] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:79]: freeing 2 columns Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[0] at 0x82f4e84 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[1] at 0x82f5730 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:92]: freeing result names at 0x82f5768 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:97]: freeing result types at 0x82f4ebc Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:52]: freeing 1 rows Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x82f5960 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:60]: freeing rows at 0x82f4e10 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:134]: freeing result set at 0x82f56e4 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [presentity.c:88]: etag= a.1250015022.390.2.9 / 20#012 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [presentity.c:102]: send 200OK reply Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [presentity.c:103]: etag= a.1250015022.390.2.9 - len= 20 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=4 global id=4 T start=0xb585090c Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1152]: DEBUG: t_check_msg: T already found! Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [mem/shm_mem.c:117]: WARNING:vqm_resize: resize(0) called Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:1355]: DEBUG: cleanup_uac_timers: RETR/FR timers reset Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1998]: tcp_send: send from reader (390 (36)), reusing fd Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tls [tls_server.c:738]: write finished, 643 bytes written Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb584b448 n=643 fd=8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-8b6841568301eb55-1---d8754z-;rport=2783;received=92.249.143.13#015#012To: "alice"<sip:alice@atlanta.test>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-2965#015#012From: "alice"<sip:alice@atlanta.test>;tag=6470be16#015#012Call-ID: MTM5NDE0YjRjMmU2ZWNlOThjNDI1MGM2ZjAzMDBjZjA.#015#012CSeq: 17 PUBLISH#015#012Expires: 1200#015#012SIP-ETag: a.1250015022.390.2.9#015#012Server: SIP Router (2.99.0-dev01-serk (i386/linux))#015#012Content-Length: 0#015#012Warning: 392 195.111.158.41:5061 "Noisy feedback tells: pid=390 req_src_ip=92.249.143.13 req_src_port=2783 in_uri=sip:alice@atlanta.test out_uri=sip:alice@atlanta.test via_cnt==1"#015#012#015#012 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:610]: DEBUG: reply sent out. buf=0x82f5c80: SIP/2.0 2..., shmem=0xb584f674: SIP/2.0 2 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:620]: DEBUG: _reply_light: finished Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: sl [sl.c:309]: reply in stateful mode (tm) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [notify.c:1302]: found 0 dialogs( 0 in database and 0 in hash_table) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: presence [notify.c:1321]: Could not find subs_dialog Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:254]: receive_msg: cleaning up Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 544 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <INVITE> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:bob@biloxi.test> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-0b3389781d1b817e-1---d8754z->; state=6 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:127]: After parse_msg... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:166]: preparing to run routing scripts... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: ERROR: <script>: Misi: INVITE sip:bob@biloxi.test SIP/2.0#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-0b3389781d1b817e-1---d8754z-;rport#015#012Max-Forwards: 70#015#012Contact: <sip:alice@92.249.143.13:2783;transport=TLS>#015#012To: <sip:bob@biloxi.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 1 INVITE#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/sdp#015#012Supported: replaces#015#012User-Agent: Bria Professional release 2.4 stamp 49381#015#012Content-Length: 544#015#012#015#012v=0#015#012o=- 6 2 IN IP4 92.249.143.13#015#012s=CounterPath Bria Professional#015#012c=IN IP4 92.249.143.13#015#012t=0 0#015#012m=audio 4242 RTP/AVP 107 119 100 106 0 98 8 18 101#015#012a=alt:1 2 : bg/abBbq 9nirlFAG 192.168.1.7 4242#015#012a=alt:2 1 : wCTfkbfT 6n6JS41z 92.249.143.13 4242#015#012a=fmtp:18 annexb=yes#015#012a=fmtp:101 0-15#015#012a=rtpmap:107 BV32/16000#015#012a=rtpmap:119 BV32-FEC/16000#015#012a=rtpmap:100 SPEEX/16000#015#012a=rtpmap:106 SPEEX-FEC/16000#015#012a=rtpmap:98 iLBC/8000#015#012a=rtpmap:18 G729/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=sendrecv#015#012a=x-rtp-session-id:C5EF9F1EE4C64633A625BEC3FF808160#015#012 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=9 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:173]: DEBUG: get_hdr_field: <To> [23]; uri=[sip:bob@biloxi.test] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:175]: DEBUG: to body [<sip:bob@biloxi.test>#015#012] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: siputils [checks.c:65]: no totag Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=5 global id=4 T start=0xffffffff Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field: cseq <CSeq>: <1> <INVITE> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: get_hdr_body : content_length=544 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:89]: found end of header Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=5d194242 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=29 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=47015, isACK=0 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1149]: DEBUG: t_check_msg: msg id=5 global id=5 T end=(nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:126]: credentials with given realm not found Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [index.c:128]: second= 18, sec_monit= 8, index= 13 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [challenge.c:107]: nonce index= 13 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [challenge.c:151]: 'Proxy-Authenticate: Digest realm="atlanta.test", nonce="4a81bacd0000000dda4c36dd574a1b80048af63c44e36fd0", qop="auth"#015#012' Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: sl [sl.c:314]: reply in stateless mode (sl) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1998]: tcp_send: send from reader (390 (36)), reusing fd Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tls [tls_server.c:738]: write finished, 724 bytes written Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb584b448 n=724 fd=8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012SIP/2.0 407 Proxy Authentication Required#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-0b3389781d1b817e-1---d8754z-;rport=2783;received=92.249.143.13#015#012To: <sip:bob@biloxi.test>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.d643#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 1 INVITE#015#012Proxy-Authenticate: Digest realm="atlanta.test", nonce="4a81bacd0000000dda4c36dd574a1b80048af63c44e36fd0", qop="auth"#015#012Server: SIP Router (2.99.0-dev01-serk (i386/linux))#015#012Content-Length: 0#015#012Warning: 392 195.111.158.41:5061 "Noisy feedback tells: pid=390 req_src_ip=92.249.143.13 req_src_port=2783 in_uri=sip:bob@biloxi.test out_uri=sip:bob@biloxi.test via_cnt==1"#015#012#015#012 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:254]: receive_msg: cleaning up Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 0 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <ACK> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:bob@biloxi.test> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-0b3389781d1b817e-1---d8754z->; state=6 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:127]: After parse_msg... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:166]: preparing to run routing scripts... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=f8f2ab2c1295e90ed7dbb499b30f44b2.d643 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=29 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:173]: DEBUG: get_hdr_field: <To> [65]; uri=[sip:bob@biloxi.test] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:175]: DEBUG: to body [<sip:bob@biloxi.test>] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: sl [sl_funcs.c:327]: local ACK found -> dropping it! Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:254]: receive_msg: cleaning up Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 544 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <INVITE> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:bob@biloxi.test> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-2a767f38e361686d-1---d8754z->; state=6 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:127]: After parse_msg... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:166]: preparing to run routing scripts... Aug 11 20:38:39 a1 /usr/sbin/ser[390]: ERROR: <script>: Misi: INVITE sip:bob@biloxi.test SIP/2.0#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-2a767f38e361686d-1---d8754z-;rport#015#012Max-Forwards: 70#015#012Contact: <sip:alice@92.249.143.13:2783;transport=TLS>#015#012To: <sip:bob@biloxi.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 2 INVITE#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/sdp#015#012Proxy-Authorization: Digest username="alice",realm="atlanta.test",nonce="4a81bacd0000000dda4c36dd574a1b80048af63c44e36fd0",uri="sip:bob@biloxi.test",response="60ca1ab3ccd52ae04fded05e2056a49a",cnonce="41e9f5aabf671596242bb02343062a1b",nc=00000001,qop=auth,algorithm=MD5#015#012Supported: replaces#015#012User-Agent: Bria Professional release 2.4 stamp 49381#015#012Content-Length: 544#015#012#015#012v=0#015#012o=- 6 2 IN IP4 92.249.143.13#015#012s=CounterPath Bria Professional#015#012c=IN IP4 92.249.143.13#015#012t=0 0#015#012m=audio 4242 RTP/AVP 107 119 100 106 0 98 8 18 101#015#012a=alt:1 2 : bg/abBbq 9nirlFAG 192.168.1.7 4242#015#012a=alt:2 1 : wCTfkbfT 6n6JS41z 92.249.143.13 4242#015#012a=fmtp:18 annexb=yes#015#012a=fmtp:101 0-15#015#012a=rtpmap:107 BV32/16000#015#012a=rtpmap:119 BV32-FEC/16000#015#012a=rtpmap:100 SPEEX/16000#015#012a=rtpmap:106 SPEEX-FEC/16000#015#012a=rtpmap:98 iLBC/8000#015#012a=rtpmap:18 G729/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=sendrecv#015#012a=x-rtp-session-id:C5EF9F1EE4C64633A625BEC3FF808160#015#012 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=9 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:173]: DEBUG: get_hdr_field: <To> [23]; uri=[sip:bob@biloxi.test] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:175]: DEBUG: to body [<sip:bob@biloxi.test>#015#012] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: siputils [checks.c:65]: no totag Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=7 global id=5 T start=(nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field: cseq <CSeq>: <2> <INVITE> Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: get_hdr_body : content_length=544 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:89]: found end of header Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=5d194242 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=29 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=47012, isACK=0 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1149]: DEBUG: t_check_msg: msg id=7 global id=7 T end=(nil) Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==9 && [atlanta.test] == [127.0.0.1] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 12==14 && [atlanta.test] == [195.111.158.41] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [nonce.c:186]: comparing [4a81bacd0000000dda4c36dd574a1b80048af63c44e36fd0] and [4a81bacd0000000dda4c36dd574a1b80048af63c44e36fd0] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:116]: allocate 28 bytes for result set at 0x82bd628 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:68]: 3 columns returned from the query Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:153]: allocate 12 bytes for result names at 0x82f55d8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:163]: allocate 12 bytes for result types at 0x82f52b8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[0] at 0x82dbf88 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82dbf88)[0]=[password] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[1] at 0x82f4e4c Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f4e4c)[1]=[email_address] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:85]: allocate 8 bytes for RES_NAMES[2] at 0x82f4ebc Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x82f4ebc)[2]=[rpid] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:182]: allocate 8 bytes for rows at 0x82f5768 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:119]: allocate 60 bytes for row values at 0x82f5960 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [bakker] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_val.c:117]: converting STRING [sip:003631001001@atlanta.test] Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth_db [authorize.c:123]: HA1 string calculated: 67bb4b4b59a70b7f246682dfdd188df2 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:239]: our result = '60ca1ab3ccd52ae04fded05e2056a49a' Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:246]: authorization is OK Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth [api.c:194]: nonce index= 13 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: auth_db [authorize.c:176]: set string AVP ""/13 = "sip:003631001001@atlanta.test" Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:79]: freeing 3 columns Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[0] at 0x82dbf88 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[1] at 0x82f4e4c Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:83]: freeing RES_NAMES[2] at 0x82f4ebc Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:92]: freeing result names at 0x82f55d8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:97]: freeing result types at 0x82f52b8 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:52]: freeing 1 rows Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x82f5960 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:60]: freeing rows at 0x82f5768 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: <core> [db_res.c:134]: freeing result set at 0x82bd628 Aug 11 20:38:39 a1 /usr/sbin/ser[390]: DEBUG: uri_db [checks.c:137]: Digest username and URI username match Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: rr [loose.c:108]: No Route headers found Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: rr [loose.c:907]: There is no Route HF Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==9 && [biloxi.test] == [127.0.0.1] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==14 && [biloxi.test] == [195.111.158.41] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==9 && [biloxi.test] == [127.0.0.1] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==14 && [biloxi.test] == [195.111.158.41] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==9 && [biloxi.test] == [127.0.0.1] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==14 && [biloxi.test] == [195.111.158.41] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5061 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==9 && [biloxi.test] == [127.0.0.1] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:484]: grep_sock_info - checking if host==us: 11==14 && [biloxi.test] == [195.111.158.41] Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [socket_info.c:487]: grep_sock_info - checking if port 5060 matches port 5060 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [forward.c:318]: check_self: host != me Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1383]: DEBUG: t_newtran: msg id=7 , global msg id=7 , T on entrance=(nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=47012, isACK=0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb584cf18, callback type 1, id 0 entered Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_funcs.c:348]: SER: new INVITE Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [mem/shm_mem.c:117]: WARNING:vqm_resize: resize(0) called Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1998]: tcp_send: send from reader (390 (36)), reusing fd Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tls [tls_server.c:738]: write finished, 572 bytes written Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb584b448 n=572 fd=8 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012SIP/2.0 100 trying -- your call is important to us#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-2a767f38e361686d-1---d8754z-;rport=2783;received=92.249.143.13#015#012To: <sip:bob@biloxi.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 2 INVITE#015#012Server: SIP Router (2.99.0-dev01-serk (i386/linux))#015#012Content-Length: 0#015#012Warning: 392 195.111.158.41:5061 "Noisy feedback tells: pid=390 req_src_ip=92.249.143.13 req_src_port=2783 in_uri=sip:bob@biloxi.test out_uri=sip:bob@biloxi.test via_cnt==1"#015#012#015#012 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:610]: DEBUG: reply sent out. buf=0x82f5c80: SIP/2.0 1..., shmem=0xb58505ec: SIP/2.0 1 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:620]: DEBUG: _reply_light: finished Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:560]: dns_hash_find(biloxi.test(11), 35), h=599 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2674]: naptr_iterate: found a valid sip NAPTR rr _sip._tcp.biloxi.test, proto 2 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [resolve.c:1091]: naptr_choose(o: -1 w: -1 p:0 , o: 20 w:50 p:2) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [resolve.c:1107]: naptr_choose: changed Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2674]: naptr_iterate: found a valid sip NAPTR rr _sip._udp.biloxi.test, proto 1 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [resolve.c:1091]: naptr_choose(o: 20 w: 50 p:2 , o: 30 w:50 p:1) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [resolve.c:1102]: naptr_choose: no change Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2674]: naptr_iterate: found a valid sip NAPTR rr _sips._tcp.biloxi.test, proto 3 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [resolve.c:1091]: naptr_choose(o: 20 w: 50 p:2 , o: 10 w:50 p:3) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [resolve.c:1107]: naptr_choose: changed Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2688]: naptr_iterate: choosed NAPTR rr _sips._tcp.biloxi.test, proto 3 tried: 0x0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:560]: dns_hash_find(_sips._tcp.biloxi.test(22), 33), h=208 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2246]: dns_srv_get_nxt_rr(0xb5864a2c, 0, 0, 559080590): selected 0/1 in grp. 0 (rand_w=0, rr=0xb5864a70 p=10 w=0 rsum=0) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:560]: dns_hash_find(b1.biloxi.test(14), 1), h=386 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2861]: dns_a_resovle(b1.biloxi.test, 0) returning 0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:3115]: dns_srv_resolve_ip("_sips._tcp.biloxi.test", 0, 0), ret=0, ip=195.111.158.43 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:3350]: dns_naptr_sip_resolve(biloxi.test, 0, 0), srv0, ret=0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: <script>: new branch at sip:bob@biloxi.test Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:2379]: create_via_hf: id added: <;i=2>, rcv proto=3 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1778]: tcp_send: no open tcp connection found, opening new one Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [ip_addr.c:116]: tcpconn_new: new tcp connection: 195.111.158.43 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1050]: tcpconn_new: on port 5061, type 3 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [tcp_main.c:3014]: handle_ser_child: read response= b5865b20, 2, fd 68 from 36 (390) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: BUG: tls [tls_server.c:98]: Invalid connection state (bug in TCP code) Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [tcp_main.c:1349]: tcpconn_add: hashes: 1306:736:1196, 9 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: tls [tls_server.c:145]: Delayed init failed Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [io_wait.h:361]: DBG: io_watch_add(0x8228560, 68, 2, 0xb5865b20), fd_no=55 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb5865b20 n=-1 fd=13 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012INVITE sip:bob@biloxi.test SIP/2.0#015#012Record-Route: <sip:195.111.158.41:5061;transport=tls;lr=on;ftag=5d194242>#015#012Via: SIP/2.0/TLS 195.111.158.41:5061;branch=z9hG4bK4a7b.1036c875.0;i=2#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;received=92.249.143.13;branch=z9hG4bK-d8754z-2a767f38e361686d-1---d8754z-;rport=2783#015#012Max-Forwards: 69#015#012Contact: <sip:alice@92.249.143.13:2783;transport=TLS>#015#012To: <sip:bob@biloxi.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 2 INVITE#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/sdp#015#012Supported: replaces#015#012User-Agent: Bria Professional release 2.4 stamp 49381#015#012Content-Length: 544#015#012P-hint: outbound#015#012#015#012v=0#015#012o=- 6 2 IN IP4 92.249.143.13#015#012s=CounterPath Bria Professional#015#012c=IN IP4 92.249.143.13#015#012t=0 0#015#012m=audio 4242 RTP/AVP 107 119 100 106 0 98 8 18 101#015#012a=alt:1 2 : bg/abBbq 9nirlFAG 192.168.1.7 4242#015#012a=alt:2 1 : wCTfkbfT 6n6JS41z 92.249.143.13 4242#015#012a=fmtp:18 annexb=yes#015#012a=fmtp:101 0-15#015#012a=rtpmap:107 BV32/16000#015#012a=rtpmap:119 BV32-FEC/16000#015#012a=rtpmap:100 SPEEX/16000#015#012a=rtpmap:106 SPEEX-FEC/16000#015#012a=rtpmap:98 iLBC/8000#015#012a=rtpmap:18 G729/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=sendrecv#015#012a=x-rtp-session-id:C5EF9F1EE4C64633A625BEC3FF808160#015#012 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: <core> [tcp_main.c:2166]: ERROR: tcp_send: failed to send on 0xb5865b20 (195.111.158.41:59267->195.111.158.43:5061): Operation now in progress (115) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: tm [../../forward.h:163]: msg_send: ERROR: tcp_send failed Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [tcp_main.c:3014]: handle_ser_child: read response= b5865b20, -2, fd -1 from 36 (390) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_fwd.c:961]: t_send_branch: send to 195.111.158.43:5061 (3) failed Aug 11 20:38:40 a1 /usr/sbin/ser[398]: ERROR: <core> [tcp_main.c:3027]: handle_ser_child: ERROR: received CON_ERROR for 0xb5865b20 (id 9), refcnt 2 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2861]: dns_a_resovle(b1.biloxi.test, 1) returning -1 Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [io_wait.h:588]: DBG: io_watch_del (0x8228560, 68, -1, 0x10) fd_no=56 called Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2246]: dns_srv_get_nxt_rr(0xb5864a2c, 0, 0, 559080593): selected 0/1 in grp. 1 (rand_w=0, rr=0xb5864a98 p=20 w=0 rsum=0) Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: tls [tls_server.c:689]: Closing SSL connection Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:560]: dns_hash_find(b2.biloxi.test(14), 1), h=281 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2861]: dns_a_resovle(b2.biloxi.test, 0) returning 0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:3115]: dns_srv_resolve_ip("_sips._tcp.biloxi.test", 1, 0), ret=0, ip=195.111.158.44 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:3256]: dns_sip_resolve(biloxi.test, 1, 0), srv, ret=0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:2379]: create_via_hf: id added: <;i=2>, rcv proto=3 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_fwd.c:974]: t_send_branch: send on branch 0 failed, adding another branch with another ip Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1778]: tcp_send: no open tcp connection found, opening new one Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [ip_addr.c:116]: tcpconn_new: new tcp connection: 195.111.158.44 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1050]: tcpconn_new: on port 5061, type 3 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:40 a1 /usr/sbin/ser[390]: BUG: tls [tls_server.c:98]: Invalid connection state (bug in TCP code) Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [tcp_main.c:3014]: handle_ser_child: read response= b5865b20, 2, fd 68 from 36 (390) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: tls [tls_server.c:145]: Delayed init failed Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [tcp_main.c:1349]: tcpconn_add: hashes: 1693:359:2697, 10 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb5865b20 n=-1 fd=13 Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [io_wait.h:361]: DBG: io_watch_add(0x8228560, 68, 2, 0xb5865b20), fd_no=55 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012INVITE sip:bob@biloxi.test SIP/2.0#015#012Record-Route: <sip:195.111.158.41:5061;transport=tls;lr=on;ftag=5d194242>#015#012Via: SIP/2.0/TLS 195.111.158.41:5061;branch=z9hG4bK4a7b.1036c875.1;i=2#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;received=92.249.143.13;branch=z9hG4bK-d8754z-2a767f38e361686d-1---d8754z-;rport=2783#015#012Max-Forwards: 69#015#012Contact: <sip:alice@92.249.143.13:2783;transport=TLS>#015#012To: <sip:bob@biloxi.test>#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 2 INVITE#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/sdp#015#012Supported: replaces#015#012User-Agent: Bria Professional release 2.4 stamp 49381#015#012Content-Length: 544#015#012P-hint: outbound#015#012#015#012v=0#015#012o=- 6 2 IN IP4 92.249.143.13#015#012s=CounterPath Bria Professional#015#012c=IN IP4 92.249.143.13#015#012t=0 0#015#012m=audio 4242 RTP/AVP 107 119 100 106 0 98 8 18 101#015#012a=alt:1 2 : bg/abBbq 9nirlFAG 192.168.1.7 4242#015#012a=alt:2 1 : wCTfkbfT 6n6JS41z 92.249.143.13 4242#015#012a=fmtp:18 annexb=yes#015#012a=fmtp:101 0-15#015#012a=rtpmap:107 BV32/16000#015#012a=rtpmap:119 BV32-FEC/16000#015#012a=rtpmap:100 SPEEX/16000#015#012a=rtpmap:106 SPEEX-FEC/16000#015#012a=rtpmap:98 iLBC/8000#015#012a=rtpmap:18 G729/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=sendrecv#015#012a=x-rtp-session-id:C5EF9F1EE4C64633A625BEC3FF808160#015#012 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: <core> [tcp_main.c:2166]: ERROR: tcp_send: failed to send on 0xb5865b20 (195.111.158.41:55898->195.111.158.44:5061): Operation now in progress (115) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: tm [../../forward.h:163]: msg_send: ERROR: tcp_send failed Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [tcp_main.c:3014]: handle_ser_child: read response= b5865b20, -2, fd -1 from 36 (390) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_fwd.c:961]: t_send_branch: send to 195.111.158.44:5061 (3) failed Aug 11 20:38:40 a1 /usr/sbin/ser[398]: ERROR: <core> [tcp_main.c:3027]: handle_ser_child: ERROR: received CON_ERROR for 0xb5865b20 (id 10), refcnt 2 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:2861]: dns_a_resovle(b2.biloxi.test, 1) returning -1 Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: <core> [io_wait.h:588]: DBG: io_watch_del (0x8228560, 68, -1, 0x10) fd_no=56 called Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:3115]: dns_srv_resolve_ip("_sips._tcp.biloxi.test", 2, 1), ret=-1, ip= Aug 11 20:38:40 a1 /usr/sbin/ser[398]: DEBUG: tls [tls_server.c:689]: Closing SSL connection Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [dns_cache.c:3256]: dns_sip_resolve(biloxi.test, 2, 1), srv, ret=-1 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: ERROR: tm [t_fwd.c:980]: ERROR: t_send_branch: sending request on branch 1 failed Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_funcs.c:358]: ERROR:tm:t_relay_to: t_forward_nonack returned error Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_funcs.c:366]: -477 error reply generation delayed Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: sl [sl_funcs.c:283]: error text is Unfortunately error on sending to next hop occurred (477/SL) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1998]: tcp_send: send from reader (390 (36)), reusing fd Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tls [tls_server.c:738]: write finished, 636 bytes written Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb584b448 n=636 fd=8 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012SIP/2.0 477 Unfortunately error on sending to next hop occurred (477/SL)#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-2a767f38e361686d-1---d8754z-;rport=2783;received=92.249.143.13#015#012To: <sip:bob@biloxi.test>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.573f#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 2 INVITE#015#012Server: SIP Router (2.99.0-dev01-serk (i386/linux))#015#012Content-Length: 0#015#012Warning: 392 195.111.158.41:5061 "Noisy feedback tells: pid=390 req_src_ip=92.249.143.13 req_src_port=2783 in_uri=sip:bob@biloxi.test out_uri=sip:bob@biloxi.test via_cnt==1"#015#012#015#012 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_lookup.c:1536]: t_unref: delayed error reply generation(-477) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [msg_translator.c:200]: check_via_address(92.249.143.13, 192.168.1.7, 0) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:1355]: DEBUG: cleanup_uac_timers: RETR/FR timers reset Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:1998]: tcp_send: send from reader (390 (36)), reusing fd Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2049]: tcp_send: sending... Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tls [tls_server.c:738]: write finished, 636 bytes written Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2085]: tcp_send: after real write: c= 0xb584b448 n=636 fd=8 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_main.c:2086]: tcp_send: buf=#012SIP/2.0 477 Unfortunately error on sending to next hop occurred (477/TM)#015#012Via: SIP/2.0/TLS 192.168.1.7:4241;branch=z9hG4bK-d8754z-2a767f38e361686d-1---d8754z-;rport=2783;received=92.249.143.13#015#012To: <sip:bob@biloxi.test>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-573f#015#012From: "alice"<sip:alice@atlanta.test>;tag=5d194242#015#012Call-ID: ZTczYjE5ZThhZjhkNmYyMDY0NGYxM2ExOTdkYjg5ZDM.#015#012CSeq: 2 INVITE#015#012Server: SIP Router (2.99.0-dev01-serk (i386/linux))#015#012Content-Length: 0#015#012Warning: 392 195.111.158.41:5061 "Noisy feedback tells: pid=390 req_src_ip=92.249.143.13 req_src_port=2783 in_uri=sip:bob@biloxi.test out_uri=sip:bob@biloxi.test via_cnt==1"#015#012#015#012 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_hooks.c:252]: DBG: trans=0xb584cf18, callback type 128, id 0 entered Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:610]: DEBUG: reply sent out. buf=0x82f6088: SIP/2.0 4..., shmem=0xb58505ec: SIP/2.0 4 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: tm [t_reply.c:620]: DEBUG: _reply_light: finished Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:254]: receive_msg: cleaning up Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 0 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <ACK> Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:bob@biloxi.test> Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-2a767f38e361686d-1---d8754z->; state=6 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:40 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:127]: After parse_msg... Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:166]: preparing to run routing scripts... Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=f8f2ab2c1295e90ed7dbb499b30f44b2.573f Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_to.c:753]: end of header reached, state=29 Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:173]: DEBUG: get_hdr_field: <To> [65]; uri=[sip:bob@biloxi.test] Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:175]: DEBUG: to body [<sip:bob@biloxi.test>] Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: sl [sl_funcs.c:327]: local ACK found -> dropping it! Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) Aug 11 20:38:41 a1 /usr/sbin/ser[390]: DEBUG: <core> [receive.c:254]: receive_msg: cleaning up Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 447 Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:599]: SIP Request: Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:601]: method: <PUBLISH> Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:603]: uri: <sip:alice@atlanta.test> Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:605]: version: <SIP/2.0> Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK-d8754z-0d1d4d59c544e42e-1---d8754z->; state=6 Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:495]: parse_headers: Via found, flags=2 Aug 11 20:38:44 a1 /usr/sbin/ser[390]: DEBUG: <core> [parser/msg_parser.c:497]: parse_headers: this is the first via # # $Id$ # # This a very basic config file w aliases and anamed route but # w/o authentication, accounting, database, multi-domain support etc. # Please refer to sip-router.cfg for a more complete example # # ----------- global configuration parameters ------------------------ debug=5 # debug level (cmd line: -dddddddddd) memdbg=6 # memory debug message level memlog=6 # memory statistics log level #log_facility=LOG_LOCAL0 # sets the facility used for logging (see syslog(3)) /* 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 user=ser group=ser #disable_core=yes #disables core dumping #open_fd_limit=1024 # sets the open file descriptors limit #mhomed=yes # usefull for multihomed hosts, small performance penalty #TLS enable_tls=yes #TCP settings disable_tcp=no tcp_async=no tcp_send_timeout=2 #tcp_accept_aliases=yes # accepts the tcp alias via option (see NEWS) tcp_delayed_ack=no tcp_fd_cache=no # Alias alias=atlanta.test:5061 alias=atlanta.test:5060 #Tells how long to keep negative DNS responses in cache. If set to 0, disables caching of negative responses. #Default is 60 (seconds). dns_cache_negative_ttl=5 #Number of dns retransmissions before giving up. dns_retr_no=3 #Time in seconds before retrying a dns request. dns_retr_time=3 #dns_srv_loadbalancing Enable dns srv weight based load balancing dns_srv_lb = yes #If it is set to 'yes' and a DNS lookup fails, it will retry it for ipv6 (AAAA record) dns_try_ipv6=yes #Enable NAPTR support according to RFC 3263 dns_try_naptr = yes #Set preference for each protocol when doing naptr lookups. #By default dns_udp_pref=30, dns_tcp_pref=20, dns_tls_pref=10 and dns_sctp_pref=20. #To completely ignore NAPTR records for a specific protocol, set the corresponding protocol preference to -1 (or any other negative number). dns_udp_pref = 1 dns_tcp_pref = 1 dns_tls_pref = 1 dns_sctp_pref = 1 #If set to 'no', the search list in '/etc/resolv.conf' will be ignored. #(-> fewer lookups -> gives up faster). Default value is 'yes'. dns_use_search_list=no #default off use_dns_failover=yes # ------------------ module loading ---------------------------------- #loadpath "modules:modules_s" #loadpath "/usr/lib/ser/modules:/usr/lib/ser/modules_s" # common modules loadpath "/usr/lib/ser/modules" loadmodule "tm" loadmodule "utils" loadmodule "db_mysql" loadmodule "avpops.so" loadmodule "tls" # Kamailio modules loadpath "/usr/lib/ser/modules_k" loadmodule "sl" loadmodule "rr" loadmodule "usrloc" loadmodule "registrar" loadmodule "maxfwd" loadmodule "textops" loadmodule "uri_db.so" loadmodule "acc.so" loadmodule "auth.so" loadmodule "auth_db.so" loadmodule "alias_db.so" loadmodule "pv.so" loadmodule "siputils.so" loadmodule "presence.so" loadmodule "presence_xml.so" loadmodule "presence_mwi.so" loadmodule "presence_dialoginfo.so" loadmodule "xlog.so" # ser modules loadpath "/usr/lib/ser/modules_s" loadmodule "ctl" loadmodule "cfg_rpc" loadmodule "auth_identity" #loadmodule "sl" #loadmodule "sanity" #loadmodule "registrar" # ----------------- setting module-specific parameters --------------- # -- tls params -- modparam("tls","config","/etc/ser/tls.cfg") # -- usrloc params -- modparam("usrloc", "db_mode", 0) # -- rr params -- # add value to ;lr param to make some broken UAs happy modparam("rr", "enable_full_lr", 1) # ctl params # by default ctl listens on unixs:/tmp/sip-router_ctl if no other address is # specified in modparams; this is also the default for sercmd modparam("ctl", "binrpc", "unixs:/tmp/sip-router_ctl") # listen on the "standard" fifo for backward compatibility modparam("ctl", "fifo", "fifo:/tmp/sip-router_fifo") # listen on tcp, localhost #modparam("ctl", "binrpc", "tcp:localhost:2046") # ----- registrar params ----- #modparam("registrar", "method_filtering", 1) /* uncomment the next line to disable parallel forking via location */ # modparam("registrar", "append_branches", 0) /* uncomment the next line not to allow more than 10 contacts per AOR */ #modparam("registrar", "max_contacts", 10) # ----- usrloc params ----- #modparam("usrloc", "db_mode", 0) /* uncomment the following lines if you want to enable DB persistency for location entries */ modparam("usrloc", "db_mode", 1) modparam("usrloc", "db_url", "mysql://opensips:opensipsrw@localhost/opensips") # ----- uri_db params ----- /* by default we disable the DB support in the module as we do not need it in this configuration */ modparam("uri_db", "use_uri_table", 0) modparam("uri_db", "db_url", "") # ----- acc params ----- /* what sepcial events should be accounted ? */ modparam("acc", "early_media", 1) modparam("acc", "report_ack", 1) modparam("acc", "report_cancels", 1) /* by default ww do not adjust the direct of the sequential requests. if you enable this parameter, be sure the enable "append_fromtag" in "rr" module */ modparam("acc", "detect_direction", 0) /* account triggers (flags) */ modparam("acc", "failed_transaction_flag", 3) modparam("acc", "log_flag", 1) modparam("acc", "log_missed_flag", 2) /* uncomment the following lines to enable DB accounting also */ modparam("acc", "db_flag", 1) modparam("acc", "db_missed_flag", 2) # ----- auth params ----- modparam("auth", "rpid_avp", "$avp(i:13)") # ----- auth_db params ----- /* uncomment the following lines if you want to enable the DB based authentication */ modparam("auth_db", "calculate_ha1", yes) modparam("auth_db", "password_column", "password") modparam("auth_db", "db_url", "mysql://opensips:opensipsrw@localhost/opensips") modparam("auth_db", "load_credentials", "$avp(i:13)=rpid;email_address") # ----- alias_db params ----- /* uncomment the following lines if you want to enable the DB based aliases */ modparam("alias_db", "db_url", "mysql://opensips:opensipsrw@localhost/opensips") # ----- presence params ----- /* uncomment the following lines if you want to enable presence */ modparam("presence", "db_url","mysql://opensips:opensipsrw@localhost/opensips") modparam("presence", "server_address", "sip:atlanta.test") modparam("presence_xml", "db_url","mysql://opensips:opensipsrw@localhost/opensips") modparam("presence_xml", "force_active", 1) # ----- auth identity params ----- modparam("auth_identity","cainfo_path","/etc/ssl/certs/ca-certificates.crt") #TODO web server publicating CERTIFICATE. modparam("auth_identity","certificate_url","https://www.atlanata.test/mycert.der") modparam("auth_identity","certificate_path","/etc/ser/tls/cert.pem") modparam("auth_identity","privatekey_path","/etc/ser/tls/privkey.pem") ####### Routing Logic ######## # main request routing logic route{ xlog("L_ERR", "Misi: $mb\n"); # 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 >= 4096 ) { sl_send_reply("513", "Message too big"); exit; } if (has_totag()) { # sequential request withing a dialog should # take the path determined by record-routing if (loose_route()) { if (is_method("BYE")) { setflag(1); # do accounting ... setflag(3); # ... even if the transaction fails } else if (is_method("INVITE")) { # even if in most of the cases is useless, do RR for # re-INVITEs alos, as some buggy clients do change route set # during the dialog. record_route(); } # route it out to whatever destination was set by loose_route() # in $du (destination URI). route(1); } else { /* uncomment the following lines if you want to enable presence */ if (is_method("SUBSCRIBE") && $rd == "atlanta.test") { # in-dialog subscribe requests route(2); exit; } if ( is_method("ACK") ) { if ( t_check_trans() ) { # non loose-route, but stateful ACK; must be an ACK after # a 487 or e.g. 404 from upstream server t_relay(); exit; } else { # ACK without matching transaction -> # ignore and discard exit; } } sl_send_reply("404","Not here"); } exit; } #initial requests # CANCEL processing if (is_method("CANCEL")) { if (t_check_trans()) t_relay(); exit; } t_check_trans(); # authenticate if from local subscriber (uncomment to enable auth) # authenticate all initial non-REGISTER request that pretend to be # generated by local subscriber (domain from FROM URI is local) if (!(method=="REGISTER") && from_uri==myself) /*no multidomain version*/ ##if (!(method=="REGISTER") && is_from_local()) /*multidomain version*/ { if (!proxy_authorize("", "subscriber")) { proxy_challenge("", "0"); exit; } if (!check_from()) { sl_send_reply("403","Forbidden auth ID"); exit; } consume_credentials(); # caller authenticated } # preloaded route checking if (loose_route()) { xlog("L_ERR", "Attempt to route with preloaded Route's [$fu/$tu/$ru/$ci]"); if (!is_method("ACK")) sl_send_reply("403","Preload Route denied"); exit; } # record routing if (!is_method("REGISTER|MESSAGE")) record_route(); # account only INVITEs if (is_method("INVITE")) { setflag(1); # do accounting } if (!uri==myself) ## replace with following line if multi-domain support is used ##if (!is_uri_host_local()) { append_hf("P-hint: outbound\r\n"); # if you have some interdomain connections via TLS ##if($rd=="tls_domain1.net") { ## t_relay("tls:domain1.net"); ## exit; ##} else if($rd=="tls_domain2.net") { ## t_relay("tls:domain2.net"); ## exit; ##} route(1); } # requests for my domain ## uncomment this if you want to enable presence server ## and comment the next 'if' block ## NOTE: uncomment also the definition of route[2] from below if( is_method("PUBLISH|SUBSCRIBE")) route(2); #if (is_method("PUBLISH")) #{ # sl_send_reply("503", "Service Unavailable"); # exit; #} if (is_method("REGISTER")) { # authenticate the REGISTER requests (uncomment to enable auth) if (!www_authorize("", "subscriber")) { www_challenge("", "0"); exit; } if (!check_to()) { sl_send_reply("403","Forbidden auth ID"); exit; } if (!save("location")) sl_reply_error(); exit; } if ($rU=="") { # request with no Username in RURI sl_send_reply("484","Address Incomplete"); exit; } # apply DB based aliases (uncomment to enable) alias_db_lookup("dbaliases"); if(uri=~"sip:0.*@.*"){ sethost("195.111.158.3"); strip(1); # Append Remote-Party-ID header field append_rpid_hf("<", ">;party=calling;id-type=subscriber;screen=yes;privacy=off"); /* Remote-Party-ID: <sip:003646565111@195.111.104.13>;party=calling;screen=no;privacy=off */ route(1); exit; } if (!lookup("location")) { switch ($rc) { case -1: case -3: t_newtran(); t_reply("404", "Not Found"); exit; case -2: sl_send_reply("405", "Method Not Allowed"); exit; } } # when routing via usrloc, log the missed calls also setflag(2); route(1); } route[1] { # for INVITEs enable some additional helper routes if (is_method("INVITE")) { t_on_branch("2"); t_on_reply("2"); t_on_failure("1"); } if (!t_relay()) { sl_reply_error(); }; exit; } # Presence route /* uncomment the whole following route for enabling presence NOTE: do not forget to enable the call of this route from the main route */ route[2] { if (!t_newtran()) { sl_reply_error(); exit; }; if(is_method("PUBLISH")) { handle_publish(); # Removed command. Not Supported anymore. # At the end of script the transaction is automaticaly relased by TM. #t_release(); } else if( is_method("SUBSCRIBE")) { handle_subscribe(); # Removed command. Not Supported anymore. # At the end of script the transaction is automaticaly relased by TM. #t_release(); } exit; } branch_route[2] { xlog("new branch at $ru\n"); } onreply_route[2] { xlog("L_ERR", "Reply Misi: $mb\n"); xlog("incoming reply\n"); } failure_route[1] { if (t_is_canceled()) { exit; } # uncomment the following lines if you want to block client # redirect based on 3xx replies. ##if (t_check_status("3[0-9][0-9]")) { ##t_reply("404","Not found"); ## exit; ##} # uncomment the following lines if you want to redirect the failed # calls to a different new destination ##if (t_check_status("486|408")) { ## sethostport("192.168.2.100:5060"); ## # do not set the missed call flag again ## t_relay(); ##} } ####################################Ser########################################## # ## ------------------------- 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"); # break; # } # if (msg:len >= 4096 ) { # sl_send_reply("513", "Message too big"); # break; # } # # # 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(FORWARD); # break; # } # # if (!uri==myself) { # # mark routing logic in request # append_hf("P-hint: outbound\r\n"); # route(FORWARD); # break; # } # # # 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") { # save_contacts("location"); ## break; # } # # # native SIP destinations are handled using our USRLOC DB # if (!lookup_contacts("location")) { # sl_send_reply("404", "Not Found"); # break; # } ## append_hf("P-hint: usrloc applied\r\n"); # } # route(FORWARD); #} # #route[FORWARD] #{ # # send it out now; use stateful forwarding as it works reliably # # even for UDP2TCP # if (!t_relay()) { # sl_reply_error(); ## } #} # # $Id$ # # Example SER TLS Configuration File # # This is the default server domain, settings # in this domain will be used for all incoming # connections that do not match any other server # domain in this configuration file. # # We do not enable anything else than TLSv1 # over the public internet. Clients do not have # to present client certificates by default. # [server:default] method = TLSv1 verify_certificate = yes require_certificate = no private_key = /etc/ser/tls/privkey.pem certificate = /etc/ser/tls/cert.pem ca_list = /etc/ser/tls/calist.pem # This is the default client domain, settings # in this domain will be used for all outgoing # TLS connections that do not match any other # client domain in this configuration file. # We require that servers present valid certificate. # [client:default] verify_certificate = yes require_certificate = yes # This is example server domain for TLS connections # received from the loopback interface. We allow # the use of SSLv2 and SSLv3 protocols here, we do # not require that clients present client certificates # but if they present it it must be valid. We also use # a special certificate and CA list for loopback # interface. # #[server:127.0.0.1:5061] #method = SSLv23 #verify_certificate = yes #require_certificate = no #private_key = local_key.pem #certificate = local_cert.pem #verify_depth = 3 #ca_list = local_ca.pem # Special settings for the iptel.org public SIP # server. We do not verify the certificate of the # server because it can be expired. The server # implements authentication using SSL client # certificates so configure the client certificate # that was given to use by iptel.org staff here. # #[client:195.37.77.101:5061] #verify_certificate = no #certificate = iptel_client.pem #private_key = iptel_key.pem #ca_list = iptel_ca.pem

2 3

sip-router select
by MÉSZÁROS Mihály 12 Aug '09

12 Aug '09

Hi! Can any of you explain how select framework is working? Where can i find any documentation about it. I am experiencing problem when i am try using it. Any help highly appreciated! Regards, Misi

2 4

[Kamailio-Users] HOWTO rewrite to: header
by alexander merkulov 12 Aug '09

12 Aug '09

here is correct reqwest and reqwest via kamailio is there any way to rewrite To: field in kamailio because now it nto work correct reqwest(asterisk) RECEIVING FROM: 69.70.173.195:5060 CANCEL sip:34249@193.110.78.12:8484 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.180:5060;branch=z9hG4bK4c97bd4a From: "Unknown" <sip:Unknown@voip1.bravotelecom.com<sip%3AUnknown(a)voip1.bravotelecom.com> >;tag=as366a0ba0 To: <sip:34249@193.110.78.12:8484> Call-ID: 322db75c71be4ba45a61c7666b93e6be(a)voip1.bravotelecom.com CSeq: 102 CANCEL User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 incorrect reqwest(multi-homed kamailio, asterisk originate to internal eth) RECEIVING FROM: 69.70.173.195:5060 CANCEL sip:34249@193.110.78.12:8484 SIP/2.0 Via: SIP/2.0/UDP 69.70.173.195;branch=z9hG4bK1b1b.3c42cea6.0 From: "Unknown" <sip:Unknown@69.70.173.195 <sip%3AUnknown(a)69.70.173.195> >;tag=as6075df60 Call-ID: 4d784fa972c4e9c9795032417f46cb26(a)voip1.bravotelecom.com To: <sip:34249@192.168.2.170 <sip%3A34249(a)192.168.2.170>> CSeq: 102 CANCEL Max-Forwards: 70 asterisk Content-Length: 0 -- Merkulov Alexander

6 21

[Kamailio-Users] kamailio auth with service provider
by Lance Evans 12 Aug '09

12 Aug '09

Hey Guys, Apparently Kamailio cannot authenticate with my service provider. Can this not be done with a sip trunk or peering!? if so how do i setup a trunk with kamailio!? and how do i setup peering?! Thanks

2 1

[Kamailio-Users] Fwd: Getting Error 477 while registering Softphones
by Daniel-Constantin Mierla 12 Aug '09

12 Aug '09

... fwd to list ... reply all button mismatch ... ---------- Forwarded message ---------- From: Daniel-Constantin Mierla <miconda(a)gmail.com> Date: Wed, Aug 12, 2009 at 8:27 AM Subject: Re: [Kamailio-Users] Getting Error 477 while registering Softphones To: Meftah Tayeb <tayeb.meftah(a)gmail.com> Hello, add: alias=tayeb.blogdns.com in your config file or use the domain module: http://kamailio.org/docs/modules/1.5.x/domain.html http://kamailio.org/dokuwiki/doku.php/core-cookbook:1.5.x#alias Cheers, Daniel On Wed, Aug 12, 2009 at 1:15 AM, Meftah Tayeb <tayeb.meftah(a)gmail.com>wrote: > hello, > i'm getting Error 477 while registering a Softphone from outside my domain > i added my domain, tayeb.blogdns.com to the domain name variable, > sip_domain in kamctlrc.conf > created the DB, started, and added user 1000 and 1001 > in registration: > for internal use, i use 192.168.1.3 (Kamailio IP Address) > and for external use i use my domain > for internal, is working corectly but while i register a external softphone > is getting Error 477 > what is this error message? > how i can fix it? > please try to help me, any help is welcome > > > __________ Information from ESET NOD32 Antivirus, version of virus > signature database 4327 (20090811) __________ > > The message was checked by ESET NOD32 Antivirus. > > http://www.eset.com > > > > _______________________________________________ > Kamailio (OpenSER) - Users mailing list > Users(a)lists.kamailio.org > http://lists.kamailio.org/cgi-bin/mailman/listinfo/users > http://lists.openser-project.org/cgi-bin/mailman/listinfo/users > -- Daniel-Constantin Mierla http://www.asipto.com -- Daniel-Constantin Mierla http://www.asipto.com

1 0

[Kamailio-Users] Getting Error 477 while registering Softphones
by Meftah Tayeb 11 Aug '09

11 Aug '09

hello, i'm getting Error 477 while registering a Softphone from outside my domain i added my domain, tayeb.blogdns.com to the domain name variable, sip_domain in kamctlrc.conf created the DB, started, and added user 1000 and 1001 in registration: for internal use, i use 192.168.1.3 (Kamailio IP Address) and for external use i use my domain for internal, is working corectly but while i register a external softphone is getting Error 477 what is this error message? how i can fix it? please try to help me, any help is welcome __________ Information from ESET NOD32 Antivirus, version of virus signature database 4327 (20090811) __________ The message was checked by ESET NOD32 Antivirus. http://www.eset.com

1 0

[Kamailio-Users] dialog info + Grandstreams = freezing
by David 11 Aug '09

11 Aug '09

Hello, I am having this problem on kamailio 1.5.2-tls compiled on Ubuntu 8.04, 1.5.1-tls ( compiled with no tls ) on Ubuntu 8.04 and with OpenSIPS 1.5.2-tls compilde on Ubuntu 8.04 I am trying to setup presence_dialoginfo with my Grandstreams, Snom and Linksys. I have a 4 phones on the server. 101 - Linksys SPA962 ( 6.1.5a ) 102 - Grandstream GXP2020 ( 1.2.1.4 ) 103 - Grandstream GXP2000 ( 1.2.1.4 ) 104 - Grandstream GXP2000 ( 1.1.6.46 ) 105 - Snom 360 ( 7.3.23 ) My Kamailio deals with registrations, NAT and BLF everything else is sent to one of two asterisk boxes. I use the dispatcher module for this. This means that when I call one extension to the other, both call legs from asterisk are going through Kamailio as separate calls. But to divide my customers, the usernames are different from the URL that the user types. For example the customer dials '101' but it is changed to testspace.101 when it comes back from asterisk. So Kamailio would have two calls in the event that 101 dials 102. sip:testspace.101@myserver to 102 ( this is sent to asterisk ) sip:testspace.101@myserver to testspace.102 ( this is coming back from asterisk ) Something is horribly wrong. I have the following problems : 1. If 102 calls 103, when 103 answers both phones hang for about 2 minutes 2. If 105 calls 101, 101 BLF comes back to the inactive state ( green on the Linksys and dark on the Snom), but the orange light stays on on the Snom and it thinks the call is still active ( the light is on, but the call is over ) 3. If any extension calls any extension and I try a call pickup, it fails. It looks like the Linksys is sending a NOTIFY to pickup the call ( I thought it was supposed to send an invite... ? ) Looking at the logs it looks like Kamailio is sending out so many NOTIFYs that it is crashing the Grandstreams, and causing the Snom to act funny. Here are some experts from my config file : root@kamailio-dev:/etc/kamailio# grep dialog * kamailio.cfg:# * avp value for dialogs is still not correct kamailio.cfg:loadmodule "dialog.so" kamailio.cfg:loadmodule "presence_dialoginfo.so" kamailio.cfg:loadmodule "pua_dialoginfo.so" kamailio.cfg:#modparam("pua_dialoginfo", "include_localremote", 0) kamailio.cfg:#modparam("pua_dialoginfo", "include_tags", 0) kamailio.cfg:#modparam("pua_dialoginfo", "include_callid", 0) kamailio.cfg:modparam("dialog", "dlg_flag", 4) kamailio.cfg:modparam("dialog", "db_mode", 1) kamailio.cfg:modparam("dialog", "timeout_avp", "$avp(i:10)") # I still haven't figured out how to set $avp(i:10) kamailio.cfg:modparam("pua_dialoginfo", "override_lifetime", 300) kamailio.cfg:modparam("presence_dialoginfo", "force_single_dialog", 1) kamailio.cfg:modparam("pua_dialoginfo", "caller_confirmed", 1) kamailio.cfg:modparam("auth_db|usrloc|acc|domain|avpops|presence|presence_xml|pua|dialog", "db_url", kamailio.cfg:# Flag 4 = Mark the current request for a dialog kamailio.cfg: # sequential request withing a dialog should the set flag looks like this : if ( ds_is_from_list() ) { xlog("L_INFO", "Coming from asterisk"); if ( is_method("INVITE")) { setflag(4); } } So the dialog flag is only set for the leg coming back from asterisk. When a notify comes in : if(is_method("NOTIFY") ) { if (! t_newtran()) { sl_reply_error(); exit; }; t_reply("200", "OK"); t_release(); exit ; } Publish and subscribe are like this : if( is_method("PUBLISH") || is_method("SUBSCRIBE") ) { route(5); exit; } route[5] { # absorb retransmissions if (! t_newtran()) { xlog("L_INFO", "Ignoring PUBLISH/SUBSCRIBE on retransmition - M=$rm RURI=$ru F=$fu T=$tu IP=$si ID=$ci\n"); sl_reply_error(); exit; }; append_to_reply("Contact: <sip:myserver.tld:5060>\r\n"); if(is_method("PUBLISH")) { handle_publish(); t_release(); } else if( is_method("SUBSCRIBE")) { handle_subscribe(); t_release(); } else { } exit; } I also have NAT checking for those telephones where stun isn't enough. Before I reach publish/subscribe/invite/notify, I also call setbflag() and sometimes call fix_nated_contact(). Additionnally, I have a block if code before my presence stuff if ( has_totag() && loose_route()) { t_relay(); }. If sip.conf:canreinvite=yes, the grandstreams freeze so long that the server times out, and the BLFs get really messed up. if sip:canreinvite=no the grandstreams only freeze for about 30 seconds. Obviously I am doing something wrong, but despite having searched google for endless hours, and poured over documentation, I can not seem to find what I did wrong. I would really appreciate if someone could shed light on my problem. I am having this problem on kamailio 1.5.2-tls compiled on Ubuntu 8.04, 1.5.1-tls ( compiled with no tls ) on Ubuntu 8.04 and with OpenSIPS 1.5.2-tls compilde on Ubuntu 8.04 Thanks, David

2 3

[Kamailio-Users] problem regarding openser+sip+raduis project
by Sanyog Kale 10 Aug '09

10 Aug '09

sir i am working on project Build SIP-based VOIP Service With RADIUS AAA Using Kamailio (OpenSER) And FreeRadius as per tutorial given by you. but the problem is 1.i am not understanding how to intialize modules for freeradius 2.while testing radius server where to make file named digest 3.the openser configuration which is given by you should be stored in which file? 4.and after all configurations done how to test all the parameters configured hoping for reply regards sanyog

4 3

[Kamailio-Users] Traffic parsing
by michel freiha 09 Aug '09

09 Aug '09

Hi all, I would like to ask you please how to configure kamailio in order to send signaling traffic to a specific gateway and rtp traffic to another gateway? Kindly note that I'm using media proxy for rtp and carrierroute for sending traffic to different gateways Regards

4 5

Jump to page:

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