access reject problem
Hi List, I am seeing strange behaviour when using auth-type reject for a user. We are running version 3.0.12. # radiusd -X FreeRADIUS Version 3.0.12 The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes. Below the radpostauth shows the continual rejects which it has been rejected all day then all of a sudden at 00:02:46 the session starts. Does anyone have an explanation or idea as to why this would occur? Radcheck: username | Simultaneous-Use | := | 1 username | Cleartext-Password | := | password username | Auth-Type | := | Reject username | Calling-Station-Id | := | number radpostauth: username | Access-Reject | 2017-01-13 00:02:16 username | Access-Reject | 2017-01-13 00:02:00 username | Access-Reject | 2017-01-13 00:01:34 username | Access-Reject | 2017-01-13 00:01:09 username | Access-Reject | 2017-01-13 00:00:43 username | Access-Reject | 2017-01-13 00:00:18 radacct: username | acctstarttime username | 2017-01-13 00:02:46 Thanks, Greg
On Fri, Jan 13, 2017 at 07:18:16AM +0000, Greg Antic wrote:
The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes.
Does anyone have an explanation or idea as to why this would occur?
Maybe try asking FreeRADIUS with -X? Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
Yes I did but it takes hours before this occurs and I always miss the event. Ive not looked yet but perhaps I can output the -X to file to review. -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+greg.antic=stc.za.com@lists.freeradius.org] On Behalf Of Matthew Newton Sent: Friday, 13 January 2017 12:00 PM To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: access reject problem On Fri, Jan 13, 2017 at 07:18:16AM +0000, Greg Antic wrote:
The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes.
Does anyone have an explanation or idea as to why this would occur?
Maybe try asking FreeRADIUS with -X? Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk> - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Fri, Jan 13, 2017 at 11:34:21AM +0000, Greg Antic wrote:
Yes I did but it takes hours before this occurs and I always miss the event. Ive not looked yet but perhaps I can output the -X to file to review.
Take a look at raddebug (and/or radmin). You can set a condition for debug outputs to help filter down the logs that are written. All we can do here without debug logs is guess, which isn't particularly helpful for you or us... Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
Agreed, I'll work on getting the logs. On version 2.2.9 this never happened, we have only been on 3.0.12 for a few months, since October 16. -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+greg.antic=stc.za.com@lists.freeradius.org] On Behalf Of Matthew Newton Sent: Friday, 13 January 2017 1:42 PM To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: access reject problem On Fri, Jan 13, 2017 at 11:34:21AM +0000, Greg Antic wrote:
Yes I did but it takes hours before this occurs and I always miss the event. Ive not looked yet but perhaps I can output the -X to file to review.
Take a look at raddebug (and/or radmin). You can set a condition for debug outputs to help filter down the logs that are written. All we can do here without debug logs is guess, which isn't particularly helpful for you or us... Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk> - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On 13/01/2017 07:18, Greg Antic wrote:
The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes.
Firstly, do you have a log which shows that FreeRADIUS actually returned Access-Accept? Turning on auth detail logging may help here - or better, capture all the radius traffic with tcpdump. If FreeRADIUS returned Access-Reject (which apparently the logs say), but the NAS allowed a session to start, then clearly the NAS is at fault. I'd want tcpdump evidence to be sure it's that. The alternative explanation is that FreeRADIUS is occasionally returning Access-Accept instead of Access-Reject, and again tcpdump will show you if that's the case. If so, you might want to check how you've configured the database query. If there is a temporary failure to retrieve the mysql query results, you want FreeRADIUS to reject, not to continue as if there was a successful query with no results. In particular: - are you using configurable failover between multiple databases? - if so, have you ensured that if all sources are unavailable, the default is to reject? It might be useful if you could simulate a mysql query error, for example by sending a bad SQL query or by shutting down the database, and seeing what happens in those circumstances. But it seems rather odd, because your radcheck table contains the Cleartext-Password as well as the Auth-Type; so for a successful auth I would have thought at least the Cleartext-Password was being retrieved successfully. This makes it seem unlikely that the database query is the problem. Regards, Brian.
Firstly, do you have a log which shows that FreeRADIUS actually returned Access-Accept? Turning on auth detail logging may help here - or better, capture all the radius traffic with tcpdump.
I can see the start radius packet in the NAS log, I will look at detail logging and packet capture.
If so, you might want to check how you've configured the database query. If there is a temporary failure to retrieve the mysql query results, you want FreeRADIUS to reject, not to continue as if there was a successful query with no results.
When our mysql connection is "offline" nobody can authenticate to get a session. I had a look through the config files but can't see where you would set an implicit reject or default action? We use mysql on the same box so all connections are local. This is an account on an ADSL network, there are multiple NAS's sending the authentication requests to freeradius from the ADSL network. Right now the way I am preventing the account from coming up again is by changing the allowed calling id. Matthew has guided me on getting some logs so will travel the road and revert. -----Original Message----- From: Brian Candler [mailto:b.candler@pobox.com] Sent: Friday, 13 January 2017 1:12 PM To: Greg Antic <greg.antic@stc.za.com>; freeradius-users@lists.freeradius.org Subject: Re: access reject problem On 13/01/2017 07:18, Greg Antic wrote:
The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes.
Firstly, do you have a log which shows that FreeRADIUS actually returned Access-Accept? Turning on auth detail logging may help here - or better, capture all the radius traffic with tcpdump. If FreeRADIUS returned Access-Reject (which apparently the logs say), but the NAS allowed a session to start, then clearly the NAS is at fault. I'd want tcpdump evidence to be sure it's that. The alternative explanation is that FreeRADIUS is occasionally returning Access-Accept instead of Access-Reject, and again tcpdump will show you if that's the case. If so, you might want to check how you've configured the database query. If there is a temporary failure to retrieve the mysql query results, you want FreeRADIUS to reject, not to continue as if there was a successful query with no results. In particular: - are you using configurable failover between multiple databases? - if so, have you ensured that if all sources are unavailable, the default is to reject? It might be useful if you could simulate a mysql query error, for example by sending a bad SQL query or by shutting down the database, and seeing what happens in those circumstances. But it seems rather odd, because your radcheck table contains the Cleartext-Password as well as the Auth-Type; so for a successful auth I would have thought at least the Cleartext-Password was being retrieved successfully. This makes it seem unlikely that the database query is the problem. Regards, Brian.
On 13/01/2017 12:19, Greg Antic wrote:
Firstly, do you have a log which shows that FreeRADIUS actually returned Access-Accept? Turning on auth detail logging may help here - or better, capture all the radius traffic with tcpdump. I can see the start radius packet in the NAS log, I will look at detail logging and packet capture. When you say "start", do you mean an Accounting-Start packet sent by the NAS?
Then that doesn't answer my question of whether FreeRadius returned Access-Accept or Access-Reject to the authentication request. It would be really weird if a NAS receives Access-Reject and still goes ahead and starts the session anyway. However it would be equally weird if FreeRADIUS were to send Access-Accept even though you have set Auth-Type := Reject. You need to prove one way or another what's going on.
When our mysql connection is "offline" nobody can authenticate to get a session. I had a look through the config files but can't see where you would set an implicit reject or default action? We use mysql on the same box so all connections are local.
OK, so it sounds like you're not using configurable failover. The behaviour I mentioned is implicit. In your "authorize" section I expect you have something like this: ... sql ... Every module can return one of a number of return codes. FreeRADIUS has a default action associated with each return code: notfound = 1 noop = 2 ok = 3 updated = 4 fail = return reject = return userlock = return invalid = return handled = return What this means is, for example, a status of "fail" will cause the authorize block to return immediately. A status of "notfound", "noop", "ok" or "updated" will continue onto the next module in the block, remembering the associated priority value. If execution continues to the very end of the block, then the final result code used is the one with the priority value. In the case of the sql module, if it failed to communicate with the backend server, you'd get a "fail" response and your authorize section would terminate at that point (fail = return). But a more sophisticated configuration would override these defaults so for example it would try a second sql instance. In that case, "fail" is no longer a hard error response from the mysql module. The details are in doc/configuration/configurable_failover.rst in the freeradius source. Regards, Brian.
On 13/01/2017 14:13, Brian Candler wrote:
It would be really weird if a NAS receives Access-Reject and still goes ahead and starts the session anyway.
Aside: I have a vague feeling that in the distant past I came across a NAS that could be configured so that if it received no RADIUS authentication response at all, it defaulted to access accept. This would have been way back in the days of pay-as-you-go dial-up Internet access. So it may also be worth shutting down the NIC on the RADIUS server, and trying to authenticate. I would expect the NAS would resend Access-Request packets two or three times; then you can see what happens if it gets no response to any of them. Note that this is not the same as just shutting down the radiusd process, since in that case the OS will send back an ICMP "port unreachable" message which might be handled differently by the NAS.
hi, other idea - the NAS has another RADIUS server to authenticate against....after failing enough times against the one being looked at, its flipped over to another one, the user got auth'd okay on the other one....then when it came to RADIUS accounting, the NAS sent the accounting packet to the RADIUS server being looked at (as its first in list and probably hasnt failed for acct ACKs so is alive). alan
On Jan 13, 2017, at 2:18 AM, Greg Antic <greg.antic@stc.za.com> wrote:
The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes.
That doesn't happen.
Below the radpostauth shows the continual rejects which it has been rejected all day then all of a sudden at 00:02:46 the session starts.
To be clear, the radpostauth table shows nothing but rejects. The radacct table shows a session.
Does anyone have an explanation or idea as to why this would occur?
The NAS is broken. What most people don't know is that authentication and accounting are entirely separate. The NAS doesn't need an Access-Accept to start an accounting session. It can just send accounting packets. So if the radpostauth table shows nothing but rejects, and there's a session in radacct... the NAS is broken. If you care to prove it to yourself, do: $ radsniff -r 'Packet-Type == Access-Accept' and leave that running for hours. You should see nothing being printed. That means the server isn't sending Access-Accept. Alan DeKok.
The radpostauth table shows the rejects up until the point that a session starts in radacct and then the rejects stop in the radpostauth table, I wasn’t clear on that initially below. When the session arrives in the radacct table the customer goes back online like a full successful authentication has taken place. -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+greg.antic=stc.za.com@lists.freeradius.org] On Behalf Of Alan DeKok Sent: Friday, 13 January 2017 2:38 PM To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: access reject problem On Jan 13, 2017, at 2:18 AM, Greg Antic <greg.antic@stc.za.com> wrote:
The user account has been disabled and the auth-type set as per radcheck output below. The logs show rejected for many hours and all of a sudden it will start a session however the postauth table shows it was rejected. It's almost like freeradius gets tired of saying no and eventually gives in and says yes.
That doesn't happen.
Below the radpostauth shows the continual rejects which it has been rejected all day then all of a sudden at 00:02:46 the session starts.
To be clear, the radpostauth table shows nothing but rejects. The radacct table shows a session.
Does anyone have an explanation or idea as to why this would occur?
The NAS is broken. What most people don't know is that authentication and accounting are entirely separate. The NAS doesn't need an Access-Accept to start an accounting session. It can just send accounting packets. So if the radpostauth table shows nothing but rejects, and there's a session in radacct... the NAS is broken. If you care to prove it to yourself, do: $ radsniff -r 'Packet-Type == Access-Accept' and leave that running for hours. You should see nothing being printed. That means the server isn't sending Access-Accept. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Jan 13, 2017, at 8:33 AM, Greg Antic <greg.antic@stc.za.com> wrote:
The radpostauth table shows the rejects up until the point that a session starts in radacct and then the rejects stop in the radpostauth table, I wasn’t clear on that initially below.
I understand. Are you logging Access-Accepts in the radpostauth table? From the looks of it, the answer is either (1) No, or (2) yes, and there are no Access-Accepts being sent.
When the session arrives in the radacct table the customer goes back online like a full successful authentication has taken place.
Please read what I read. I don't want to think I wasted my time trying to help you. The NAS is in *complete control* of the user access. The RADIUS server is acting only as an advisor. If FreeRADIUS sends an Access-Reject, the NAS may still allow the user on... if it's broken. There is nothing that FreeRADIUS can do about this. Again, you need to find out what's happening. Log Access-Accepts, and use radsniff as a double-check. If FreeRADIUS never sends Access-Accepts but the NAS still lets the user on... the NAS is broken. Throw it in the garbage, and buy a new one. There is just no situation possible where FreeRADIUS magically returns an Access-Accept. There *are* situations possible where a NAS is broken. Or where a NAS has a "fail to accept" VLAN, and lets the user on when the server returns a reject, or is unresponsive. Alan DeKok.
participants (5)
-
A.L.M.Buxey＠lboro.ac.uk -
Alan DeKok -
Brian Candler -
Greg Antic -
Matthew Newton