<div dir="ltr">On Thu, Jul 24, 2008 at 10:01 PM, Phil Mayers <<a href="mailto:p.mayers@imperial.ac.uk">p.mayers@imperial.ac.uk</a>> wrote:<br><div class="gmail_quote"><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
Khalukhin Alexander wrote:<br>
<blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;"><div class="Ih2E3d">
Hi all! I'm using 'sql' module in accounting to log all the radius packets from remote radius client (cisco 2600). I've investigated, that accounting packets are received in right order ("Start" then "Stop"), but putted into DB log table in wrong order ("Stop" then "Start"). Here are the logs:<br>

<br>
============ /var/log/radius/radacct/x.y.z.a/detail-20080724 =================<br>
<br>
Thu Jul 24 09:48:26 2008<br>
        Acct-Session-Id = "57000000000008F7"<br>
        Calling-Station-Id = "4959636156"<br>
        Called-Station-Id = "74955891937"<br></div>
        Cisco-AVPair = "call-id=<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>"<div class="Ih2E3d">
<br>
        h323-setup-time = ".09:48:16.191 MSD Thu Jul 24 2008"<br></div>
        h323-gw-id = "<a href="http://voice5.di-net.ru" target="_blank">voice5.di-net.ru</a> <<a href="http://voice5.di-net.ru" target="_blank">http://voice5.di-net.ru</a>>"<div class="Ih2E3d"><br>
        h323-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"<br>
        h323-call-origin = "originate"<br>
        h323-call-type = "VoIP"<br>
        Cisco-AVPair = "h323-incoming-conf-id=F0FF23AA 587A11DD B8009A2D 9B5B4497"<br>
        Cisco-AVPair = "subscriber=Unknown"<br>
        Cisco-AVPair = "session-protocol=sipv2"<br>
        Cisco-AVPair = "gw-rxd-cdn=ton:0,npi:0,#:74955891937"<br>
        User-Name = "4959636156"<br>
        Cisco-AVPair = "connect-progress=Call Up"<br>
        Acct-Status-Type = *Start*<br>
        Service-Type = Login-User<br></div>
        NAS-IP-Address = <a href="http://89.208.190.6" target="_blank">89.208.190.6</a> <<a href="http://89.208.190.6" target="_blank">http://89.208.190.6</a>><br>
        Acct-Delay-Time = 0<br>
        call-id = "<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>"<div class="Ih2E3d">
<br>
        h323-incoming-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"<br>
        subscriber = "Unknown"<br>
        session-protocol = "sipv2"<br>
        gw-rxd-cdn = "ton:0,npi:0,#:74955891937"<br></div>
        Client-IP-Address = <a href="http://89.208.190.6" target="_blank">89.208.190.6</a> <<a href="http://89.208.190.6" target="_blank">http://89.208.190.6</a>><div class="Ih2E3d"><br>
        Acct-Unique-Session-Id = "51b334248c332b3b"<br>
        Timestamp = 1216878506<br>
<br>
Thu Jul 24 09:48:27 2008<br>
        Acct-Session-Id = "57000000000008F7"<br>
        Calling-Station-Id = "4959636156"<br>
        Called-Station-Id = "74955891937"<br></div>
        Cisco-AVPair = "call-id=<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>"<div class="Ih2E3d">
