On Tue, Dec 20, 2011 at 3:55 PM, Miha Zoubek <miha@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. -- Fajar