September 2015 - Freeradius-Users - lists.freeradius.org

otpd - resurrecting it
by Michael A Hawkins 23 Sep '15

23 Sep '15

I am trying to resurrect otpd, a GPL fork is here "https://code.google.com/p/otpd/. I like this thing because it allows me to run my own OTP service with OATH compliant event based tokens of almost any kind. I never got any time based tokens working and I don't really care. Years ago, I got otpd working by running it as radiusd so that FreeRadius could interact with it. This required setting all rights on all otpd related files and /var/run/otpd/socket to be owned and perm'd for radiusd. I don't know enough about LINUX to know why radiusd had to run otpd but I do remember that no matter what I did, if radiusd did not have rights to /var/run/otpd/socket then FreeRadius was always denied permission when attempting to interact with otpd. Compiling the otpd code was also a challenge because I mostly run Fedora and C files, ./configure and make files all had to be messed with. But I managed. The problem I face now though is that if I do everything I originally did as above I get all the way to authenticating and freeradius always fails the authentication and otpd seg faults. otptest executable works just fine (while running as user otpd, I haven't worked out how to use radiusd while running otptest. I always get... [root@HP-LAB-1 otpd]# su -l radiusd otptest This account is currently not available. I can use tokens and confirm that otpd is working with otptest if and only if I use root while otpd itself is running as root. The major changes that I used to make to FreeRadius configuration was: 4. Now edit the /etc/raddb/sites-available/default file and add a single line with text “otp” inside of both the authorize and authenticate sections. 5. Now add the same “otp” entries into the same sections found in the file /etc/raddb/sites_enabled/inner-tunnel. 6. Restart radiusd with “service radiusd restart”. I added otp to default and inner-tunnel like below (right underneath the heading: authorize { otp ... } authenticate { otp ... } Executing radtest... [mhawkins@HP-LAB-1 bNAC]$ radtest test1 885115 localhost 10 testing123 Sending Access-Request of id 84 to 127.0.0.1 port 1812 User-Name = "test1" User-Password = "885115" NAS-IP-Address = 127.0.0.1 NAS-Port = 10 Message-Authenticator = 0x00000000000000000000000000000000 rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=84, length=20 Debug from freeradius looks like... rad_recv: Access-Request packet from host 127.0.0.1 port 37633, id=84, length=75 User-Name = "test1" User-Password = "885115" NAS-IP-Address = 127.0.0.1 NAS-Port = 10 Message-Authenticator = 0x54ce669945c80bffd886fce32b90a76a # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} rlm_otp: otp_pwe_present: password attributes 2, 2 ++[otp] returns ok ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "test1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop Found Auth-Type = otp # Executing group from file /etc/raddb/sites-enabled/default +- entering group authenticate {...} rlm_otp: otp_pwe_present: password attributes 2, 2 ++[otp] returns fail Failed to authenticate the user. Using Post-Auth-Type REJECT # Executing group from file /etc/raddb/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> test1 attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 6 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 6 Sending Access-Reject of id 84 to 127.0.0.1 port 37633 Waking up in 4.9 seconds. Cleaning up request 6 ID 84 with timestamp +858 Ready to process requests. All of the above results in otpd still running. But if I run radtest once more... otpd segfaults and leaves the /var/run/otpd/socket inaccessible by radiusd. I can see that otpd passes the authentication but freeradius doesn't see it. Sep 22 22:16:59 HP-LAB-1 otpd[9352]: accept_thread: plugin accept fd=8 Sep 22 22:16:59 HP-LAB-1 otpd[9352]: work_thread(140561874147072,8): handling plugin request for [test1] Sep 22 22:16:59 HP-LAB-1 otpd[9352]: verify: user [test1] authentication succeeded So I don't know why FreeRadius is failing the authentication and I don't know why otpd is segfaulting (this is the first time I've ever had to work on an executable that does that). Any help or hints on how to solve or troubleshoot this would be *VERY* much appreciated. /Mike Hawkins

4 3

dynamic home server
by Jorge Pereira 22 Sep '15

22 Sep '15

Hi, Someone know if is possible to setup a home-serverpool dynamically?

2 2

rlm_python failing
by Andrew Parisio 22 Sep '15

22 Sep '15