<br>
        h323-setup-time = ".09:48:16.191 MSD Thu Jul 24 2008"<br></div>
        h323-gw-id = "<a href="http://voice5.di-net.ru" target="_blank">voice5.di-net.ru</a> <<a href="http://voice5.di-net.ru" target="_blank">http://voice5.di-net.ru</a>>"<div class="Ih2E3d"><br>
        h323-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"<br>
        h323-call-origin = "originate"<br>
        h323-call-type = "VoIP"<br>
        Cisco-AVPair = "h323-incoming-conf-id=F0FF23AA 587A11DD B8009A2D 9B5B4497"<br>
        Cisco-AVPair = "subscriber=Unknown"<br>
        Cisco-AVPair = "session-protocol=sipv2"<br>
        Cisco-AVPair = "gw-rxd-cdn=ton:0,npi:0,#:74955891937"<br>
        Acct-Input-Octets = 0<br>
        Acct-Output-Octets = 0<br>
        Acct-Input-Packets = 0<br>
        Acct-Output-Packets = 0<br>
        Acct-Session-Time = 0<br>
        h323-connect-time = ".09:48:16.371 MSD Thu Jul 24 2008"<br>
        h323-disconnect-time = ".09:48:16.371 MSD Thu Jul 24 2008"<br>
        h323-disconnect-cause = "1"<br></div>
        h323-remote-address = "<a href="http://89.208.190.4" target="_blank">89.208.190.4</a> <<a href="http://89.208.190.4" target="_blank">http://89.208.190.4</a>>"<div class="Ih2E3d"><br>
        Cisco-AVPair = "release-source=4"<br>
        h323-voice-quality = "0"<br>
        Cisco-AVPair = "gw-rxd-cgn=ton:0,npi:0,pi:1,si:0,#:4959636156"<br>
        Cisco-AVPair = "gw-final-xlated-cdn=ton:0,npi:0,#:74955891937"<br>
        Cisco-AVPair = "gw-final-xlated-cgn=ton:0,npi:0,pi:1,si:0,#:4959636156"<br>
        User-Name = "4959636156"<br>
        Acct-Status-Type = *Stop*<br>
        Service-Type = Login-User<br></div>
        NAS-IP-Address = <a href="http://89.208.190.6" target="_blank">89.208.190.6</a> <<a href="http://89.208.190.6" target="_blank">http://89.208.190.6</a>><br>
        Acct-Delay-Time = 0<br>
        call-id = "<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>"<div class="Ih2E3d">
<br>
        h323-incoming-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"<br>
        subscriber = "Unknown"<br>
        session-protocol = "sipv2"<br>
        gw-rxd-cdn = "ton:0,npi:0,#:74955891937"<br>
        release-source = "4"<br>
        gw-rxd-cgn = "ton:0,npi:0,pi:1,si:0,#:4959636156"<br>
        gw-final-xlated-cdn = "ton:0,npi:0,#:74955891937"<br>
        gw-final-xlated-cgn = "ton:0,npi:0,pi:1,si:0,#:4959636156"<br></div>
        Client-IP-Address = <a href="http://89.208.190.6" target="_blank">89.208.190.6</a> <<a href="http://89.208.190.6" target="_blank">http://89.208.190.6</a>><div class="Ih2E3d"><br>
        Acct-Unique-Session-Id = "51b334248c332b3b"<br>
        Timestamp = 1216878507<br>
<br>
=========== /var/log/radius/sqltrace.sql ================<br>
<br></div>
INSERT INTO ACC ("ACCT-STATUS-TYPE", "NAS-IP-ADDRESS", "H323-CALL-ORIGIN", "CALLED-STATION-ID", "CALLING-STATION-ID", "ACCT-SESSION-ID", "CALL-ID", "SIP-TO-TAG", "SIP-FROM-TAG", "SIP-TRANSLATED-REQUEST-URI", "USER-NAME", "SIP-SOURCE-IP-ADDRESS", "SIP-SOURCE-PORT", "ACCT-SESSION-TIME", "H323-CONNECT-TIME", "H323-SETUP-TIME", "H323-DISCONNECT-TIME", "H323-DISCONNECT-CAUSE", "IPHOP-COUNT", "IPHOP1", "IPHOP2", "IPHOP3", "H323-CONF-ID") VALUES ('*Start*', '<a href="http://89.208.190.6" target="_blank">89.208.190.6</a> <<a href="http://89.208.190.6" target="_blank">http://89.208.190.6</a>>', 'originate', '74955891937', '4959636156', '57000000000008F7', '<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>', '', '', '', '4959636156', '', '', '', '', '.09:48:16.191 MSD Thu Jul 24 2008', '', '', '', '', '', '', 'F0FF23AA 587A11DD B8009A2D 9B5B4497');<br>

