Re: Alternative for rlm_attr_filter for filtering vsa

22 Jan 2019

      ----- On Jan 22, 2019, at 3:49 PM, Alan DeKok aland@deployingradius.com wrote:
...
attr_filter  List the attributes you want it to keep, and it will delete the
rest.
Ok, that's good to know, so I did some further digging to figure out what's going wrong and I may have found the issue now.

Here's some relevant debugging output first...

  # Loading module "attr_filter_preproxy" from file /opt/radius/etc/raddb/modules.conf
  attr_filter attr_filter_preproxy {
        filename = "/opt/radius/etc/raddb/attr_filter_preproxy"
        key = "%{Packet-Type}"
        relaxed = no
  }

  # Instantiating module "attr_filter_preproxy" from file /opt/radius/etc/raddb/modules.conf
reading pairlist file /opt/radius/etc/raddb/attr_filter_preproxy

The file contains:

DEFAULT
        NAS-Identifier =* ANY,
        Framed-IP-Address =* ANY,
        Acct-Status-Type =* ANY,
        Acct-Session-Time =* ANY,
        Acct-Delay-Time =* ANY,
        Acct-Multi-Session-Id =* ANY,
        Acct-Session-Id =* ANY,
        Event-Timestamp =* ANY,
        Alc-Subsc-ID-Str =* ANY,
        Alc-Acct-I-Inprof-Octets-64 =* ANY,
        Alc-Acct-I-Outprof-Octets-64 =* ANY,
        Alc-Acct-I-Inprof-Pkts-64 =* ANY,
        Alc-Acct-I-Outprof-Pkts-64 =* ANY,
        Alc-Acct-O-Inprof-Octets-64 =* ANY,
        Alc-Acct-O-Outprof-Octets-64 =* ANY,
        Alc-Acct-O-Inprof-Pkts-64 =* ANY,
        Alc-Acct-O-Outprof-Pkts-64 =* ANY,
        Fall-Through = No

Ready to process requests
detail (/opt/radius/var/log/radius/radacct/detail-for-proxy): Read packet from /opt/radius/var/log/radius/radacct/detail-for-proxy.work
        Acct-Status-Type = Interim-Update
        NAS-IP-Address = 127.0.0.1
        Acct-Session-Id = "30392D00A54FC35C46F9A5"
        Acct-Session-Time = 22665
        Acct-Multi-Session-Id = "30392D00A54FC35C46F9A5"
        Alc-Subsc-ID-Str = "subscriber_id"
        Alc-Subsc-Prof-Str = "subscriber_profile"
        Alc-Acct-I-Inprof-Octets-64 = 0x00010000000000000000
        Alc-Acct-I-Outprof-Octets-64 = 0x00010000000000000000
        Alc-Acct-I-Inprof-Pkts-64 = 0x00010000000000000000
        Alc-Acct-I-Outprof-Pkts-64 = 0x00010000000000000000
        Alc-Acct-I-Inprof-Octets-64 = 0x00030000000000000000
        Alc-Acct-I-Outprof-Octets-64 = 0x000300000000002f0f2e
        Alc-Acct-I-Inprof-Pkts-64 = 0x00030000000000000000
        Alc-Acct-I-Outprof-Pkts-64 = 0x0003000000000000450d
        Alc-Acct-O-Inprof-Octets-64 = 0x000100000000000b2190
        Alc-Acct-O-Outprof-Octets-64 = 0x00010000000000280e14
        Alc-Acct-O-Inprof-Pkts-64 = 0x000100000000000022d7
        Alc-Acct-O-Outprof-Pkts-64 = 0x00010000000000004532
        Alc-Acct-O-Inprof-Octets-64 = 0x000300000000002efba2
        Alc-Acct-O-Outprof-Octets-64 = 0x00030000000000000000
        Alc-Acct-O-Inprof-Pkts-64 = 0x0003000000000000450a
        Alc-Acct-O-Outprof-Pkts-64 = 0x00030000000000000000
        NAS-Identifier = "TEST"
        ADSL-Agent-Circuit-Id = "circuit id"
        ADSL-Agent-Remote-Id = "remote id"
        Event-Timestamp = "Jan 22 2019 18:36:23 CET"
        Packet-Original-Timestamp = "Jan 22 2019 18:36:23 CET"
        Acct-Delay-Time = 963
        Packet-Transmit-Counter = 1
