Debug output and users file is included at the end of this message.
When the external program is not involved, the logging mechanism works as expected using the configuration shown below - only failed passwords show up in radius.log. Good passwords are not displayed.
in radius.conf: --------------- log_auth = yes log_auth_badpass = yes log_auth_goodpass = no
When the external program is in the picture (same radius.conf), the following happens:
If the password is good, and the external program returns 0, the access is accepted and the good password is not logged. This is expected behavior. Log entry looks like this:
===============================================================================================
Wed Feb 16 15:55:53 2005 : Auth: Login OK: [dls] (from client BAMNet002 port 1 cli 6096318457)
===============================================================================================
If the password is BAD, the external program isn't executed, as I would expect,
and I and get a log entry that looks like this, which includes the bad password, also as expected:
===============================================================================================
Wed Feb 16 15:57:56 2005 : Info: rlm_sql (sql): No matching entry in the database for request from user [dls]
Wed Feb 16 15:57:56 2005 : Auth: Login incorrect: [dls/badpasswd] (from client BAMNet002 port 1 cli 6096318457)
Wed Feb 16 15:58:17 2005 : Error: rlm_radutmp: Logout for NAS BAMNet002 port 1, but no Login record
===============================================================================================
The error message regarding rlm_radutmp looks odd, but appears to cause no problem. I think the NAS is getting confused, but I'll look into that later.
- - - - - - - - - - -
The above two scenarios are working as expected, per the documentation.
Now for the anomalous behavior:
If the password is GOOD, but the external program returns a non-zero value based on other user considerations, I would expect NOT to see the good password logged, but it IS logged. Log entry looks like this:
===============================================================================================
Wed Feb 16 16:23:39 2005 : Auth: Login incorrect (external check failed): [dls/mygoodpass] (from client BAMNet002 port 1 cli 6096318457)
===============================================================================================
This results in showing good passwords in the log file, which is a security problem. I do want to show bad passwords, to assist the help desk folks, so I don't want to turn off password logging completely.
Is there a way around this? Is this correct behavior given "log_auth_goodpass = no"?
On a related subject, it would be nice to get the return code value from the external program to
show up in the log file. The old Cistron radius provided this. Have I missed some option to add this?
It would be nice to see the message in radius.log read (external check failed: 20) or anything
that would include the return code. This paragraph has been a feature request. Do not confuse this feature request with the rest of this post regarding the improper logging (I think) of good passwords despite setting log_auth_goodpass = no.
Here are some more details:
Version: freeRADIUS 1.0.1 and freeRADIUS 1.0.2
Authentication via mysql.
Hopefully relevant part of debug output: (from 1.0.1 but same result on 1.0.2)
-----------------------------------------
This is output from a request with a GOOD password but external check will fail. I
expect good password NOT to be logged, but it is.
...
...
...
rlm_sql (sql): Released sql socket id: 4
modcall[authorize]: module "sql" returns ok for request 0
modcall: group authorize returns ok for request 0
rad_check_password: Found Auth-Type Local
auth: type Local
auth: user supplied User-Password matches local User-Password
radius_xlat: '/home/dls/perl/radscan3'
Exec-Program: /home/dls/perl/radscan3
Exec-Program output: Reply-Message = Error 20
Exec-Program-Wait: plaintext: Reply-Message = Error 20
Exec-Program: returned: 20
Login incorrect (external check failed): [dls/mygoodpass] (from client BAMNet002 port 1 cli 6096318457)
Delaying request 0 for 1 seconds
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Sending Access-Reject of id 70 to 8.10.241.74:1645
Reply-Message := "Reply-Message = Error 20"
Users file ----------- DEFAULT Exec-Program-Wait = "/home/dls/perl/radscan3", Framed-IP-Address = 255.255.255.254, Framed-MTU = 1500, Service-Type = Framed-User, Fall-Through = Yes
DEFAULT Framed-Protocol == PPP
Framed-Protocol = PPP,
Framed-Compression = Van-Jacobson-TCP-IPDEFAULT Hint == "CSLIP"
Framed-Protocol = SLIP,
Framed-Compression = Van-Jacobson-TCP-IPDEFAULT Hint == "SLIP"
Framed-Protocol = SLIP- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