<br>
INSERT INTO ACC ("ACCT-STATUS-TYPE", "NAS-IP-ADDRESS", "H323-CALL-ORIGIN", "CALLED-STATION-ID", "CALLING-STATION-ID", "ACCT-SESSION-ID", "CALL-ID", "SIP-TO-TAG", "SIP-FROM-TAG", "SIP-TRANSLATED-REQUEST-URI", "USER-NAME", "SIP-SOURCE-IP-ADDRESS", "SIP-SOURCE-PORT", "ACCT-SESSION-TIME", "H323-CONNECT-TIME", "H323-SETUP-TIME", "H323-DISCONNECT-TIME", "H323-DISCONNECT-CAUSE", "IPHOP-COUNT", "IPHOP1", "IPHOP2", "IPHOP3", "H323-CONF-ID") VALUES ('*Stop*', '<a href="http://89.208.190.6" target="_blank">89.208.190.6</a> <<a href="http://89.208.190.6" target="_blank">http://89.208.190.6</a>>', 'originate', '74955891937', '4959636156', '57000000000008F7', '<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>', '', '', '', '4959636156', '', '', '0', '.09:48:16.371 MSD Thu Jul 24 2008', '.09:48:16.191 MSD Thu Jul 24 2008', '.09:48:16.371 MSD Thu Jul 24 2008', '1', '', '', '', '', 'F0FF23AA 587A11DD B8009A2D 9B5B4497');<div class="Ih2E3d">
<br>
<br>
========== Data from DB acc table ===========<br>
<br>
        ID ACCT-STATUS-TYPE   CALL-ID                                               H323-CONF-ID                       ---------- ------------------ ----------------------------------------------------- ------------------------------------<br>
</div>
   1134861 Stop               <a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>      F0FF23AA 587A11DD B8009A2D 9B5B4497<br>

   1134862 Start              <a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a> <mailto:<a href="mailto:F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6" target="_blank">F217BA24-587A11DD-83D18BF5-E033E9AB@89.208.190.6</a>>      F0FF23AA 587A11DD B8009A2D 9B5B4497<div class="Ih2E3d">
<br>
<br>
ID here is autoincremented primary key (taked from sequence - DB is Oracle 10gR2). As you can see, right order of packets ("Start" then "Stop") is violated. I need them to appear in database  in right order. This error happens once-twice per day, in hours of medium load average. Maybe I should use only one database connection in oracle_sql (now num_sql_socks=5 in /etc/raddb/oraclesql.conf)? Or what it can be? Give me a clue, please<br>

</div></blockquote>
<br>
That's an oracle problem, nothing to do with FreeRadius. Either write your SQL queries to sort by the acctstarttime/acctstoptime fields or make oracle "work right"<br>
<br>
FWIW Postgres does exactly the same with "serial" keys; they're not guaranteed to be monotonically increasing if contending threads are talking to the database.<br>
<br>
Using one SQL connection would probably work but will be slow.<br>
-<br>
List info/subscribe/unsubscribe? See <a href="http://www.freeradius.org/list/users.html" target="_blank">http://www.freeradius.org/list/users.html</a><br>
</blockquote></div><br><br>Due to <a href="http://download.oracle.com/docs/cd/B19306_01/server.102/b14220/schema.htm#sthref883">http://download.oracle.com/docs/cd/B19306_01/server.102/b14220/schema.htm#sthref883</a>:<br>

<i>Therefore, the sequence generator reduces serialization where the
statements of two transactions must generate sequential numbers at the
same time.<br>
<br>
</i>It's seems you're right in case, if freeradius using more, than one
connection (isolated transaction) to oracle database (that's my case). I should have
known better this feature. Thanks for help!</div>