We use rlm_python and AWS DynamoDB as a backend, and over the weekend there were some problems with DynamoDB: http://venturebeat.com/2015/09/20/amazons-aws-outage-takes-down-netflix-red…. During this time we saw lots of dynamo errors, but we also started to see a lot of freeradius problems: Sun Sep 20 09:22:18 2015 : WARNING: (27733) WARNING: Module rlm_python became unblocked for request 27733 Sun Sep 20 09:22:37 2015 : Error: Unresponsive child for request 27751, in component accounting module python During this timeframe I see a few things in my statistics: * Our python code taking as long as 4,500 seconds to respond to requests (freeradius is configured to 30 seconds max per request) [image: Inline image 1] * Accounting requests went from 100/5minutes to 17,000/5minutes (as devices were resending accounting packets because they didn't get a response) [image: Inline image 4] These errors kept accumulating and eventually our server wasn't sending any incoming requests to python (and it didn't recover when dynamo recovered), which I know because the python code should have created external logs that don't exist during this time period. This morning I turned on debugging on a node and this is what I see: Mon Sep 21 18:14:46 2015 : Debug: (870048) accounting { Mon Sep 21 18:14:46 2015 : Debug: (870048) modsingle[accounting]: calling python (rlm_python) for request 870048 Mon Sep 21 18:14:46 2015 : Debug: (870048) python: Using thread state 0x7f1058000cc0 Mon Sep 21 18:14:46 2015 : Debug: (870048) modsingle[accounting]: returned from python (rlm_python) for request 870048 Mon Sep 21 18:14:46 2015 : Debug: (870048) [python] = fail Mon Sep 21 18:14:46 2015 : Debug: (870048) } # accounting = fail Mon Sep 21 18:14:46 2015 : Debug: (870048) Not sending reply to client. The first line in our python accounting module is to radlog() so I know if the request hit our code, and that wasn't even happening so it seems as though FreeRADIUS+rlm_python had failed in some way. Restarting freeradius resolved the problem. I'm fairly certain the long request time problem is because the default timeout for the dynamo SDK is none (wait forever). I'm working on setting a boto timeout to prevent the long response time from happening again, but at the moment I'm concerned about how freeradius was failing to even call python after a while. Aside from the boto timeout issue how would we go about debugging the freeradius+python problem to make sure it doesn't happen in the future? Thanks! Andrew

4 6

RadPerf failover test
by Daniel M. 22 Sep '15

22 Sep '15

Hi all, is there a way to use two ip adresses in radperf so that you can check fail-over/load-balance of two freeradius servers? Or is there another way to test it? Regards, Daniel

2 2

Unexpected response - Freeradius 3.0.10
by Michal Tomaszewski 22 Sep '15

22 Sep '15

