Hello everyone, I have a question regarding the release of IP addresses with the module ippool. We are about to replace our old Feeradius 2.2.8 with a new 3.0.16 installation. This worked very well, but there is still a problem with the release of the IP pools after the Acct-Stop. The corresponding "Acct-Status-Type = Stop" packets arrive correctly at the radius, but the evaluation is exited after the first "ippool area" within which no IP is found. (unabridged debug log in appendix —> debug_1) (6079) Mon Oct 29 14:40:20 2018: Debug: User-Name = "user1" (6079) Mon Oct 29 14:40:20 2018: Debug: NAS-Port = 202153984 (6079) Mon Oct 29 14:40:20 2018: Debug: Service-Type = Framed-User (6079) Mon Oct 29 14:40:20 2018: Debug: Framed-Protocol = PPP (6079) Mon Oct 29 14:40:20 2018: Debug: Framed-IP-Address = 10.99.157.108 (6079) Mon Oct 29 14:40:20 2018: Debug: Called-Station-Id = "193.25.18.219" (6079) Mon Oct 29 14:40:20 2018: Debug: Calling-Station-Id = "109.90.177.240" (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Status-Type = Stop (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Delay-Time = 0 (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Input-Octets = 5152 (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Output-Octets = 11550 (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Session-Id = "6DC02E18" (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Authentic = RADIUS (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Session-Time = 19 (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Input-Packets = 79 (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Output-Packets = 15 (6079) Mon Oct 29 14:40:20 2018: Debug: Acct-Terminate-Cause = User-Request (6079) Mon Oct 29 14:40:20 2018: Debug: NAS-Port-Type = Virtual ... (6079) Mon Oct 29 14:40:20 2018: Debug: accounting { (6079) Mon Oct 29 14:40:20 2018: Debug: detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (6079) Mon Oct 29 14:40:20 2018: Debug: detail: --> /var/log/freeradius/radacct/193.25.18.219/detail-20181029 (6079) Mon Oct 29 14:40:20 2018: Debug: detail: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/193.25.18.219/detail-20181029 (6079) Mon Oct 29 14:40:20 2018: Debug: detail: EXPAND %t (6079) Mon Oct 29 14:40:20 2018: Debug: detail: --> Mon Oct 29 14:40:20 2018 (6079) Mon Oct 29 14:40:20 2018: Debug: [detail] = ok (6079) Mon Oct 29 14:40:20 2018: Debug: [unix] = ok (6079) Mon Oct 29 14:40:20 2018: Debug: FB1-B: EXPAND %{NAS-IP-Address} %{NAS-Port} (6079) Mon Oct 29 14:40:20 2018: Debug: FB1-B: --> 193.25.18.219 202153984 (6079) Mon Oct 29 14:40:20 2018: Debug: FB1-B: MD5 on 'key' directive maps to: 8c9ebba43c49461c579616773eb1d008 (6079) Mon Oct 29 14:40:20 2018: Debug: FB1-B: Searching for an entry for key: '193.25.18.219 202153984' (6079) Mon Oct 29 14:40:20 2018: Debug: FB1-B: Entry not found (6079) Mon Oct 29 14:40:20 2018: Debug: [FB1-B] = notfound (6079) Mon Oct 29 14:40:20 2018: Debug: } # accounting = notfound (6079) Mon Oct 29 14:40:20 2018: Debug: Not sending reply to client. (6079) Mon Oct 29 14:40:20 2018: Debug: Finished request (6079) Mon Oct 29 14:40:21 2018: Debug: Cleaning up request packet ID 132 with timestamp +76 If we adjust the order of the ippools in the site-availiable configuration so that the used area is in first place, it will be evaluated correctly at the Acct-Stop and the IP address will be released but the evaluation will jump out again after the first pool without an entry. (unabridged debug log in appendix —> debug_2) (2931) Mon Oct 29 14:45:52 2018: Debug: Received Accounting-Request Id 149 from 193.25.18.219:38622 to 10.100.16.162:2011 length 213 (2931) Mon Oct 29 14:45:52 2018: Debug: User-Name = "user1" (2931) Mon Oct 29 14:45:52 2018: Debug: NAS-Port = 202162176 (2931) Mon Oct 29 14:45:52 2018: Debug: Service-Type = Framed-User (2931) Mon Oct 29 14:45:52 2018: Debug: Framed-Protocol = PPP (2931) Mon Oct 29 14:45:52 2018: Debug: Framed-IP-Address = 10.99.156.54 (2931) Mon Oct 29 14:45:52 2018: Debug: Called-Station-Id = "193.25.18.219" (2931) Mon Oct 29 14:45:52 2018: Debug: Framed-IP-Address = 10.99.156.54 (2931) Mon Oct 29 14:45:52 2018: Debug: Called-Station-Id = "193.25.18.219" (2931) Mon Oct 29 14:45:52 2018: Debug: Calling-Station-Id = "109.90.177.240" (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Status-Type = Stop (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Delay-Time = 0 (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Input-Octets = 2747 (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Output-Octets = 2789 (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Session-Id = "6DC02E1B" (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Authentic = RADIUS (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Session-Time = 6 (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Input-Packets = 43 (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Output-Packets = 6 (2931) Mon Oct 29 14:45:52 2018: Debug: Acct-Terminate-Cause = User-Request (2931) Mon Oct 29 14:45:52 2018: Debug: NAS-Port-Type = Virtual ... (2931) Mon Oct 29 14:45:52 2018: Debug: accounting { (2931) Mon Oct 29 14:45:52 2018: Debug: detail: EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (2931) Mon Oct 29 14:45:52 2018: Debug: detail: --> /var/log/freeradius/radacct/193.25.18.219/detail-20181029 (2931) Mon Oct 29 14:45:52 2018: Debug: detail: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/193.25.18.219/detail-20181029 (2931) Mon Oct 29 14:45:52 2018: Debug: detail: EXPAND %t (2931) Mon Oct 29 14:45:52 2018: Debug: detail: --> Mon Oct 29 14:45:52 2018 (2931) Mon Oct 29 14:45:52 2018: Debug: [detail] = ok (2931) Mon Oct 29 14:45:52 2018: Debug: [unix] = ok (2931) Mon Oct 29 14:45:52 2018: Debug: DVZ-S: EXPAND %{NAS-IP-Address} %{NAS-Port} (2931) Mon Oct 29 14:45:52 2018: Debug: DVZ-S: --> 193.25.18.219 202162176 (2931) Mon Oct 29 14:45:52 2018: Debug: DVZ-S: MD5 on 'key' directive maps to: e1441074cac9707ffe85004a796a5062 (2931) Mon Oct 29 14:45:52 2018: Debug: DVZ-S: Searching for an entry for key: '193.25.18.219 202162176' (2931) Mon Oct 29 14:45:52 2018: Debug: DVZ-S: Deallocated entry for ip: 10.99.156.54 (2931) Mon Oct 29 14:45:52 2018: Debug: DVZ-S: Allocated count now: 0 (2931) Mon Oct 29 14:45:52 2018: Debug: [DVZ-S] = ok (2931) Mon Oct 29 14:45:52 2018: Debug: Gaeste: EXPAND %{NAS-IP-Address} %{NAS-Port} (2931) Mon Oct 29 14:45:52 2018: Debug: Gaeste: --> 193.25.18.219 202162176 (2931) Mon Oct 29 14:45:52 2018: Debug: Gaeste: MD5 on 'key' directive maps to: e1441074cac9707ffe85004a796a5062 (2931) Mon Oct 29 14:45:52 2018: Debug: Gaeste: Searching for an entry for key: '193.25.18.219 202162176' (2931) Mon Oct 29 14:45:52 2018: Debug: Gaeste: Entry not found (2931) Mon Oct 29 14:45:52 2018: Debug: [Gaeste] = notfound (2931) Mon Oct 29 14:45:52 2018: Debug: } # accounting = notfound (2931) Mon Oct 29 14:45:52 2018: Debug: Not sending reply to client. (2931) Mon Oct 29 14:45:52 2018: Debug: Finished request (2931) Mon Oct 29 14:45:52 2018: Debug: Cleaning up request packet ID 149 with timestamp +42 Does anyone know a similar behavior and has a tip for us? The unabridged debug logs and the corresponding sites-available configuration (vpn) can be found in the appendix. Many thanks in advance! Yours sincerely Lars Hillebrand __ Fachhochschule Dortmund University of Applied Sciences and Arts Dipl.-Ing. (FH) Lars Hillebrand Dez. VI, IT-Basisdienste Sonnenstraße 100 - 44139 Dortmund Raum SON D 008 Tel 0231 9112-253 Fax 0231 9112-338 lars.hillebrand@fh-dortmund.de www.fh-dortmund.de