Discussion:
[SR-Users] Kamailio + FreeRadius + MySQL Accounting STOP not updating
Satish Patel
2014-08-13 02:50:19 UTC
Permalink
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-Q0ErXNX1RuZx9BMjSy+***@public.gmane.org"
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-***@public.gmane.org1.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-Q0ErXNX1RuZx9BMjSy+***@public.gmane.org"
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-Q0ErXNX1RuZx9BMjSy+***@public.gmane.org"
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-***@public.gmane.org1.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-Q0ErXNX1RuZx9BMjSy+***@public.gmane.org"
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-Q0ErXNX1RuZx9BMjSy+***@public.gmane.org', nas '127.0.0.1']
Tue Aug 12 22:46:20 2014 : Info: [sql] stop packet with zero session
length. [user '2002-Q0ErXNX1RuZx9BMjSy+***@public.gmane.org', 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)
Daniel-Constantin Mierla
2014-08-13 08:04:54 UTC
Permalink
Hello,

from logs I see that the STOP record is sent by kamailio and received by
Radius. From there is only Radius config that needs to be fixed -- I
cannot help with that.

Also, as you write to mysql, it might be faster to just write to
database, unless you do other special handling inside radius.

Cheers,
Daniel
Post by Satish Patel
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
--
Daniel-Constantin Mierla
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Next Kamailio Advanced Trainings 2014 - http://www.asipto.com
Sep 22-25, Berlin, Germany ::: Oct 15-17, San Francisco, USA
Satish Patel
2014-08-13 13:44:55 UTC
Permalink
I don't get this like, can you explain what you trying to say?

Also, as you write to mysql, it might be faster to just write to database,
unless you do other special handling inside radius.
Post by Daniel-Constantin Mierla
Hello,
from logs I see that the STOP record is sent by kamailio and received by
Radius. From there is only Radius config that needs to be fixed -- I cannot
help with that.
Also, as you write to mysql, it might be faster to just write to database,
unless you do other special handling inside radius.
Cheers,
Daniel
Post by Satish Patel
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
--
Daniel-Constantin Mierla
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Next Kamailio Advanced Trainings 2014 - http://www.asipto.com
Sep 22-25, Berlin, Germany ::: Oct 15-17, San Francisco, USA
_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
Daniel-Constantin Mierla
2014-08-13 14:49:42 UTC
Permalink
Your logs looked like the values sent to radius server are ultimately
stored in a mysql server (by the radius server).

Not having a deep knowledge of the entire ecosystem there and if radius
server has other role than just being a proxy of those values between
kamailio and database, I suggested that maybe it is easier to write
directly to MySQL database from kamailio (via acc or sqlops modules).

Cheers,
Daniel
Post by Satish Patel
I don't get this like, can you explain what you trying to say?
Also, as you write to mysql, it might be faster to just write to
database, unless you do other special handling inside radius.
On Wed, Aug 13, 2014 at 4:04 AM, Daniel-Constantin Mierla
Hello,
from logs I see that the STOP record is sent by kamailio and
received by Radius. From there is only Radius config that needs to
be fixed -- I cannot help with that.
Also, as you write to mysql, it might be faster to just write to
database, unless you do other special handling inside radius.
Cheers,
Daniel
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
--
Daniel-Constantin Mierla
http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -
http://www.linkedin.com/in/miconda
Next Kamailio Advanced Trainings 2014 - http://www.asipto.com
Sep 22-25, Berlin, Germany ::: Oct 15-17, San Francisco, USA
_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Next Kamailio Advanced Trainings 2014 - http://www.asipto.com
Sep 22-25, Berlin, Germany ::: Oct 15-17, San Francisco, USA
Loading...