Hello, Freeradius – last build from repo – reject response adds unexpected values when SQL is not available. Default configuration straight from repo, SQL enabled, empty mysql database. When I call: echo "User-Name=service-check,User-Password=somepassword,Framed-Protocol=PPP " | radclient -x -r 1 -t 2 server_address:1812 auth testing123 I get: Sending Access-Request of id 118 to server_address port 1812 User-Name = "service-check" User-Password = " somepassword " Framed-Protocol = PPP rad_recv: Access-Reject packet from host server_address port 1812, id=118, length=20 When SQL server is down calling the same: echo "User-Name=service-check,User-Password=somepassword,Framed-Protocol=PPP " | radclient -x -r 1 -t 2 server_address:1812 auth testing123 Gives: Sending Access-Request of id 239 to server_address 8 port 1812 User-Name = "service-check" User-Password = " somepassword" Framed-Protocol = PPP rad_recv: Access-Reject packet from host server_address port 1812, id=239, length=32 Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP It seems that response adds Framed-Protocol and Framed-Compression responses when SQL is not available. In debug there is: Mon Sep 21 19:57:11 2015 : Debug: (2) Post-Auth-Type REJECT { Mon Sep 21 19:57:11 2015 : Debug: (2) modsingle[post-auth]: calling sql (rlm_sql) for request 2 Mon Sep 21 19:57:11 2015 : Debug: .query Mon Sep 21 19:57:11 2015 : Debug: Parsed xlat tree: Mon Sep 21 19:57:11 2015 : Debug: literal --> .query Mon Sep 21 19:57:11 2015 : Debug: (2) sql: EXPAND .query Mon Sep 21 19:57:11 2015 : Debug: (2) sql: --> .query Mon Sep 21 19:57:11 2015 : Debug: (2) sql: Using query template 'query' Mon Sep 21 19:57:11 2015 : Debug: rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" Mon Sep 21 19:57:11 2015 : Info: rlm_sql (sql): Opening additional connection (3), 1 of 32 pending slots used Mon Sep 21 19:57:11 2015 : Debug: rlm_sql_mysql: Starting connect to MySQL server Mon Sep 21 19:57:11 2015 : Error: rlm_sql_mysql: Couldn't connect to MySQL server radius@127.0.0.1:Radius-DB Mon Sep 21 19:57:11 2015 : Error: rlm_sql_mysql: MySQL error: Can't connect to MySQL server on '127.0.0.1' (111) Mon Sep 21 19:57:11 2015 : Debug: rlm_sql_mysql: Socket destructor called, closing socket Mon Sep 21 19:57:11 2015 : Error: rlm_sql (sql): Opening connection failed (3) Mon Sep 21 19:57:11 2015 : Debug: (2) modsingle[post-auth]: returned from sql (rlm_sql) for request 2 Mon Sep 21 19:57:11 2015 : Debug: (2) [sql] = fail Mon Sep 21 19:57:11 2015 : Debug: (2) } # Post-Auth-Type REJECT = fail Mon Sep 21 19:57:11 2015 : Debug: (2) Delaying response for 1.000000 seconds Mon Sep 21 19:57:11 2015 : Debug: Waking up in 0.3 seconds. Mon Sep 21 19:57:11 2015 : Debug: Waking up in 0.6 seconds. Mon Sep 21 19:57:12 2015 : Debug: (2) <REQUEST_RESPONSE_DELAY>: Sending delayed response Mon Sep 21 19:57:12 2015 : Debug: (2) <REQUEST_RESPONSE_DELAY>: Sent Access-Reject Id 100 from 10.10.10.10:1812 to EXT_ADDRESS:59005 length 32 Mon Sep 21 19:57:12 2015 : Debug: (2) <REQUEST_RESPONSE_DELAY>: Framed-Protocol = PPP Mon Sep 21 19:57:12 2015 : Debug: (2) <REQUEST_RESPONSE_DELAY>: Framed-Compression = Van-Jacobson-TCP-IP Mon Sep 21 19:57:12 2015 : Debug: Waking up in 3.9 seconds. Mon Sep 21 19:57:16 2015 : Debug: (2) <REQUEST_RESPONSE_DELAY>: Cleaning up request packet ID 100 with timestamp +19 Mon Sep 21 19:57:16 2015 : Info: Ready to process requests Is this response correct? Regards, Mike ________________________________________ Uwaga: Treść niniejszej wiadomości może być poufna i objęta zakazem jej ujawniania. Jeśli czytelnik tej wiadomości nie jest jej zamierzonym adresatem, pracownikiem lub pośrednikiem upoważnionym do jej przekazania adresatowi, informujemy że wszelkie rozprowadzanie, rozpowszechnianie lub powielanie niniejszej wiadomości jest zabronione. Jeśli otrzymałeś tę wiadomość omyłkowo, proszę bezzwłocznie odesłać ją nadawcy, a samą wiadomość usunąć z komputera. Dziękujemy. ________________________________ Note: The information contained in this message may be privileged and confidential and protected from disclosure. If the reader of this message is not the intended recipient, or an employee or agent responsible for delivering this message to the intended recipient, you are hereby notified that any dissemination, distribution or copying of this communication is strictly prohibited.If you have received this communication in error, please notify the sender immediately by replying to the message and deleting it from your computer. Thank you. ________________________________

2 4

RE: Backtrace of ldap related crash
by Franks Andy (IT Technical Architecture Manager) 22 Sep '15

22 Sep '15

Hi Alan, Drat, I fixed AD (memory leak) and now it's not likely to happen again until the next time, which could be a while away. I guess I'd best come back then :-) Sorry about that. Thanks Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Alan DeKok Sent: 22 September 2015 13:11 To: FreeRadius users mailing list Subject: Re: Backtrace of ldap related crash On Sep 22, 2015, at 6:16 AM, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: > Backtrace: > > Program received signal SIGSEGV, Segmentation fault. > 0x00007ffff2fc2b8a in mod_authorize (instance=0xb3c680, request=0xd5f060) at src/modules/rlm_ldap/rlm_ldap.c:1455 > 1455 if (rlm_ldap_map_do(inst, request, conn->handle, &expanded, entry) > 0) rcode = RLM_MODULE_UPDATED; That's a weird place to have a crash. Can you do: (gdb) p *conn (gdb) p request Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

4 3

Return not working in 2.2.8?
by Jonathan 22 Sep '15

22 Sep '15