(0) # Executing section accounting from file /opt/radius/etc/raddb/server.conf
(0)   accounting {
(0)     update control {
(0)       Proxy-To-Realm := PROXY
(0)     } # update control = noop
(0)   } # accounting = noop
(0) Starting proxy to home server 1.1.1.1 port 1813
(0) # Executing section pre-proxy from file /opt/radius/etc/raddb/server.conf
(0)   pre-proxy {
(0) detail_proxy_request: EXPAND /opt/radius/var/log/radius/radacct/detail-proxy-request-%Y%m%d
(0) detail_proxy_request:    --> /opt/radius/var/log/radius/radacct/detail-proxy-request-20190122
(0) detail_proxy_request: /opt/radius/var/log/radius/radacct/detail-proxy-request-%Y%m%d expands to /opt/radius/var/log/radius/radacct/detail-proxy-request-20190122
(0) detail_proxy_request: EXPAND %t
(0) detail_proxy_request:    --> Tue Jan 22 18:52:26 2019
(0)     [detail_proxy_request] = ok
(0) attr_filter_preproxy: EXPAND %{Packet-Type}
(0) attr_filter_preproxy:    --> Accounting-Request
(0) attr_filter_preproxy: Matched entry DEFAULT at line 2
(0)     [attr_filter_preproxy] = updated
(0) detail_proxy_request: EXPAND /opt/radius/var/log/radius/radacct/detail-proxy-request-%Y%m%d
(0) detail_proxy_request:    --> /opt/radius/var/log/radius/radacct/detail-proxy-request-20190122
(0) detail_proxy_request: /opt/radius/var/log/radius/radacct/detail-proxy-request-%Y%m%d expands to /opt/radius/var/log/radius/radacct/detail-proxy-request-20190122
(0) detail_proxy_request: EXPAND %t
(0) detail_proxy_request:    --> Tue Jan 22 18:52:26 2019
(0)     [detail_proxy_request] = ok
(0)   } # pre-proxy = updated
(0) Proxying request to home server 1.1.1.1 port 1813 timeout 5.000000

The following goes into the detail-proxy-request-20190122 file:

Tue Jan 22 18:57:29 2019
        Packet-Type = Accounting-Request
        Acct-Status-Type = Interim-Update
        NAS-IP-Address = 127.0.0.1
        Acct-Session-Id = "30392D00A54FC35C46F9A5"
        Acct-Session-Time = 22665
        Acct-Multi-Session-Id = "30392D00A54FC35C46F9A5"
        Alc-Subsc-ID-Str = "subscriber_id"
        Alc-Subsc-Prof-Str = "subscriber_profile"
        Alc-Acct-I-Inprof-Octets-64 = 0x00010000000000000000
        Alc-Acct-I-Outprof-Octets-64 = 0x00010000000000000000
        Alc-Acct-I-Inprof-Pkts-64 = 0x00010000000000000000
        Alc-Acct-I-Outprof-Pkts-64 = 0x00010000000000000000
        Alc-Acct-I-Inprof-Octets-64 = 0x00030000000000000000
        Alc-Acct-I-Outprof-Octets-64 = 0x000300000000002f0f2e
        Alc-Acct-I-Inprof-Pkts-64 = 0x00030000000000000000
        Alc-Acct-I-Outprof-Pkts-64 = 0x0003000000000000450d
        Alc-Acct-O-Inprof-Octets-64 = 0x000100000000000b2190
        Alc-Acct-O-Outprof-Octets-64 = 0x00010000000000280e14
        Alc-Acct-O-Inprof-Pkts-64 = 0x000100000000000022d7
        Alc-Acct-O-Outprof-Pkts-64 = 0x00010000000000004532
        Alc-Acct-O-Inprof-Octets-64 = 0x000300000000002efba2
        Alc-Acct-O-Outprof-Octets-64 = 0x00030000000000000000
        Alc-Acct-O-Inprof-Pkts-64 = 0x0003000000000000450a
        Alc-Acct-O-Outprof-Pkts-64 = 0x00030000000000000000
        NAS-Identifier = "TEST"
        ADSL-Agent-Circuit-Id = "circuit id"
        ADSL-Agent-Remote-Id = "remote id"
        Event-Timestamp = "Jan 22 2019 18:36:23 CET"
        Packet-Original-Timestamp = "Jan 22 2019 18:36:23 CET"
        Acct-Delay-Time = 1266
        Packet-Transmit-Counter = 1
        Proxy-State = 0x30
        Timestamp = 1548179849

