SQL Logging quirks with cisco-avpair

Mike Manning Mike.Manning at chaptech.com.au
Mon Apr 4 05:37:52 UTC 2022


Hi all,

I have a strange issue that I have seen pop up on a thread years ago but cannot for the life of me find the answer to it anymore.  I have a freeradius 3.0 server set up handling authentication requests from Cisco ASR's for our internet users.  We're sending through extended attributes in our AAA data from our ASR's and can see the details in our radacct files (details removed for privacy):

Mon Apr  4 00:01:09 2022
        Acct-Session-Id = "0003E6A0"
        Framed-Protocol = PPP
        Framed-IP-Address = x.x.x.x
        User-Name = "username at realm"
        X-Ascend-Connect-Progress = LAN-Session-Up
        Cisco-AVPair = "connect-progress=LAN Ses Up"
        X-Ascend-PreSession-Time = 1
        X-Ascend-Xmit-Rate = 1410065408
        Cisco-AVPair = "nas-tx-speed=1410065408"
        Cisco-AVPair = "nas-tx-speed-kbps=1410065"
        X-Ascend-Data-Rate = 1410065408
        Cisco-AVPair = "nas-rx-speed=1410065408"
        Cisco-AVPair = "nas-rx-speed-kbps=1410065"
        Acct-Session-Time = 888770
        Acct-Input-Gigawords = 151
        Acct-Output-Gigawords = 18
        Acct-Input-Octets = 1877053998
        Acct-Output-Octets = 3577481241
        WLAN-RF-Band = 83
        X-Ascend-Pre-Output-Octets = 53
        Acct-Input-Packets = 494627556
        Acct-Output-Packets = 336289465
        X-Ascend-Pre-Input-Packets = 4
        X-Ascend-Pre-Output-Packets = 4
        Acct-Authentic = RADIUS
        Acct-Status-Type = Interim-Update
        NAS-Port-Type = Virtual
        NAS-Port = 0
        NAS-Port-Id = "0/1/0/2066.123"
        Cisco-AVPair = "client-mac-address=7c5a.xxxx.xxxx"
        Cisco-AVPair = "circuit-id-tag=AVC000xxxxxxxx"
        Service-Type = Framed-User
        NAS-IP-Address = y.y.y.y
        Acct-Delay-Time = 0
        Event-Timestamp = "Apr  4 2022 00:01:09 AEST"
        Tmp-String-9 = "ai:"

As you can see in the radacct files, the Cisco-AVPair is being written correctly for the client-mac-address and circuit-id tag.  This also appears correctly in the /var/log/freeradius/radius.log file as I have the following 2 lines in radiusd.conf

        msg_goodpass = "Mac: %{Cisco-AVPair[0]}, Circuit ID: %{Cisco-AVPair[1]}"
        msg_badpass = "Mac: %{Cisco-AVPair[0]}, Circuit ID: %{Cisco-AVPair[1]}"

Mon Apr  4 15:23:43 2022 : Auth: (3463054) Login OK: [username at realm] (from client CLIENTNAME port 0) Mac: client-mac-address=7483.xxxx.yyyy, Circuit ID: circuit-id-tag=AVC00xxxxxxx

Here's the strange part.  I am logging the circuit-id and also mac address to the postauth table as follows in the SQL db.  Here is the extract from /etc/freeradius/3.0/mods-config/sql/main/mysql/queries.conf:

post-auth {
        # Write SQL queries to a logfile. This is potentially useful for bulk inserts
        # when used with the rlm_sql_null driver.
#       logfile = ${logdir}/post-auth.sql

        query = "\
                INSERT IGNORE INTO ${..postauth_table} \
                        (username, pass, reply, authdate, macaddress, circuitid) \
                VALUES ( \
                        '%{SQL-User-Name}', \
                        '%{%{User-Password}:-%{Chap-Password}}', \
                        '%{reply:Packet-Type}', \
                        '%S', \
                        '%{Cisco-AVPair[0]}', \
                        '%{Cisco-AVPair[1]}')"

This proceeds to log the details in the SQL DB however both cisco-avpair entries are prepended with a "3D" entry:

INSERT INTO `radpostauth` (`id`, `username`, `reply`, `authdate`, `macaddress`, `circuitid`) VALUES
(131788, 'username at realm', 'Access-Accept', '2022-04-04 05:08:41', 'client-mac-address=3D7c5a.xxxx.yyyy', 'circuit-id-tag=3DAVC0000xxxxxx');

This does not appear in any other log files, is there something to remove the "3D" header that these entries have when logging?

Cheers, Mike


More information about the Freeradius-Users mailing list