Hi, The server version is 2.2.8; In case the user is not found in our system and we are not doing EAP (as EAP doesn't support webredirects) we want to redirect them to a registration page. authorize { # All other default stuff ... # See "Authorization Queries" in sql.conf sql{ notfound = 1 } # Redirect unknown users to registration page # Do this only for captive-portal users if(notfound){ # Add failsafe when eap{ ok=return } is disabled if(EAP-Message){ notfound } else{ # Redirect unknown user to registration page register.redirect # do not parse other modules in authorize section return } } I tried to add the 'return' action to make avoid processing of the other authorize modules to save precious CPU cycles. However, the server throws an error: Module: Loading virtual module register.redirect /etc/freeradius/sites-enabled/default[197]: Failed to find "return" in the "modules" section. /etc/freeradius/sites-enabled/default[197]: Failed to parse "return" entry. /etc/freeradius/sites-enabled/default[193]: Failed to parse "else" subsection. /etc/freeradius/sites-enabled/default[69]: Errors parsing authorize section. I also tried notfound = return (as in the example of the EAP return message) Without the 'return' action, all works, but unnecessarily parses the other authorize modules which I want to avoid. Not sure what i'm doing wrong here, i followed the docs from http://freeradius.org/radiusd/man/unlang.html

2 1

It's possible to point a accounting packet to another virtual-server using VirtualServer?
by Jorge Pereira 22 Sep '15

22 Sep '15

Hi, I have a setup with many kinds of NAS, something like. 1) I have a default accounting server <set> # # Servidor de accounting # listen { type = acct ipaddr = * port = 1813 virtual_server = default-accounting } server default-accounting { preacct { if (!Acct-Status-Type) { do_not_respond } if ((&Acct-Status-Type == Accounting-On) || (&Acct-Status-Type == Accounting-Off)) { ok } acct_unique } accounting { attr_filter.accounting_response detail sql_acct } } </set> And I have the same below concept for another's NAS. root@srv1:# cat sites-enabled/server-nas-alcatel server server-nas-alcatel { authorize { ...... } authenticate { ...... } preact { ... doing translates from alcatel avp to intermediate avps. } accounting { # send to default acct virtual server update control { &Virtual-Server := "default-accounting" &FreeRADIUS-Client-Virtual-Server := "default-accounting" } } } root@srv1:# But wihtout success... someone have suggestions? -- Jorge Pereira

2 1

Yet Another PEAP-MSCHAPV2 problem
by Alex Moen 22 Sep '15

22 Sep '15

I have searched through the mailing list and Google for the resolution to this, and I have found quite a bit of information, but I have not yet found the solution to my problem. I am trying to properly configure a FreeRADIUS version 3.0.9 server to authenticate wireless users using PEAP and MSCHAPv2 against a OpenLDAP version 2.4.39. I can authenticate both users that I will be discussing directly against the LDAP server correctly (using "ldapsearch"). However, only one of them work via the wireless connection. I have attached 2 files: - debi-debug.txt: the failing account full debug of radiusd -x - alex-debug.txt: the working account full debug of radiusd -x These dubugs were gathered by attempting to authenticate the same Windows 7 laptop to the 802.1x wireless network. Working laptop, working network, different outcomes with two accounts that both work when authenticated with ldapsearch. When I run the debi-debug.txt text through the web debugger, I get the following lines in red: mschap: ERROR: FAILED: No NT/LM-Password. Cannot perform authentication mschap: ERROR: MS-CHAP2-Response is incorrect [mschap] = reject } # Auth-Type MS-CHAP = reject MSCHAP-Error: ?E=691 R=1 Could not parse new challenge from MS-CHAP-Error: 2 ERROR: MSCHAP Failure This is what I have been searching for, but I can't find any real reason that it works for the alex account but not the debi account. I can provide whatever is needed to find the problem here, I just don't know what will be helpful. TIA! Alex

5 12

Backtrace of ldap related crash
by Franks Andy (IT Technical Architecture Manager) 22 Sep '15

22 Sep '15

