Problem with sql entry

[Miha Zoubek]

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<miha at 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.