rad_recv: Access-Request packet from host 127.0.0.1:52562, id=100, length=276 User-Name = "87001@fastervoip.com.br" Digest-Attributes = 0x0a073837303031 Digest-Attributes = 0x0113666173746572766f69702e636f6d2e6272 Digest-Attributes = 0x0232343865323331313030303030303030316139663732323835373863346362366631633431373338323539323238396130 Digest-Attributes = 0x04237369703a303135393131383437303140666173746572766f69702e636f6d2e6272 Digest-Attributes = 0x0308494e56495445 Digest-Response = "8bc0fd932079ff98448f762db47c4f3f" Service-Type = Sip-Session Sip-Uri-User = "000d6570-880e000a-66c47069-22b197ab@200.187.80.9" NAS-Port = 5060 NAS-IP-Address = 127.0.0.1 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 rlm_digest: Adding Auth-Type = DIGEST modcall[authorize]: module "digest" returns ok for request 0 users: Matched entry DEFAULT at line 153 users: Matched entry 87001@fastervoip.com.br at line 250 modcall[authorize]: module "files" returns ok for request 0 rlm_python [freeradius-cdrtool]: Entering the authorization phase ... rlm_python [freeradius-cdrtool]: Ignoring unsupported method None modcall[authorize]: module "python" returns ok for request 0 modcall: leaving group authorize (returns ok) for request 0 rad_check_password: Found Auth-Type Digest auth: type "digest" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0 rlm_digest: Converting Digest-Attributes to something sane... Digest-User-Name = "87001" Digest-Realm = "fastervoip.com.br" Digest-Nonce = "48e2311000000001a9f7228578c4cb6f1c417382592289a0" Digest-URI = "sip:01591184701@fastervoip.com.br" Digest-Method = "INVITE" A1 = 87001:fastervoip.com.br:135 A2 = INVITE:sip:01591184701@fastervoip.com.br KD = d283a82987a57cdf8eb9fb14cb169f02:48e2311000000001a9f7228578c4cb6f1c417382592289a0:8cb011c7d497b7c9f7522cad7c539b9b modcall[authenticate]: module "digest" returns ok for request 0 modcall: leaving group authenticate (returns ok) for request 0 radius_xlat: 'Authenticated' Sending Access-Accept of id 100 to 127.0.0.1 port 52562 Reply-Message = "Authenticated" SIP-AVP += "rpid:87001" Finished request 0 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Access-Request packet from host 127.0.0.1:41124, id=101, length=223 User-Name = "87001@fastervoip.com.br" Digest-Attributes = 0x0a073837303031 Digest-Attributes = 0x0113666173746572766f69702e636f6d2e6272 Digest-Attributes = 0x0232343865323331313430303030303030326434643233646563653130373333626139323166656635646231323932613965 Digest-Attributes = 0x04177369703a666173746572766f69702e636f6d2e6272 Digest-Attributes = 0x030a5245474953544552 Digest-Response = "5d64e39b4652263bcbb90b86bdf5f52b" Service-Type = Sip-Session Sip-Uri-User = "87001" NAS-Port = 5060 NAS-IP-Address = 127.0.0.1 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 modcall[authorize]: module "preprocess" returns ok for request 1 rlm_digest: Adding Auth-Type = DIGEST modcall[authorize]: module "digest" returns ok for request 1 users: Matched entry DEFAULT at line 153 users: Matched entry 87001@fastervoip.com.br at line 250 modcall[authorize]: module "files" returns ok for request 1 rlm_python [freeradius-cdrtool]: Entering the authorization phase ... rlm_python [freeradius-cdrtool]: Ignoring unsupported method None modcall[authorize]: module "python" returns ok for request 1 modcall: leaving group authorize (returns ok) for request 1 rad_check_password: Found Auth-Type Digest auth: type "digest" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 1 rlm_digest: Converting Digest-Attributes to something sane... Digest-User-Name = "87001" Digest-Realm = "fastervoip.com.br" Digest-Nonce = "48e2311400000002d4d23dece10733ba921fef5db1292a9e" Digest-URI = "sip:fastervoip.com.br" Digest-Method = "REGISTER" A1 = 87001:fastervoip.com.br:135 A2 = REGISTER:sip:fastervoip.com.br KD = d283a82987a57cdf8eb9fb14cb169f02:48e2311400000002d4d23dece10733ba921fef5db1292a9e:743baeb428df4b5f56684da06344e31a modcall[authenticate]: module "digest" returns ok for request 1 modcall: leaving group authenticate (returns ok) for request 1 radius_xlat: 'Authenticated' Sending Access-Accept of id 101 to 127.0.0.1 port 41124 Reply-Message = "Authenticated" SIP-AVP += "rpid:87001" Finished request 1 Going to the next request --- Walking the entire request list --- Waking up in 3 seconds... --- Walking the entire request list --- Cleaning up request 0 ID 100 with timestamp 48e22fe5 Waking up in 3 seconds... --- Walking the entire request list --- Cleaning up request 1 ID 101 with timestamp 48e22fe8 Nothing to do. Sleeping until we see a request. rad_recv: Accounting-Request packet from host 127.0.0.1:47462, id=103, length=490 Acct-Status-Type = Start Service-Type = Sip-Session Sip-Response-Code = 200 Sip-Method = Invite X-Ascend-Bridge = 0x0230e24860ae2c087c7195b75c7295b7647295b708db9abf4e3d95b748f7a0b577f2170884901b080a Sip-From-Tag = "000d6570880e00203b622075-14fec910" Sip-To-Tag = "as2e1c2a80" Acct-Session-Id = "000d6570-880e000a-66c47069-22b197ab@200.187.80.9" User-Name = "87001@fastervoip.com.br" Calling-Station-Id = "sip:87001@fastervoip.com.br" Called-Station-Id = "sip:01591184701@fastervoip.com.br" Sip-Translated-Request-URI = "sip:01591184701@200.187.80.17:5060;transport=udp" Sip-Rpid = "87001" Source-IP = "200.187.80.9" Source-Port = "5070" Acct-Authentic = 49 SIP-Proxy-IP = "127.0.0.1" Canonical-URI = "sip:01591184701@fastervoip.com.br" Billing-Party = "87001@fastervoip.com.br" Contact = "" NAS-Port = 5060 Acct-Delay-Time = 0 NAS-IP-Address = 127.0.0.1 Processing the preacct section of radiusd.conf modcall: entering group preacct for request 3 modcall[preacct]: module "preprocess" returns noop for request 3 rlm_acct_unique: Hashing 'NAS-Port = 5060,Client-IP-Address = 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-Session-Id = "000d6570-880e000a-66c47069-22b197ab@200.187.80.9",User-Name = "87001@fastervoip.com.br"' rlm_acct_unique: Acct-Unique-Session-ID = "ff702e02176d5004". modcall[preacct]: module "acct_unique" returns ok for request 3 rlm_realm: Looking up realm "fastervoip.com.br" for User-Name = "87001@fastervoip.com.br" rlm_realm: No such realm "fastervoip.com.br" modcall[preacct]: module "suffix" returns noop for request 3 modcall[preacct]: module "files" returns noop for request 3 modcall: leaving group preacct (returns ok) for request 3 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 3 radius_xlat: '/var/log/radacct/127.0.0.1/detail-20080930' rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/127.0.0.1/detail-20080930 modcall[accounting]: module "detail" returns ok for request 3 modcall[accounting]: module "unix" returns ok for request 3 radius_xlat: '/var/log/radutmp' radius_xlat: '87001@fastervoip.com.br' modcall[accounting]: module "radutmp" returns ok for request 3 radius_xlat: ' CALL insert_radacct_record( 'radius', '000d6570-880e000a-66c47069-22b197ab@200.187.80.9', 'ff702e02176d5004', '87001@fastervoip.com.br', '87001@fastervoip.com.br', '127.0.0.1', '5060', '2008-09-30 10:56:18', '0', '0', '0', '0', 'sip:01591184701@fastervoip.com.br', 'sip:87001@fastervoip.com.br', '200', 'Sip-Session', '', '', '0', '0', '200', 'Invite', 'sip:01591184701@200.187.80.17:5060=3Btransport=3Dudp', 'as2e1c2a80', '000d6570880e00203b622075-14fec910', '87001', '200.187.80.9', '5070', 'sip:01591184701@fastervoip.com.br', '', '' )' rlm_sql (sql): Reserving sql socket id: 24 rlm_sql (sql): Released sql socket id: 24 modcall[accounting]: module "sql" returns ok for request 3 rlm_python [freeradius-cdrtool]: Entering accounting section rlm_python [freeradius-cdrtool]: Got the following params: (('Acct-Status-Type', 'Start'), ('Service-Type', 'Sip-Session'), ('Sip-Response-Code', '200'), ('Sip-Method', 'Invite'), ('X-Ascend-Bridge', '0x0230e24860ae2c087c7195b75c7295b7647295b708db9abf4e3d95b748f7a0b577f2170884901b080a'), ('Sip-From-Tag', '"000d6570880e00203b622075-14fec910"'), ('Sip-To-Tag', '"as2e1c2a80"'), ('Acct-Session-Id', '"000d6570-880e000a-66c47069-22b197ab@200.187.80.9"'), ('User-Name', '"87001@fastervoip.com.br"'), ('Calling-Station-Id', '"sip:87001@fastervoip.com.br"'), ('Called-Station-Id', '"sip:01591184701@fastervoip.com.br"'), ('Sip-Translated-Request-URI', '"sip:01591184701@200.187.80.17:5060;transport=udp"'), ('Sip-Rpid', '"87001"'), ('Source-IP', '"200.187.80.9"'), ('Source-Port', '"5070"'), ('Acct-Authentic', '49'), ('SIP-Proxy-IP', '"127.0.0.1"'), ('Canonical-URI', '"sip:01591184701@fastervoip.com.br"'), ('Billing-Party', '"87001@fastervoip.com.br"'), ('Contact', '""'), ('NAS-Port', '5060'), ('Acct-Delay-Time', '0'), ('NAS-IP-Address', '127.0.0.1'), ('Client-IP-Address', '127.0.0.1'), ('Acct-Unique-Session-Id', '"ff702e02176d5004"')) rlm_python [freeradius-cdrtool]: Extracted atribute with value rlm_python [freeradius-cdrtool]: Extracted atribute with value <49> rlm_python [freeradius-cdrtool]: Extracted atribute with value <000d6570-880e000a-66c47069-22b197ab@200.187.80.9> rlm_python [freeradius-cdrtool]: Extracted atribute with value <87001@fastervoip.com.br> rlm_python [freeradius-cdrtool]: Extracted atribute with value rlm_python [freeradius-cdrtool]: Extracted atribute with value rlm_python [freeradius-cdrtool]: Extracted atribute with value <127.0.0.1> rlm_python [freeradius-cdrtool]: will cache 87001@fastervoip.com.br,sip:01591184701@fastervoip.com.br,127.0.0.1,1222782978.16 with key 000d6570-880e000a-66c47069-22b197ab@200.187.80.9 rlm_python [freeradius-cdrtool]: init info for call_start saved. modcall[accounting]: module "python" returns ok for request 3 modcall: leaving group accounting (returns ok) for request 3 Sending Accounting-Response of id 103 to 127.0.0.1 port 47462 Finished request 3 Going to the next request --- Walking the entire request list --- Waking up in 3 seconds... rad_recv: Accounting-Request packet from host 127.0.0.1:42525, id=104, length=411 Acct-Status-Type = Stop Service-Type = Sip-Session Sip-Response-Code = 200 Sip-Method = Bye X-Ascend-Bridge = 0x1630e24868862d087c7195b75c7295b7647295b708db9abf4e3d95b748f7a0b563f217087cbc1b080a Sip-From-Tag = "000d6570880e00203b622075-14fec910" Sip-To-Tag = "as2e1c2a80" Acct-Session-Id = "000d6570-880e000a-66c47069-22b197ab@200.187.80.9" User-Name = "87001@fastervoip.com.br" Calling-Station-Id = "sip:87001@fastervoip.com.br" Called-Station-Id = "sip:01591184701@fastervoip.com.br" Sip-Translated-Request-URI = "sip:01591184701@200.187.80.17:5060;ftag=000d6570880e00203b622075-14fec910" Source-IP = "200.187.80.9" Source-Port = "5070" Billing-Party = "87001@fastervoip.com.br" NAS-Port = 5060 Acct-Delay-Time = 0 NAS-IP-Address = 127.0.0.1 Processing the preacct section of radiusd.conf modcall: entering group preacct for request 4 modcall[preacct]: module "preprocess" returns noop for request 4 rlm_acct_unique: Hashing 'NAS-Port = 5060,Client-IP-Address = 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-Session-Id = "000d6570-880e000a-66c47069-22b197ab@200.187.80.9",User-Name = "87001@fastervoip.com.br"' rlm_acct_unique: Acct-Unique-Session-ID = "ff702e02176d5004". modcall[preacct]: module "acct_unique" returns ok for request 4 rlm_realm: Looking up realm "fastervoip.com.br" for User-Name = "87001@fastervoip.com.br" rlm_realm: No such realm "fastervoip.com.br" modcall[preacct]: module "suffix" returns noop for request 4 modcall[preacct]: module "files" returns noop for request 4 modcall: leaving group preacct (returns ok) for request 4 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 4 radius_xlat: '/var/log/radacct/127.0.0.1/detail-20080930' rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/127.0.0.1/detail-20080930 modcall[accounting]: module "detail" returns ok for request 4 modcall[accounting]: module "unix" returns ok for request 4 radius_xlat: '/var/log/radutmp' radius_xlat: '87001@fastervoip.com.br' modcall[accounting]: module "radutmp" returns ok for request 4 radius_xlat: ' CALL update_radacct_record( 'radius', '2008-09-30 10:56:38', '0', '', '', '000d6570-880e000a-66c47069-22b197ab@200.187.80.9', 'as2e1c2a80', '000d6570880e00203b622075-14fec910' )' rlm_sql (sql): Reserving sql socket id: 23 radius_xlat: '' rlm_sql (sql): Released sql socket id: 23 modcall[accounting]: module "sql" returns ok for request 4 rlm_python [freeradius-cdrtool]: Entering accounting section rlm_python [freeradius-cdrtool]: Got the following params: (('Acct-Status-Type', 'Stop'), ('Service-Type', 'Sip-Session'), ('Sip-Response-Code', '200'), ('Sip-Method', 'Bye'), ('X-Ascend-Bridge', '0x1630e24868862d087c7195b75c7295b7647295b708db9abf4e3d95b748f7a0b563f217087cbc1b080a'), ('Sip-From-Tag', '"000d6570880e00203b622075-14fec910"'), ('Sip-To-Tag', '"as2e1c2a80"'), ('Acct-Session-Id', '"000d6570-880e000a-66c47069-22b197ab@200.187.80.9"'), ('User-Name', '"87001@fastervoip.com.br"'), ('Calling-Station-Id', '"sip:87001@fastervoip.com.br"'), ('Called-Station-Id', '"sip:01591184701@fastervoip.com.br"'), ('Sip-Translated-Request-URI', '"sip:01591184701@200.187.80.17:5060;ftag=000d6570880e00203b622075-14fec910"'), ('Source-IP', '"200.187.80.9"'), ('Source-Port', '"5070"'), ('Billing-Party', '"87001@fastervoip.com.br"'), ('NAS-Port', '5060'), ('Acct-Delay-Time', '0'), ('NAS-IP-Address', '127.0.0.1'), ('Client-IP-Address', '127.0.0.1'), ('Acct-Unique-Session-Id', '"ff702e02176d5004"')) rlm_python [freeradius-cdrtool]: Extracted atribute with value rlm_python [freeradius-cdrtool]: Extracted atribute with value <000d6570-880e000a-66c47069-22b197ab@200.187.80.9> rlm_python [freeradius-cdrtool]: Cannot understand answer from CDRTool: Session 000d6570-880e000a-66c47069-22b197ab@200.187.80.9 does not exist modcall[accounting]: module "python" returns fail for request 4 modcall: leaving group accounting (returns fail) for request 4 Finished request 4 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds...