Alan DeKok wrote:
"Chris A. Kalin" <cak@netwurx.net> wrote:
Right, the users file has a default Auth-Type := System
Yes, which doesn't affect anything, because the unix module is only used during authentication, and it's proxying, so it's not hitting the unix module.
This makes sense. What I don't get is why the request is sailing through the proxy module (where it apparently receives an "Access-Accept") and then continues INTO the files/unix part of the config, which is where the failure occurs - with no log of the failure to radius.log. Here's an output of the 0.8 server's debug log handling the exact same request: rad_recv: Access-Request packet from host yy.yy.yy.31:1354, id=2, length=60 User-Name = "bob@domain.com" User-Password = "XXXX" modcall: entering group authorize modcall[authorize]: module "preprocess" returns ok rlm_realm: Looking up realm domain.com for User-Name = "bob@domain.com" rlm_realm: Found realm domain.com rlm_realm: Adding Stripped-User-Name = "bob" rlm_realm: Proxying request from user bob to realm domain.com rlm_realm: Adding Realm = "domain.com" rlm_realm: Preparing to proxy authentication request to realm domain.com modcall[authorize]: module "realmat" returns updated rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair modcall[authorize]: module "monthlycounter" returns noop users: Matched DEFAULT at 54 modcall[authorize]: module "files" returns ok rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair modcall[authorize]: module "monthlycounter" returns noop modcall: group authorize returns updated Sending Access-Request of id 1 to xx.xx.xx.xx:1645 User-Name = "bob" User-Password = "\004\315\007\274\t\214\006\315\315JO\344\330\337\275I" NAS-IP-Address = yy.yy.yy.31 Proxy-State = "2" --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Access-Accept packet from host xx.xx.xx.xx:1645, id=1, length=47 Service-Type = Framed-User Framed-Protocol = PPP Session-Timeout = 57600 Idle-Timeout = 900 Proxy-State = 0x32 modcall: entering group authorize modcall[authorize]: module "preprocess" returns ok rlm_realm: Proxy reply, or no user name. Ignoring. modcall[authorize]: module "realmat" returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair modcall[authorize]: module "monthlycounter" returns noop users: Matched DEFAULT at 54 modcall[authorize]: module "files" returns ok rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair modcall[authorize]: module "monthlycounter" returns noop modcall: group authorize returns ok rad_check_password: Found Auth-Type System rad_check_password: Auth-Type = Accept, accepting the user Login OK: [bob@domain.com/Password] (from client yy.yy.yy.31 port 0) Sending Access-Accept of id 2 to yy.yy.yy.31:1354 Service-Type = Framed-User Framed-Protocol = PPP Session-Timeout = 57600 Idle-Timeout = 900 Finished request 0 Going to the next request rl_next: returning NULL Waking up in 6 seconds... --- Walking the entire request list --- Cleaning up request 0 ID 2 with timestamp 4501e9a6 Nothing to do. Sleeping until we see a request. I'll admit there are some steps in there that don't make sense to me either, which suggests that maybe I was relying on a bug or bad behavior before. But even so, if nothing changed, then I should be getting the same bug or bad behavior now, right? If I'm doing this completely wrong in the first place and was simply lucking out before, tell me that and I'll try to learn the correct way. The users file is identical in the 0.8 and 1.1.3 servers, and the radiusd.conf file had minimal changes - I can upload the 0.8 radiusd.conf if you think it'll help. Thanks!