Tue Jan 22 18:57:29 2019
        Packet-Type = Accounting-Request
        Acct-Status-Type = Interim-Update
        Acct-Session-Id = "30392D00A54FC35C46F9A5"
        Acct-Session-Time = 22665
        Acct-Multi-Session-Id = "30392D00A54FC35C46F9A5"
        Alc-Subsc-ID-Str = "subscriber_id"
        Alc-Subsc-Prof-Str = "subscriber_profile"
        Alc-Acct-I-Inprof-Octets-64 = 0x00010000000000000000
        Alc-Acct-I-Outprof-Octets-64 = 0x00010000000000000000
        Alc-Acct-I-Inprof-Pkts-64 = 0x00010000000000000000
        Alc-Acct-I-Outprof-Pkts-64 = 0x00010000000000000000
        Alc-Acct-I-Inprof-Octets-64 = 0x00030000000000000000
        Alc-Acct-I-Outprof-Octets-64 = 0x000300000000002f0f2e
        Alc-Acct-I-Inprof-Pkts-64 = 0x00030000000000000000
        Alc-Acct-I-Outprof-Pkts-64 = 0x0003000000000000450d
        Alc-Acct-O-Inprof-Octets-64 = 0x000100000000000b2190
        Alc-Acct-O-Outprof-Octets-64 = 0x00010000000000280e14
        Alc-Acct-O-Inprof-Pkts-64 = 0x000100000000000022d7
        Alc-Acct-O-Outprof-Pkts-64 = 0x00010000000000004532
        Alc-Acct-O-Inprof-Octets-64 = 0x000300000000002efba2
        Alc-Acct-O-Outprof-Octets-64 = 0x00030000000000000000
        Alc-Acct-O-Inprof-Pkts-64 = 0x0003000000000000450a
        Alc-Acct-O-Outprof-Pkts-64 = 0x00030000000000000000
        NAS-Identifier = "TEST"
        ADSL-Agent-Circuit-Id = "circuit id"
        ADSL-Agent-Remote-Id = "remote id"
        Event-Timestamp = "Jan 22 2019 18:36:23 CET"
        Acct-Delay-Time = 1266
        Timestamp = 1548179849

So the filter didn't work, since there are still ADSL- and Alc- attributes that were not allowed in the attr_filter.

Then I started commenting the lines in the attr_filter file line by line and guess what ...
With the following attr_filter file, the issue is gone:

DEFAULT
        NAS-Identifier =* ANY,
        Framed-IP-Address =* ANY,
        Acct-Status-Type =* ANY,
        Acct-Session-Time =* ANY,
        Acct-Delay-Time =* ANY,
        Acct-Multi-Session-Id =* ANY,
        Acct-Session-Id =* ANY,
        Event-Timestamp =* ANY,
        Alc-Subsc-ID-Str =* ANY,
        Alc-Acct-I-Inprof-Octets-64 =* ANY,
        Alc-Acct-I-Outprof-Octets-64 =* ANY,
        Alc-Acct-I-Inprof-Pkts-64 =* ANY,
        Alc-Acct-I-Outprof-Pkts-64 =* ANY,
        Alc-Acct-O-Inprof-Octets-64 =* ANY,
        Alc-Acct-O-Outprof-Octets-64 =* ANY,
        Alc-Acct-O-Inprof-Pkts-64 =* ANY,
#        Alc-Acct-O-Outprof-Pkts-64 =* ANY,
        Fall-Through = No

So I wonder why it fail if only that one attribute is added the list ?

Looking up the attribute in the dictionary yields the following:
/opt/freeradius/share/freeradius/dictionary.alcatel.sr:ATTRIBUTE  Alc-Acct-O-Outprof-Pkts-64              26      octets

The number "26" immediately rings a bell... there's another attribute with value 26:
/opt/freeradius/share/freeradius/dictionary.rfc2865:ATTRIBUTE     Vendor-Specific                         26      vsa

Could it be that rlm_attr_filter mistakenly treats "Alc-Acct-O-Outprof-Pkts-64 =* ANY," as "Vendor-Specific =* ANY," ?

Kind regards,
Thor

Re: Alternative for rlm_attr_filter for filtering vsa

Thor Spruyt