Freeradius + MySQL wrong Timestamps
Satish Patel
satish.txt at gmail.com
Wed Aug 13 18:22:50 CEST 2014
I have install Kamailio 4.1 with MySQL database so all users stored in
MySQL (authentication), Later I have installed FreeRadius for accounting
only, Just accounting (Invite/Bye). In short MySQL for authentication and
FreeRadius for accounting ( CDRTool).
Problems: If i register user using SIP phone and call other SIP extension
then freeradius start accounting and insert entry in MySQL/radaccts tables
if i end call then it doesn't update END accounting ( Bye ). I have google
it everywhere but didn't get single clue so i hope i get something here
from you guys
-- kamailio.cfg ( default file i just add following radius section)
loadmodule "acc.so"
loadmodule "acc_radius.so"
...
...
# ------- FreeRadius Accounting -------
modparam("acc_radius", "radius_flag", 1)
modparam("acc_radius", "radius_missed_flag", 2)
modparam("acc", "log_flag", 1)
modparam("acc", "log_missed_flag", 1)
modparam("acc_radius", "service_type", 15)
modparam("acc_radius", "radius_config",
"/etc/radiusclient-ng/radiusclient.conf")
modparam("acc_radius", "radius_extra", "User-Name=$Au")
-- /etc/freeradius/sql.conf
sql {
driver = "rlm_sql_mysql"
server = "localhost"
login = "radius"
password = "radius"
radius_db = "radius"
sqltrace = no
sqltracefile = ${logdir}/sqltrace-%Y%m%d.log
num_sql_socks = 25
connect_failure_retry_delay = 60
accounting_start_query = "\
CALL insert_radacct_record( \
'radius', \
'%{Acct-Session-Id}', \
'%{Acct-Unique-Session-Id}', \
'%{Billing-Party}', \
'%{Billing-Party}', \
'%{SIP-Proxy-IP}', \
'%{NAS-Port}', \
FROM_UNIXTIME('%S'), \
'0', \
'0', \
'0', \
'0', \
'%{Called-Station-Id}', \
'%{Calling-Station-Id}', \
'%{Sip-Response-Code}', \
'%{Service-Type}', \
'%{ENUM-TLD}', \
'%{Framed-IP-Address}', \
UNIX_TIMESTAMP('%S') - '%{Event-Timestamp}', \
UNIX_TIMESTAMP('%S') - '%{Event-Timestamp}', \
'%{Sip-Response-Code}', \
'%{Sip-Method}', \
'%{Sip-Translated-Request-URI}', \
'%{Sip-To-Tag}', \
'%{Sip-From-Tag}', \
'%{Sip-RPId}', \
'%{Source-IP}', \
'%{Source-Port}', \
'%{Canonical-URI}', \
'', \
'', \
'%{Sip-Application-Type}', \
'%{User-Agent}', \
'%{From-Header}' \
)"
accounting_stop_query = "\
CALL update_radacct_record( \
'radius', \
FROM_UNIXTIME('%S'), \
UNIX_TIMESTAMP('%S') - '%{Event-Timestamp}', \
'', \
'%{X-RTP-Stat}', \
'%{Acct-Session-Id}', \
'%{Sip-To-Tag}', \
'%{Sip-From-Tag}' \
)"
-- Radius logs
rad_recv: Accounting-Request packet from host 127.0.0.1 port 36379, id=11,
length=152
Acct-Status-Type = Start
Service-Type = Sip-Session
Sip-Response-Code = 200
Sip-Method = Invite
Event-Timestamp = "Aug 12 2014 22:45:36 EDT"
Sip-From-Tag = "59eb1875"
Sip-To-Tag = "d443e36e"
Acct-Session-Id = "M2IwZTVkY2Y5YTU2ZjdmOTQ5NWMzYzI1NTU3MWMwYjQ."
User-Name = "2002 at 192.168.1.5"
NAS-Port = 5060
Acct-Delay-Time = 0
NAS-IP-Address = 127.0.0.1
Tue Aug 12 22:45:36 2014 : Info: # Executing section preacct from file
/etc/freeradius/sites-enabled/default
Tue Aug 12 22:45:36 2014 : Info: +- entering group preacct {...}
Tue Aug 12 22:45:36 2014 : Info: ++[preprocess] returns ok
Tue Aug 12 22:45:36 2014 : Info: [acct_unique] Hashing 'NAS-Port =
5060,Client-IP-Address = 127.0.0.1,NAS-IP-Address =
127.0.0.1,Acct-Session-Id =
"M2IwZTVkY2Y5YTU2ZjdmOTQ5NWMzYzI1NTU3MWMwYjQ.",User-Name = "2002 at 192.168.1.5
"'
Tue Aug 12 22:45:36 2014 : Info: [acct_unique] Acct-Unique-Session-ID =
"117c7740de62ba6c".
Tue Aug 12 22:45:36 2014 : Info: ++[acct_unique] returns ok
Tue Aug 12 22:45:36 2014 : Info: [suffix] Looking up realm "192.168.1.5"
for User-Name = "2002 at 192.168.1.5"
Tue Aug 12 22:45:36 2014 : Info: [suffix] No such realm "192.168.1.5"
Tue Aug 12 22:45:36 2014 : Info: ++[suffix] returns noop
Tue Aug 12 22:45:36 2014 : Info: ++[files] returns noop
Tue Aug 12 22:45:36 2014 : Info: # Executing section accounting from file
/etc/freeradius/radiusd.conf
Tue Aug 12 22:45:36 2014 : Info: +- entering group accounting {...}
Tue Aug 12 22:45:36 2014 : Info: [detail] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d ->
/var/log/freeradius/radacct/127.0.0.1/detail-20140812
Tue Aug 12 22:45:36 2014 : Info: [detail]
/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
/var/log/freeradius/radacct/127.0.0.1/detail-20140812
Tue Aug 12 22:45:36 2014 : Info: [detail] expand: %t -> Tue Aug 12
22:45:36 2014
Tue Aug 12 22:45:36 2014 : Info: ++[detail] returns ok
Tue Aug 12 22:45:36 2014 : Info: [sql] expand: CALL
insert_radacct_record( 'radius',
'%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',
'%{Billing-Party}', '%{Billing-Party}',
'%{SIP-Proxy-IP}', '%{NAS-Port}',
FROM_UNIXTIME('%S'), '0',
'0', '0', '0',
'%{Called-Station-Id}',
'%{Calling-Station-Id}',
'%{Sip-Response-Code}', '%{Service-Type}',
'%{ENUM-TLD}', '%{Framed-IP-Address}',
UNIX_TIMESTAMP('%S') - '%{Event-Timestamp}',
UNIX_TIMESTAMP('%S') - '%{Event-Timestamp}',
'%{Sip-Response-Code}', '%{Sip-Method}',
'%{Sip-Translated-Request-URI}',
'%{Sip-To-Tag}', '%{Sip-From-Tag}',
'%{Sip-RPId}', '%{Source-IP}'
Tue Aug 12 22:45:36 2014 : Debug: rlm_sql (sql): Reserving sql socket id: 24
Tue Aug 12 22:45:36 2014 : Debug: rlm_sql (sql): Released sql socket id: 24
Tue Aug 12 22:45:36 2014 : Info: ++[sql] returns ok
Sending Accounting-Response of id 11 to 127.0.0.1 port 36379
Tue Aug 12 22:45:36 2014 : Info: Finished request 0.
Tue Aug 12 22:45:36 2014 : Info: Cleaning up request 0 ID 11 with timestamp
+13
Tue Aug 12 22:45:36 2014 : Debug: Going to the next request
Tue Aug 12 22:45:36 2014 : Info: Ready to process requests.
rad_recv: Accounting-Request packet from host 127.0.0.1 port 35683, id=149,
length=152
Acct-Status-Type = Stop
Service-Type = Sip-Session
Sip-Response-Code = 200
Sip-Method = Bye
Event-Timestamp = "Aug 12 2014 22:46:20 EDT"
Sip-From-Tag = "59eb1875"
Sip-To-Tag = "d443e36e"
Acct-Session-Id = "M2IwZTVkY2Y5YTU2ZjdmOTQ5NWMzYzI1NTU3MWMwYjQ."
User-Name = "2002 at 192.168.1.5"
NAS-Port = 5060
Acct-Delay-Time = 0
NAS-IP-Address = 127.0.0.1
Tue Aug 12 22:46:20 2014 : Info: # Executing section preacct from file
/etc/freeradius/sites-enabled/default
Tue Aug 12 22:46:20 2014 : Info: +- entering group preacct {...}
Tue Aug 12 22:46:20 2014 : Info: ++[preprocess] returns ok
Tue Aug 12 22:46:20 2014 : Info: [acct_unique] Hashing 'NAS-Port =
5060,Client-IP-Address = 127.0.0.1,NAS-IP-Address =
127.0.0.1,Acct-Session-Id =
"M2IwZTVkY2Y5YTU2ZjdmOTQ5NWMzYzI1NTU3MWMwYjQ.",User-Name = "2002 at 192.168.1.5
"'
Tue Aug 12 22:46:20 2014 : Info: [acct_unique] Acct-Unique-Session-ID =
"117c7740de62ba6c".
Tue Aug 12 22:46:20 2014 : Info: ++[acct_unique] returns ok
Tue Aug 12 22:46:20 2014 : Info: [suffix] Looking up realm "192.168.1.5"
for User-Name = "2002 at 192.168.1.5"
Tue Aug 12 22:46:20 2014 : Info: [suffix] No such realm "192.168.1.5"
Tue Aug 12 22:46:20 2014 : Info: ++[suffix] returns noop
Tue Aug 12 22:46:20 2014 : Info: ++[files] returns noop
Tue Aug 12 22:46:20 2014 : Info: # Executing section accounting from file
/etc/freeradius/radiusd.conf
Tue Aug 12 22:46:20 2014 : Info: +- entering group accounting {...}
Tue Aug 12 22:46:20 2014 : Info: [detail] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d ->
/var/log/freeradius/radacct/127.0.0.1/detail-20140812
Tue Aug 12 22:46:20 2014 : Info: [detail]
/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
/var/log/freeradius/radacct/127.0.0.1/detail-20140812
Tue Aug 12 22:46:20 2014 : Info: [detail] expand: %t -> Tue Aug 12
22:46:20 2014
Tue Aug 12 22:46:20 2014 : Info: ++[detail] returns ok
Tue Aug 12 22:46:20 2014 : Info: [sql] expand: CALL
update_radacct_record( 'radius',
FROM_UNIXTIME('%S'), UNIX_TIMESTAMP('%S') -
'%{Event-Timestamp}', '',
'%{X-RTP-Stat}', '%{Acct-Session-Id}',
'%{Sip-To-Tag}', '%{Sip-From-Tag}' ) ->
CALL update_radacct_record( 'radius',
FROM_UNIXTIME('2014-08-12 22:46:20'),
UNIX_TIMESTAMP('2014-08-12 22:46:20') - 'Aug 12 2014 22:46:20
EDT', '', '',
'M2IwZTVkY2Y5YTU2ZjdmOTQ5NWMzYzI1NTU3MWMwYjQ.',
'd443e36e', '59eb1875' )
Tue Aug 12 22:46:20 2014 : Debug: rlm_sql (sql): Reserving sql socket id: 23
Tue Aug 12 22:46:20 2014 : Info: [sql] expand: stop packet with zero
session length. [user '%{User-Name}', nas '%{NAS-IP-Address}'] -> stop
packet with zero session length. [user '2002 at 192.168.1.5', nas '127.0.0.1']
Tue Aug 12 22:46:20 2014 : Info: [sql] stop packet with zero session
length. [user '2002 at 192.168.1.5', nas '127.0.0.1']
Tue Aug 12 22:46:20 2014 : Debug: rlm_sql (sql): Released sql socket id: 23
Tue Aug 12 22:46:20 2014 : Info: ++[sql] returns noop
Sending Accounting-Response of id 149 to 127.0.0.1 port 35683
Tue Aug 12 22:46:20 2014 : Info: Finished request 1.
Tue Aug 12 22:46:20 2014 : Info: Cleaning up request 1 ID 149 with
timestamp +57
Tue Aug 12 22:46:20 2014 : Debug: Going to the next request
Tue Aug 12 22:46:20 2014 : Info: Ready to process requests.
-- SQL tables ( Time is wired 1969 )
mysql> select * from radacct196912;
+-----------+-----------------
-----------------------------+------------------+----------+-------+--------------+-----------+-------------+---------------------+---------------------+-----------------+---------------+-------------------+------------------+-----------------+------------------+-----------------+------------------+--------------------+-------------+---------+-----------------+----------------+---------------+-----------+-----------------+----------+------------+-------------------------+---------------+--------------------+-----------+---------+---------------+----------+------------+--------------+-----------+-----------+---------------+------+-------+------------+-----------+-----------+---------------+------------+-----------+---------+
| RadAcctId | AcctSessionId |
AcctUniqueId | UserName | Realm | NASIPAddress | NASPortId |
NASPortType | AcctStartTime | AcctStopTime | AcctSessionTime |
AcctAuthentic | ConnectInfo_start | ConnectInfo_stop | AcctInputOctets |
AcctOutputOctets | CalledStationId | CallingStationId | AcctTerminateCause
| ServiceType | ENUMtld | FramedIPAddress | AcctStartDelay | AcctStopDelay
| SipMethod | SipResponseCode | SipToTag | SipFromTag |
SipTranslatedRequestURI | SipUserAgents | SipApplicationType | SipCodecs |
SipRPID | SipRPIDHeader | SourceIP | SourcePort | CanonicalURI | DelayTime
| Timestamp | DestinationId | Rate | Price | Normalized | BillingId |
MediaInfo | RTPStatistics | FromHeader | UserAgent | Contact |
+-----------+----------------------------------------------+------------------+----------+-------+--------------+-----------+-------------+---------------------+---------------------+-----------------+---------------+-------------------+------------------+-----------------+------------------+-----------------+------------------+--------------------+-------------+---------+-----------------+----------------+---------------+-----------+-----------------+----------+------------+-------------------------+---------------+--------------------+-----------+---------+---------------+----------+------------+--------------+-----------+-----------+---------------+------+-------+------------+-----------+-----------+---------------+------------+-----------+---------+
| 1 | Y2ExZjhkMTU4ODRmN2MwMGM1N2Q1Y2E5YTA5ZjAzNjg |
e46f9d0439141495 | | | | 5060
| | 1969-12-31 19:00:00 | 1969-12-31 19:00:00 | 0
| NULL | NULL | | 0
| 0 | | |
200 | Sip-Session | | |
1407883391 | 0 | Invite | 200 | 70cc9216 |
e2cb1f0c | | |
| | | | |
| | | 0 | | | NULL |
0 | | NULL | | |
| |
| 2 | MzYyY2JhM2Q3MzEyN2U1ODJkMDA1NGNiMTMzYmE0OTc |
aa9b8bcb6effa2c7 | | | | 5060
| | 1969-12-31 19:00:00 | 1969-12-31 19:00:00 | 0
| NULL | NULL | | 0
| 0 | | |
200 | Sip-Session | | |
0 | 0 | Invite | 200 | c6ea6056 | 407f047e
| | | |
| | | | |
| | 0 | | | NULL | 0
| | NULL | | | | |
| 3 | M2IwZTVkY2Y5YTU2ZjdmOTQ5NWMzYzI1NTU3MWMwYjQ. |
117c7740de62ba6c | | | | 5060
| | 1969-12-31 19:33:34 | 1969-12-31 19:33:34 | 0
| NULL | NULL | | 0
| 0 | | |
200 | Sip-Session | | |
1407897936 | 1407897980 | Invite | 200 | d443e36e |
59eb1875 | | |
| | | | |
| | | 0 | | | NULL |
0 | | NULL | | |
| |
+-----------+----------------------------------------------+------------------+----------+-------+--------------+-----------+-------------+---------------------+---------------------+-----------------+---------------+-------------------+------------------+-----------------+------------------+-----------------+------------------+--------------------+-------------+---------+-----------------+----------------+---------------+-----------+-----------------+----------+------------+-------------------------+---------------+--------------------+-----------+---------+---------------+----------+------------+--------------+-----------+-----------+---------------+------+-------+------------+-----------+-----------+---------------+------------+-----------+---------+
3 rows in set (0.00 sec)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20140813/2a596cd7/attachment-0001.html>
More information about the Freeradius-Users
mailing list