Thanks @Fajar,

I missed two different Acct-Session-Id. This the main reason for this. I fill chack why nas is sending different Acct-Session-ID


regards,
Miha


On 12/20/2011 10:20 AM, Fajar A. Nugraha wrote:
On Tue, Dec 20, 2011 at 3:55 PM, Miha Zoubek<m...@softnet.si>  wrote:
Hi,

please help me out why I am getting two entries in mysql table (radacct) for
outgoing call. If the call is answered I get two entries and one entry if
the call is not answered (this is ok).

Reason that I am asking this is that I do not see that my NAS is sending two
start packet and to stop packet for answered call (you can see below).

Please help me out understand why radius add two entries for stop packet if
only one is send from NAS.
First of all, if you're going to trim the debug log anyway, make sure
you include debug from a full sesssion to make it easier to diagnose.

2. Call is answered.
3142.992787 xxx.xxx.xxx.xxx ->  yyy.yyy.yyy.yyy RADIUS Accounting-Request(4)
(id=195, l=265)
3142.994570 yyy.yyy.yyy.yyy ->  xxx.xxx.xxx.xxx RADIUS Accounting-Response(5)
(id=195, l=20)
those two above most likely belong to a previous session. Accounting
usually comes after Access-Request. So I don't think you need to
include those. UNLESS your NAS is doing something funny, and it REALLY
sends Accounting - Access Request - Accounting for a session.

rad_recv: Accounting-Request packet from host xxx.xxx.xxx.xxx port 48752,
id=198, length=265
         Acct-Status-Type = Start
         Acct-Session-Id = "d446d20a-6d1c-4ffd-9b59-1aedbf63b74c"
I'd note Acct-Session-Id lines ...

rad_recv: Accounting-Request packet from host xxx.xxx.xxx.xxx port 35569,
id=200, length=401
         Acct-Status-Type = Stop
         Acct-Session-Id = "68507972-f9d9-46c7-bf22-59020602ffe2"
... and compare it with the next one. That's a different
Acct-Session-Id, so it's two different sessions.

Are you SURE you have two entries in radacct with Acct-Session-Id =
"68507972-f9d9-46c7-bf22-59020602ffe2"?

[sql]   expand:            UPDATE radacct SET           acctstarttime   =
'%{Freeswitch-Callanswerdate}',           acctstoptime       =
'%S',              acctsessiontime    = '%{Acct-Session-Time}',
acctinputoctets    = '%{%{Acct-Input-Gigawords}:-0}'<<  32
|
'%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   =
'%{%{Acct-Output-Gigawords}:-0}'<<  32 |
'%{%{Acct-Output-Octets}:-0}',              acctterminatecause =
'%{Acct-Terminate-Cause}',              acctstopdelay      =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   =
'%{Connect-Info}'           WHERE acctsessionid   =
'%{Acct-Session-Id}'           AND username          =
'%{SQL-User-Name}'           AND nasipaddress      = '%{NAS-IP-Address}'
->             UPDATE radacct SET               acctstarttime   =
'2011-12-20T09:49:30.669405=2B0100',      acctstoptime       = '2011-12-20
09:49:49',              acctsessiontime    = '3',
acctinputoctets    = '0'<<
hmmm ... that query doesn't look right.

"
UPDATE radacct SET               acctstarttime   =
'2011-12-20T09:49:30.669405=2B0100',      acctstoptime       = '2011-12-20
09:49:49',              acctsessiontime    = '3',
acctinputoctets    = '0'<<
"

seriously? Are you sure you didn't mess up the query while editing it
manually? Or was it copy-and-paste error?
Even acctstarttime looks wrong.


[sql]   expand:            INSERT INTO radacct             (acctsessionid,
acctuniqueid, username,              realm, nasipaddress,
nasportid,              nasporttype, acctstarttime,
acctstoptime,              acctsessiontime, acctauthentic,
connectinfo_start,              connectinfo_stop, acctinputoctets,
acctoutputoctets,              calledstationid, callingstationid,
acctterminatecause,              servicetype, framedprotocol,
framedipaddress,              acctstartdelay, acctstopdelay)
VALUES             ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}',              DATE_SUB('%S',                  INTERVAL
(%{%{Acct-Session-Time}:-0} +                  %{%{Acct-Delay-Time}:-0})
SECOND),              '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}',
'',              '%{Connect-Info}',
'%{%{Acct-Input-Gigawords}:-0}'<<  32 |              '%{%{Acct-Inpu
Same thing here. It should print what the actual sql statement executed

My best guess so far:
- the double lines you see are from different session (i.e. different
Acct-Session-Id). If so, the NAS sends two different accounting
request. Ask the NAS why it does that. OR
- you edit the default query and broke it.

In any case:
- check whether the records have the same Acct-Session-Id
- check that your queries are OK. Get a DBA to help you if necessary.
- get the full sql query executed somehow. It should be available in
the debug log, but the db might be able to provide it as well (e.g.
http://dev.mysql.com/doc/refman/5.5/en/query-log.html). Again, get a
DBA to help you if necessary.



--
Best regards / Lep Pozdrav
Miha Zoubek
Softnet d.o.o.

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

Reply via email to