SQL module mixes up packets when putting it to database
Phil Mayers
p.mayers at imperial.ac.uk
Thu Jul 24 20:01:03 CEST 2008
Khalukhin Alexander wrote:
> 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:
>
> ============ /var/log/radius/radacct/x.y.z.a/detail-20080724
> =================
>
> Thu Jul 24 09:48:26 2008
> Acct-Session-Id = "57000000000008F7"
> Calling-Station-Id = "4959636156"
> Called-Station-Id = "74955891937"
> Cisco-AVPair =
> "call-id=F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6>"
> h323-setup-time = ".09:48:16.191 MSD Thu Jul 24 2008"
> h323-gw-id = "voice5.di-net.ru <http://voice5.di-net.ru>"
> h323-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"
> h323-call-origin = "originate"
> h323-call-type = "VoIP"
> Cisco-AVPair = "h323-incoming-conf-id=F0FF23AA 587A11DD B8009A2D
> 9B5B4497"
> Cisco-AVPair = "subscriber=Unknown"
> Cisco-AVPair = "session-protocol=sipv2"
> Cisco-AVPair = "gw-rxd-cdn=ton:0,npi:0,#:74955891937"
> User-Name = "4959636156"
> Cisco-AVPair = "connect-progress=Call Up"
> Acct-Status-Type = *Start*
> Service-Type = Login-User
> NAS-IP-Address = 89.208.190.6 <http://89.208.190.6>
> Acct-Delay-Time = 0
> call-id = "F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6>"
> h323-incoming-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"
> subscriber = "Unknown"
> session-protocol = "sipv2"
> gw-rxd-cdn = "ton:0,npi:0,#:74955891937"
> Client-IP-Address = 89.208.190.6 <http://89.208.190.6>
> Acct-Unique-Session-Id = "51b334248c332b3b"
> Timestamp = 1216878506
>
> Thu Jul 24 09:48:27 2008
> Acct-Session-Id = "57000000000008F7"
> Calling-Station-Id = "4959636156"
> Called-Station-Id = "74955891937"
> Cisco-AVPair =
> "call-id=F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6>"
> h323-setup-time = ".09:48:16.191 MSD Thu Jul 24 2008"
> h323-gw-id = "voice5.di-net.ru <http://voice5.di-net.ru>"
> h323-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"
> h323-call-origin = "originate"
> h323-call-type = "VoIP"
> Cisco-AVPair = "h323-incoming-conf-id=F0FF23AA 587A11DD B8009A2D
> 9B5B4497"
> Cisco-AVPair = "subscriber=Unknown"
> Cisco-AVPair = "session-protocol=sipv2"
> Cisco-AVPair = "gw-rxd-cdn=ton:0,npi:0,#:74955891937"
> Acct-Input-Octets = 0
> Acct-Output-Octets = 0
> Acct-Input-Packets = 0
> Acct-Output-Packets = 0
> Acct-Session-Time = 0
> h323-connect-time = ".09:48:16.371 MSD Thu Jul 24 2008"
> h323-disconnect-time = ".09:48:16.371 MSD Thu Jul 24 2008"
> h323-disconnect-cause = "1"
> h323-remote-address = "89.208.190.4 <http://89.208.190.4>"
> Cisco-AVPair = "release-source=4"
> h323-voice-quality = "0"
> Cisco-AVPair = "gw-rxd-cgn=ton:0,npi:0,pi:1,si:0,#:4959636156"
> Cisco-AVPair = "gw-final-xlated-cdn=ton:0,npi:0,#:74955891937"
> Cisco-AVPair =
> "gw-final-xlated-cgn=ton:0,npi:0,pi:1,si:0,#:4959636156"
> User-Name = "4959636156"
> Acct-Status-Type = *Stop*
> Service-Type = Login-User
> NAS-IP-Address = 89.208.190.6 <http://89.208.190.6>
> Acct-Delay-Time = 0
> call-id = "F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6>"
> h323-incoming-conf-id = "F0FF23AA 587A11DD B8009A2D 9B5B4497"
> subscriber = "Unknown"
> session-protocol = "sipv2"
> gw-rxd-cdn = "ton:0,npi:0,#:74955891937"
> release-source = "4"
> gw-rxd-cgn = "ton:0,npi:0,pi:1,si:0,#:4959636156"
> gw-final-xlated-cdn = "ton:0,npi:0,#:74955891937"
> gw-final-xlated-cgn = "ton:0,npi:0,pi:1,si:0,#:4959636156"
> Client-IP-Address = 89.208.190.6 <http://89.208.190.6>
> Acct-Unique-Session-Id = "51b334248c332b3b"
> Timestamp = 1216878507
>
> =========== /var/log/radius/sqltrace.sql ================
>
> 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*', '89.208.190.6 <http://89.208.190.6>', 'originate',
> '74955891937', '4959636156', '57000000000008F7',
> 'F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6>', '', '', '',
> '4959636156', '', '', '', '', '.09:48:16.191 MSD Thu Jul 24 2008', '',
> '', '', '', '', '', 'F0FF23AA 587A11DD B8009A2D 9B5B4497');
>
> 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*', '89.208.190.6 <http://89.208.190.6>', 'originate',
> '74955891937', '4959636156', '57000000000008F7',
> 'F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6>', '', '', '',
> '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');
>
> ========== Data from DB acc table ===========
>
> ID ACCT-STATUS-TYPE
> CALL-ID
> H323-CONF-ID
> ---------- ------------------
> -----------------------------------------------------
> ------------------------------------
> 1134861 Stop
> F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6> F0FF23AA
> 587A11DD B8009A2D 9B5B4497
> 1134862 Start
> F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6
> <mailto:F217BA24-587A11DD-83D18BF5-E033E9AB at 89.208.190.6> F0FF23AA
> 587A11DD B8009A2D 9B5B4497
>
> 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
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"
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.
Using one SQL connection would probably work but will be slow.
More information about the Freeradius-Users
mailing list