Unstable freeRADIUS (authorization) work
Манцуров Дмитрий Вячеславович
MantsurovDV at volgatech.net
Fri Jun 3 15:14:11 CEST 2016
I have freeRADIUS version 2.2.5 installed on Debian GNU/Linux 8.4 (Jessie).
freeRADIUS use with telephone station. Now testing with two users. Their User-Names 682808 and 686038.
When I run freeRADIUS as daemon, it works about one hour (sometimes less). Then I get for one of users: "Auth: [preprocess] No huntgroup access..." (log below). And another user can continue to work
When I run FreeRADIUS in debug mode (freeradius -X), it can work for three days, I did not check longer.
Detailed log, when user was authorize:
Fri Jun 3 14:57:46 2016 : Info: expand: %{debug:3} -> 0
Fri Jun 3 14:57:46 2016 : Info: +++} # update control = noop
Fri Jun 3 14:57:46 2016 : Info: ++} # if ("%{User-Name}" == "682808") = noop
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1434
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1434
Fri Jun 3 14:57:46 2016 : Info: ++[preprocess] = ok
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: calling auth_log (rlm_detail) for request 1434
Fri Jun 3 14:57:46 2016 : Info: [auth_log] expand: %{Packet-Src-IP-Address} -> 10.10.10.200
Fri Jun 3 14:57:46 2016 : Info: [auth_log] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d -> /var/log/freeradius/radacc$
Fri Jun 3 14:57:46 2016 : Info: [auth_log] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10$
Fri Jun 3 14:57:46 2016 : Info: [auth_log] expand: %t -> Fri Jun 3 14:57:46 2016
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: returned from auth_log (rlm_detail) for request 1434
Fri Jun 3 14:57:46 2016 : Info: ++[auth_log] = ok
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: calling files (rlm_files) for request 1434
Fri Jun 3 14:57:46 2016 : Info: [files] users: Matched entry DEFAULT at line 62
Fri Jun 3 14:57:46 2016 : Info: [files] users: Matched entry DEFAULT at line 65
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: returned from files (rlm_files) for request 1434
Fri Jun 3 14:57:46 2016 : Info: ++[files] = ok
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: calling monthlycounter (rlm_counter) for request 1434
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: returned from monthlycounter (rlm_counter) for request 1434
Fri Jun 3 14:57:46 2016 : Info: ++[monthlycounter] = ok
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: calling expiration (rlm_expiration) for request 1434
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: returned from expiration (rlm_expiration) for request 1434
Fri Jun 3 14:57:46 2016 : Info: ++[expiration] = noop
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: calling logintime (rlm_logintime) for request 1434
Fri Jun 3 14:57:46 2016 : Info: modsingle[authorize]: returned from logintime (rlm_logintime) for request 1434
Fri Jun 3 14:57:46 2016 : Info: ++[logintime] = noop
Fri Jun 3 14:57:46 2016 : Info: +} # group authorize = ok
Fri Jun 3 14:57:46 2016 : Info: Found Auth-Type = Accept
Fri Jun 3 14:57:46 2016 : Info: Auth-Type = Accept, accepting the user
Fri Jun 3 14:57:46 2016 : Auth: Login OK: [682808/<via Auth-Type = Accept>] (from client localhost port 0 cli 682808)
Fri Jun 3 14:57:46 2016 : Info: WARNING: Empty post-auth section. Using default return values.
Fri Jun 3 14:57:46 2016 : Info: Sending Access-Accept packet to host 10.10.10.200 port 49777, id=15, length=0
Fri Jun 3 14:57:46 2016 : Info: Auth-Type := Reject
Fri Jun 3 14:57:46 2016 : Info: h323-credit-time = "h323-credit-time=900"
Fri Jun 3 14:57:46 2016 : Info: Session-Timeout = 5977
Fri Jun 3 14:57:46 2016 : Info: Finished request 1434.
Fri Jun 3 14:57:48 2016 : Info: Cleaning up request 1434 ID 15 with timestamp +2483
Not authorize:
Fri Jun 3 15:18:27 2016 : Info: expand: %{debug:3} -> 0
Fri Jun 3 15:18:27 2016 : Info: +++} # update control = noop
Fri Jun 3 15:18:27 2016 : Info: ++} # if ("%{User-Name}" == "682808") = noop
Fri Jun 3 15:18:27 2016 : Info: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2273
Fri Jun 3 15:18:27 2016 : Auth: [preprocess] No huntgroup access: [682808] (from client localhost port 0 cli 682808)
Fri Jun 3 15:18:27 2016 : Info: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2273
Fri Jun 3 15:18:27 2016 : Info: ++[preprocess] = reject
Fri Jun 3 15:18:27 2016 : Info: +} # group authorize = reject
Fri Jun 3 15:18:27 2016 : Auth: Invalid user: [682808/<no User-Password attribute>] (from client localhost port 0 cli 682808)
Fri Jun 3 15:18:27 2016 : Info: Using Post-Auth-Type REJECT
Fri Jun 3 15:18:27 2016 : Info: WARNING: Unknown value specified for Post-Auth-Type. Cannot perform requested action.
Fri Jun 3 15:18:27 2016 : Info: Delaying reject of request 2273 for 1 seconds
Fri Jun 3 15:18:28 2016 : Info: Sending delayed reject for request 2273
Fri Jun 3 15:18:28 2016 : Info: Sending Access-Reject packet to host 10.10.10.200 port 46827, id=42, length=0
Fri Jun 3 15:18:30 2016 : Info: Cleaning up request 2273 ID 42 with timestamp +3724
I would be grateful for any ideas.
More information about the Freeradius-Users
mailing list