Hi all, FreeRADIUS Version 3.1.0 (git #390f216), built from source (just testing!) I'm getting the below when having timeouts and connectivity issues with our ldap servers, normally it's fine, but it's still a crash.. Can anybody tell if this issue is fixed and we should upgrade? Ideally we'd have ldap go completely wrong but freeradius ride on through it. Thanks Andy Debug: (-X) rlm_ldap (ldap2): Bind with cn=LDAPQuery,OU=SpecialUsers,OU=SATHUsers,DC=SATH,DC=nhs,DC=uk to ldap://10.51.0.39:389 failed: Timed out while waiting for server to respond rlm_ldap (ldap2): Failed to reconnect (24), no free connections are available (265) ldap2: ERROR: Bind with cn=LDAPQuery,OU=SpecialUsers,OU=SATHUsers,DC=SATH,DC=nhs,DC=uk to ldap://10.51.0.39:389 failed: Timed out while waiting for server to respond (265) ldap2: Processing user attributes Program received signal SIGSEGV, Segmentation fault. Backtrace: Program received signal SIGSEGV, Segmentation fault. 0x00007ffff2fc2b8a in mod_authorize (instance=0xb3c680, request=0xd5f060) at src/modules/rlm_ldap/rlm_ldap.c:1455 1455 if (rlm_ldap_map_do(inst, request, conn->handle, &expanded, entry) > 0) rcode = RLM_MODULE_UPDATED; (gdb) bt #0 0x00007ffff2fc2b8a in mod_authorize (instance=0xb3c680, request=0xd5f060) at src/modules/rlm_ldap/rlm_ldap.c:1455 #1 0x00000000004297bb in call_modsingle (component=RLM_COMPONENT_AUTZ, sp=0xc121e0, request=0xd5f060) at src/main/modcall.c:302 #2 0x0000000000429f52 in modcall_recurse (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=5, entry=0x7fffffffd828, do_next_sibling=false) at src/main/modcall.c:584 #3 0x000000000042999e in modcall_child (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=5, entry=0x7fffffffd810, c=0xc121e0, result=0x7fffffffb8f0, do_next_sibling=false) at src/main/modcall.c:408 #4 0x000000000042b241 in modcall_recurse (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=4, entry=0x7fffffffd810, do_next_sibling=true) at src/main/modcall.c:963 #5 0x000000000042999e in modcall_child (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=4, entry=0x7fffffffd7f8, c=0xc12020, result=0x7fffffffbf30, do_next_sibling=true) at src/main/modcall.c:408 #6 0x000000000042aa27 in modcall_recurse (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=3, entry=0x7fffffffd7f8, do_next_sibling=true) at src/main/modcall.c:788 #7 0x000000000042999e in modcall_child (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=3, entry=0x7fffffffd7e0, c=0xc11f20, result=0x7fffffffc570, do_next_sibling=true) at src/main/modcall.c:408 #8 0x000000000042aff2 in modcall_recurse (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=2, entry=0x7fffffffd7e0, do_next_sibling=true) at src/main/modcall.c:925 #9 0x000000000042999e in modcall_child (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=2, entry=0x7fffffffd7c8, c=0xc11930, result=0x7fffffffcbb0, do_next_sibling=true) at src/main/modcall.c:408 #10 0x000000000042aa27 in modcall_recurse (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=1, entry=0x7fffffffd7c8, do_next_sibling=true) at src/main/modcall.c:788 #11 0x000000000042999e in modcall_child (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=1, entry=0x7fffffffd7b0, c=0xbff230, result=0x7fffffffd1f0, do_next_sibling=true) at src/main/modcall.c:408 #12 0x000000000042aa27 in modcall_recurse (request=0xd5f060, component=RLM_COMPONENT_AUTZ, depth=0, entry=0x7fffffffd7b0, do_next_sibling=true) at src/main/modcall.c:788 #13 0x000000000042b864 in modcall (component=RLM_COMPONENT_AUTZ, c=0xbff130, request=0xd5f060) at src/main/modcall.c:1134 #14 0x0000000000426d1f in indexed_modcall (comp=RLM_COMPONENT_AUTZ, idx=0, request=0xd5f060) at src/main/modules.c:890 #15 0x0000000000429088 in process_authorize (autz_type=0, request=0xd5f060) at src/main/modules.c:2000 #16 0x000000000040f2a3 in rad_authenticate (request=0xd5f060) at src/main/auth.c:436 #17 0x000000000043e09e in request_running (request=0xd5f060, action=1) at src/main/process.c:1492 #18 0x000000000043cef5 in request_queue_or_run (request=0xd5f060, process=0x43df60 <request_running>) at src/main/process.c:986 #19 0x000000000043e94a in request_receive (ctx=0xd5ecf0, listener=0xca6ec0, packet=0xd5ed50, client=0xad7d00, fun=0x40f029 <rad_authenticate>) at src/main/process.c:1751 #20 0x00000000004183e8 in auth_socket_recv (listener=0xca6ec0) at src/main/listen.c:1566 #21 0x0000000000445bc6 in event_socket_handler (xel=0xada7a0, fd=12, ctx=0xca6ec0) at src/main/process.c:4473 #22 0x00007ffff7986bf1 in fr_event_loop (el=0xada7a0) at src/lib/event.c:638 #23 0x00000000004479dc in radius_event_process () at src/main/process.c:5420 #24 0x00000000004319b0 in main (argc=2, argv=0x7fffffffe648) at src/main/radiusd.c:581

2 1