Hi Alan, thanks again for your help! Am 26.03.2018 um 20:05 schrieb Alan DeKok:
On Mar 26, 2018, at 2:00 PM, Michael Markstaller via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
(do I really need 2.2.10?):
Yes.
Unless Ubuntu has back-ported security fixes from 2.2.10 to 2.2.8. Which they might not have done.
TBH, the fixes between 2.2.8 and 2.2.10 are bug fixes, and only bug fixes. There's just no reason to run 2.2.8, much less distribute it as part of a "stable" release.
Hmm, ok. I'm really a little bit out of this business maintaining debian/ubuntu-packages and tracking which fixes were ported back (or not) but a big friend of NOT using hand-crafted software form git etc. in a production-environment like 16.04 LTS - as nobody can handle this during the next update/upgrade.. Anyway, no issue, I'll give it a try..
I want a mainly stable and admin-friendly "stock-setup" which is Ubuntu 16.04 here right now.. And my needs are also IMHO not very sophisticated, just acct to SQL mitigating somehow what the ASA-developers obviously have missed while reading the RADIUS-RFC :)
Anyway, there is also no AcctStartTime in Interim-Update packets, so Alans' suggestion fails
--- Debug --- ++if (!Acct-Session-Time && Acct-Start-Time) { +++update request { expand: %l / 1000 -> 1522081439 / 1000 expand: %{expr:%l / 1000} - %{Acct-Start-Time} -> 1522081 - ERROR: Failed parsing value "1522081 - " for attribute
Uh... that's *not* what I suggested to do. Please pay attention.
The "expr" module does math. You can't just put random math into the configuration and expect it to work.
The "%l" is the Unix time in seconds. Which is the same time system as Acct-Start-Time. There is no need to divide %l by 1000.
I said:
if (!Acct-Session-Time && Acct-Start-Time) { update request { Acct-Session-Time := "%{expr:%l - %{Acct-Start-Time}}" } }
It got me times factor 1000 too high: so I fiddled around wrong with the formula and parenthesis wrong - my fault - sorry ;) But as I have no Acct-Start-Time in the Interim-Update packet it still fails, how should FR know in preacct about Acct-Start-Time without looking at the database. --- cut --- rad_recv: Accounting-Request packet from host 172.x.x.x port 45045, id=222, length=535 User-Name = "W0xxxx" NAS-Port = 249856 Service-Type = Framed-User Framed-Protocol = PPP Called-Station-Id = "1x.x.x.x" Calling-Station-Id = "2x.x.x.x" Acct-Status-Type = Start Acct-Delay-Time = 0 Acct-Session-Id = "0CC0003D" Acct-Authentic = RADIUS NAS-Port-Type = Virtual Tunnel-Client-Endpoint:0 = "2x.x.x.x" Vendor-3076-Attr-146 = 0x45xxx Vendor-3076-Attr-150 = 0x00000006 Vendor-3076-Attr-151 = 0x00000002 Vendor-3076-Attr-152 = 0x00000003 Cisco-AVPair = "mdm-tlv=device-platform=win" Cisco-AVPair = "mdm-tlv=device-mac=74-xxx" Cisco-AVPair = "audit-session-id=ac160a270003d0005ab98eec" Cisco-AVPair = "mdm-tlv=device-type=Fxxx" Cisco-AVPair = "mdm-tlv=device-platform-version=10.0.16299 " Cisco-AVPair = "mdm-tlv=device-uid=Fxxxx" NAS-IP-Address = 172.x.x.x # Executing section preacct from file /etc/freeradius/sites-enabled/default +group preacct { ++[preprocess] = ok ++? if (!Acct-Session-Time && Acct-Start-Time) ? Evaluating !(Acct-Session-Time ) -> TRUE ? Evaluating (Acct-Start-Time) -> TRUE ++? if (!Acct-Session-Time && Acct-Start-Time) -> TRUE ++if (!Acct-Session-Time && Acct-Start-Time) { +++update request { expand: %l - %{Acct-Start-Time} -> 1522110184 - expand: %{expr:%l - %{Acct-Start-Time}} -> 1522110184 +++} # update request = noop ++} # if (!Acct-Session-Time && Acct-Start-Time) = noop [acct_unique] WARNING: Attribute NAS-Identifier was not found in request, unique ID MAY be inconsistent [acct_unique] Hashing 'NAS-Port = 249856,,NAS-IP-Address = 172.x.x.x,Acct-Session-Id = "0CC0003D",User-Name = "W0xxxx"' [acct_unique] Acct-Unique-Session-ID = "7223639885ceac94". ++[acct_unique] = ok [suffix] No '@' in User-Name = "W0xxxx", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop ++[files] = noop +} # group preacct = ok # Executing section accounting from file /etc/freeradius/sites-enabled/default +group accounting { [detail] expand: %{Packet-Src-IP-Address} -> 172.x.x.x [detail] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.x.x.x/detail-20180327 [detail] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.x.x.x/detail-20180327 [detail] expand: %t -> Tue Mar 27 02:23:04 2018 ++[detail] = ok [sql] expand: %{User-Name} -> W0xxxx [sql] sql_set_user escaped user --> 'W0xxxx' [sql] expand: %{Acct-Delay-Time} -> 0 [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, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', rlm_sql (sql): Reserving sql socket id: 31 rlm_sql (sql): Released sql socket id: 31 ++[sql] = ok ++[exec] = noop [attr_filter.accounting_response] expand: %{User-Name} -> W0xxxx attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 222 to 172.x.x.x port 45045 Finished request 0. Cleaning up request 0 ID 222 with timestamp +37 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 172.x.x.x port 45045, id=223, length=565 User-Name = "W0xxxx" NAS-Port = 249856 Service-Type = Framed-User Framed-Protocol = PPP Framed-IP-Address = 172.y.x.x Called-Station-Id = "1x.x.x.x" Calling-Station-Id = "2x.x.x.x" Acct-Status-Type = Interim-Update Acct-Delay-Time = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Id = "0CC0003D" Acct-Authentic = RADIUS Acct-Input-Packets = 0 Acct-Output-Packets = 0 NAS-Port-Type = Virtual Tunnel-Client-Endpoint:0 = "2x.x.x.x" Vendor-3076-Attr-146 = 0x4xxx Vendor-3076-Attr-150 = 0x00000006 Vendor-3076-Attr-151 = 0x00000002 Vendor-3076-Attr-152 = 0x00000003 Cisco-AVPair = "mdm-tlv=device-platform=win" Cisco-AVPair = "mdm-tlv=device-mac=74-xxx" Cisco-AVPair = "audit-session-id=ac160a270003d0005ab98eec" Cisco-AVPair = "mdm-tlv=device-type=Fxxx" Cisco-AVPair = "mdm-tlv=device-platform-version=10.0.16299 " Cisco-AVPair = "mdm-tlv=device-uid=Fxxxx" NAS-IP-Address = 172.x.x.x # Executing section preacct from file /etc/freeradius/sites-enabled/default +group preacct { ++[preprocess] = ok ++? if (!Acct-Session-Time && Acct-Start-Time) ? Evaluating !(Acct-Session-Time ) -> TRUE ? Evaluating (Acct-Start-Time) -> TRUE ++? if (!Acct-Session-Time && Acct-Start-Time) -> TRUE ++if (!Acct-Session-Time && Acct-Start-Time) { +++update request { expand: %l - %{Acct-Start-Time} -> 1522110184 - expand: %{expr:%l - %{Acct-Start-Time}} -> 1522110184 +++} # update request = noop ++} # if (!Acct-Session-Time && Acct-Start-Time) = noop [acct_unique] WARNING: Attribute NAS-Identifier was not found in request, unique ID MAY be inconsistent [acct_unique] Hashing 'NAS-Port = 249856,,NAS-IP-Address = 172.x.x.x,Acct-Session-Id = "0CC0003D",User-Name = "W0xxxx"' [acct_unique] Acct-Unique-Session-ID = "7223639885ceac94". ++[acct_unique] = ok [suffix] No '@' in User-Name = "W0xxxx", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop ++[files] = noop +} # group preacct = ok # Executing section accounting from file /etc/freeradius/sites-enabled/default +group accounting { [detail] expand: %{Packet-Src-IP-Address} -> 172.x.x.x [detail] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.x.x.x/detail-20180327 [detail] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.x.x.x/detail-20180327 [detail] expand: %t -> Tue Mar 27 02:23:04 2018 ++[detail] = ok [sql] expand: %{User-Name} -> W0xxxx [sql] sql_set_user escaped user --> 'W0xxxx' [sql] expand: %{Acct-Session-Time} -> 1522110184 [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> 0 [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> 0 [sql] expand: UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{%{Acct-Session-Time}:-0}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET framedipaddress = '172.y.x.x', acctsessiontime = '1522110184', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '0CC0003D' AND username = 'W0PROD99ADM013.prod.a rlm_sql (sql): Reserving sql socket id: 30 rlm_sql (sql): Released sql socket id: 30 ++[sql] = ok ++[exec] = noop [attr_filter.accounting_response] expand: %{User-Name} -> W0xxxx attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 223 to 172.x.x.x port 45045 Finished request 1. Cleaning up request 1 ID 223 with timestamp +37 Going to the next request Ready to process requests. --- cut --- gives me AcctSessionTime of 1522110184 in DB which is pretty clear as the substracted AcctStartTime is still 0/NULL in this context. So my AcctSessionTime is simply the timestamp of the last update. Good enough. Good and persistent solution: No! But still: it gave me an Idea how to get to a result in the reports anyway: just use the (wrong) AcctSessionTime from the SQL-DB - substract AcctStartTime from DB, easy, et voila ;-) Fix it in the display with wrong data in the backend: not neat but working. P.S.: -> I'm fully aware that the source of the problem is the ASA not sending AcctSessionTime and AcctStartTime, not FR - but I'm too old and experienced to open a Bug at Cisco which is usually unfortunately totally useless.. Though, I think about opening a bug at Cisco: because the 1hrs minimum Interim-Update interval of the ASA is an absolute No-Go and ridiculous.. Because the base for all of this is: I want to see the status of my clients/users in nearly realtime to be able to support them at best. Michael