January 2017 - Freeradius-Users - lists.freeradius.org

linelog best practice
by cedric delaunay 17 May '17

17 May '17

Hello all, I'm trying to log accounting and requests into our elasticsearch/graylog logserver. I use home made linelog modules to rewrite logs into json format. modules are called in authorize, accounting, post-auth, Post-Auth-Type REJECT, preproxy and post-proxy sections here is an exemple of my module : linelog linelog_postauth { format = "%t linelog_postauth \%Packet-Type non reconnu for %{User-Name} (%{Packet-Type})" filename = ${logdir}/linelog_json permissions = 0600 reference = "messages.%{%{reply:Packet-Type}:-format}" messages { Access-Reject = "{\"Datetime\":\"%t\",\"Module_Name\":\"linelog_postauth\",\"Packet-Type\":\"%{reply:Packet-Type}\",\"User-Name\":\"%{User-Name}\",\"Realm\":\"%{Realm}\",\"NAS-IP-Address\":\"%{NAS-IP-Address}\",\"NAS-Port\":\"%{NAS-Port}\",\"Service-Type\":\"%{Service-Type}\",\"Framed-MTU\":\"%{Framed-MTU}\",\"State\":\"%{State}\",\"Class\":\"%{Class}\",\"Vendor-Specific\":\"%{Vendor-Specific}\",\"Session-Timeout\":\"%{Session-Timeout}\",\"Idle-Timeout\":\"%{Idle-Timeout}\",\"Termination-Action\":\"%{Termination-Action}\",\"Called-Station-Id\":\"%{Called-Station-Id}\",\"Calling-Station-Id\":\"%{Calling-Station-Id}\",\"NAS-Identifier\":\"%{NAS-Identifier}\",\"Proxy-State\":\"%{Proxy-State}\",\"Login-LAT-Service\":\"%{Login-LAT-Service}\",\"Login-LAT-Node\":\"%{Login-LAT-Node}\",\"Login-LAT-Group\":\"%{Login-LAT-Group}\",\"Framed-AppleTalk-Link\":\"%{Framed-AppleTalk-Link}\",\"Framed-AppleTalk-Network\":\"%{Framed-AppleTalk-Network}\",\"Framed-AppleTalk-Zone\":\"%{Framed-AppleTalk-Zone}\",\"CHAP-Challenge\":\"%{CHAP-Challenge}\",\"NAS-Port-Type\":\"%{NAS-Port-Type}\",\"Port-Limit\":\"%{Port-Limit}\",\"Login-LAT-Port\":\"%{Login-LAT-Port}\"}" Access-Challenge = "{\"Datetime\":\"%t\",\"Module_Name\":\"linelog_postauth\",\"Packet-Type\":\"%{reply:Packet-Type}\",\"User-Name\":\"%{User-Name}\",\"Realm\":\"%{Realm}\",\"NAS-IP-Address\":\"%{NAS-IP-Address}\",\"NAS-Port\":\"%{NAS-Port}\",\"Service-Type\":\"%{Service-Type}\",\"Framed-Protocol\":\"%{Framed-Protocol}\",\"Framed-IP-Address\":\"%{Framed-IP-Address}\",\"Framed-IP-Netmask\":\"%{Framed-IP-Netmask}\",\"Framed-Routing\":\"%{Framed-Routing}\",\"Filter-Id\":\"%{Filter-Id}\",\"Framed-MTU\":\"%{Framed-MTU}\",\"Framed-Compression\":\"%{Framed-Compression}\",\"Login-IP-Host\":\"%{Login-IP-Host}\",\"Login-Service\":\"%{Login-Service}\",\"Login-TCP-Port\":\"%{Login-TCP-Port}\",\"Reply-Message\":\"%{Reply-Message}\",\"Callback-Number\":\"%{Callback-Number}\",\"Callback-Id\":\"%{Callback-Id}\",\"Framed-Route\":\"%{Framed-Route}\",\"Framed-IPX-Network\":\"%{Framed-IPX-Network}\",\"State\":\"%{State}\",\"Class\":\"%{Class}\",\"Vendor-Specific\":\"%{Vendor-Specific}\",\"Session-Timeout\":\"%{Session-Timeout}\",\"Idle-Timeout\":\"%{Idle-Timeout}\",\"Termination-Action\":\"%{Termination-Action}\",\"Called-Station-Id\":\"%{Called-Station-Id}\",\"Calling-Station-Id\":\"%{Calling-Station-Id}\",\"NAS-Identifier\":\"%{NAS-Identifier}\",\"Proxy-State\":\"%{Proxy-State}\",\"Login-LAT-Service\":\"%{Login-LAT-Service}\",\"Login-LAT-Node\":\"%{Login-LAT-Node}\",\"Login-LAT-Group\":\"%{Login-LAT-Group}\",\"Framed-AppleTalk-Link\":\"%{Framed-AppleTalk-Link}\",\"Framed-AppleTalk-Network\":\"%{Framed-AppleTalk-Network}\",\"Framed-AppleTalk-Zone\":\"%{Framed-AppleTalk-Zone}\",\"CHAP-Challenge\":\"%{CHAP-Challenge}\",\"NAS-Port-Type\":\"%{NAS-Port-Type}\",\"Port-Limit\":\"%{Port-Limit}\",\"Login-LAT-Port\":\"%{Login-LAT-Port}\"}" Access-Accept = "{\"Datetime\":\"%t\",\"Module_Name\":\"linelog_postauth\",\"Packet-Type\":\"%{reply:Packet-Type}\",\"User-Name\":\"%{User-Name}\",\"Realm\":\"%{Realm}\",\"NAS-IP-Address\":\"%{NAS-IP-Address}\",\"NAS-Port\":\"%{NAS-Port}\",\"Service-Type\":\"%{Service-Type}\",\"Framed-MTU\":\"%{Framed-MTU}\",\"Login-IP-Host\":\"%{Login-IP-Host}\",\"Login-Service\":\"%{Login-Service}\",\"Login-TCP-Port\":\"%{Login-TCP-Port}\",\"Reply-Message\":\"%{Reply-Message}\",\"Callback-Number\":\"%{Callback-Number}\",\"Callback-Id\":\"%{Callback-Id}\",\"Framed-Route\":\"%{Framed-Route}\",\"Framed-IPX-Network\":\"%{Framed-IPX-Network}\",\"State\":\"%{State}\",\"Class\":\"%{Class}\",\"Vendor-Specific\":\"%{Vendor-Specific}\",\"Session-Timeout\":\"%{Session-Timeout}\",\"Idle-Timeout\":\"%{Idle-Timeout}\",\"Termination-Action\":\"%{Termination-Action}\",\"Called-Station-Id\":\"%{Called-Station-Id}\",\"Calling-Station-Id\":\"%{Calling-Station-Id}\",\"NAS-Identifier\":\"%{NAS-Identifier}\",\"Proxy-State\":\"%{Proxy-State}\",\"Login-LAT-Service\":\"%{Login-LAT-Service}\",\"Login-LAT-Node\":\"%{Login-LAT-Node}\",\"Login-LAT-Group\":\"%{Login-LAT-Group}\",\"Framed-AppleTalk-Link\":\"%{Framed-AppleTalk-Link}\",\"Framed-AppleTalk-Network\":\"%{Framed-AppleTalk-Network}\",\"Framed-AppleTalk-Zone\":\"%{Framed-AppleTalk-Zone}\",\"CHAP-Challenge\":\"%{CHAP-Challenge}\",\"NAS-Port-Type\":\"%{NAS-Port-Type}\",\"Port-Limit\":\"%{Port-Limit}\",\"Login-LAT-Port\":\"%{Login-LAT-Port}\",\"VLAN\":\"%{Tunnel-Private-Group-ID:0}\"}" } } the goal is to keep info about login attempts and failure and why. when we run radius in debug mode we can see failure reason as next example : ..... (17) authenticate { (17) eap : Expiring EAP session with state 0x2ee654852ee14efb (17) eap : Finished EAP session with state 0x2ee654852ee14efb (17) eap : Previous EAP request found for state 0x2ee654852ee14efb, released from the list (17) eap : Peer sent method MSCHAPv2 (26) (17) eap : EAP MSCHAPv2 (26) (17) eap : Calling eap_mschapv2 to process EAP data (17) eap_mschapv2 : # Executing group from file /etc/raddb//sites-enabled/eduroam-inner-tunnel (17) eap_mschapv2 : Auth-Type MS-CHAP { (17) mschap : Found LM-Password (17) WARNING: mschap : No Cleartext-Password configured. Cannot create LM-Password (17) mschap : Found NT-Password (17) WARNING: mschap : No Cleartext-Password configured. Cannot create NT-Password (17) mschap : Creating challenge hash with username: cdelauna(a)univ-rennes1.fr (17) mschap : Client is using MS-CHAPv2 (17) ERROR: mschap : MS-CHAP2-Response is incorrect (17) [mschap] = reject (17) } # Auth-Type MS-CHAP = reject (17) eap : Freeing handler (17) [eap] = reject (17) } # authenticate = reject ..... I can't find reject reason (mscahp result, ...) in access-reject variables. I had a look into mailist's archives without success ;( Do anybody can help me to find the best way doing this ? Thanks a lot -- Cédric Delaunay Direction des Systèmes d'Informations Equipe Réseau & Telephonie 263, Avenue du Général Leclerc Tel: 02 23 23 71 59 CS 74205 - 35042 Rennes Cedex Pour toute demande utiliser l'aide et assistance via l'ENT à l'adresse http://ent.univ-rennes1.fr

7 19

Help for buy a real Cert (not self-signed)
by Spider s 04 May '17

04 May '17

Hello, I have got a few questions about radius and buy an original Certificate. Firsts thank you for the help here, but I can’t find an option for search on all post, is this possible ?? only find this: For example only can find post from this mount http://lists.freeradius.org/pipermail/freeradius-users/2017-January/thread.… Is for don’t disturb with my questions is are answered, sorry. And now my questions, first I have got running my freeradius installation 3.10 on ubuntu) with AD Auth, but with limitations, because I need install my self-signed cert on all device for connect to wifi. I don’t want this (I don’t want install the certs), and I need buy a real cert for a real CA, I know ,but I never buy one for this. (I never buy a certfor radius, web or similar) I need buy a real cert, where I can buy ?? recommendations webs?? And witch type ?? I see a lot of certs, and I don’t know the certification specification.( a lot of prices and options) Please a direct links if possible to correct cert. I never buy an original cert and I don’t know process. When I receive the certificates is like certs on the folder?? Need change data??? How can use this certs on my radius install?? Are 3, 5, 20 files ???? where i can find info about this ?? (On docs i reffer) Need a domain for this ?? can i use the cert from a Web (typical ssl cert that is used for web?? I see a lot of info on internet for use self-signed cert, but I can’t find info on documentations or on my Ubuntu install when use real certs. (Is very possible I don’t find) Thank you for your time when you read me, and sorry if a newbie questions. Thank you in advanced, i dont want confuse with this and spend money with this.

6 15

rlm_perl returning attributes
by Ryan De Kock 30 Mar '17

30 Mar '17

Hi. I'm trying to return an attribute using the rlm_rest module. Authentication works fine but when a response is sent, an Access-Reject is generated. I'm hoping someone can point me in the right direction. *Working auth *(with no attributes in the response) (8) Cleaning up request packet ID 178 with timestamp +606 Ready to process requests (9) Received Access-Request Id 17 from 127.0.0.1:45433 to 127.0.0.1:1812 length 77 (9) User-Name = "585c208457bf8c3820c9e431(a)test.com" (9) User-Password = "password" (9) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (9) authorize { rlm_rest (rest): Reserved connection (16) (9) rest: Expanding URI components (9) rest: EXPAND http://127.0.0.1:1337 (9) rest: --> http://127.0.0.1:1337 (9) rest: EXPAND /Radius/auth?username=%{User-Name}&password=%{User-Password} (9) rest: --> /Radius/auth?username=585c208457bf8c3820c9e431%40test.com &password=password (9) rest: Sending HTTP GET to " http://127.0.0.1:1337/Radius/auth?username=585c208457bf8c3820c9e431%40test.… " (9) rest: Processing response header (9) rest: Status : 201 (Created) (9) rest: Type : json (application/json) rlm_rest (rest): Released connection (16) rlm_rest (rest): Need 1 more connections to reach 10 spares rlm_rest (rest): Opening additional connection (17), 1 of 30 pending slots used rlm_rest (rest): Connecting to "http://127.0.0.1:1337" (9) [rest] = ok (9) if (ok || updated) { (9) if (ok || updated) -> TRUE (9) if (ok || updated) { (9) update control { (9) Auth-Type := Rest (9) } # update control = noop (9) } # if (ok || updated) = noop (9) policy filter_username { (9) if (&User-Name) { (9) if (&User-Name) -> TRUE (9) if (&User-Name) { (9) if (&User-Name =~ / /) { (9) if (&User-Name =~ / /) -> FALSE (9) if (&User-Name =~ /@[^@]*@/ ) { (9) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (9) if (&User-Name =~ /\.\./ ) { (9) if (&User-Name =~ /\.\./ ) -> FALSE (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (9) if (&User-Name =~ /\.$/) { (9) if (&User-Name =~ /\.$/) -> FALSE (9) if (&User-Name =~ /(a)\./) { (9) if (&User-Name =~ /(a)\./) -> FALSE (9) } # if (&User-Name) = ok (9) } # policy filter_username = ok (9) [preprocess] = ok (9) [chap] = noop (9) [mschap] = noop (9) [digest] = noop (9) suffix: Checking for suffix after "@" (9) suffix: Looking up realm "test.com" for User-Name = " 585c208457bf8c3820c9e431(a)test.com" (9) suffix: No such realm "test.com" (9) [suffix] = noop (9) eap: No EAP-Message, not doing EAP (9) [eap] = noop (9) [files] = noop (9) [expiration] = noop (9) [logintime] = noop (9) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type (9) pap: WARNING: Authentication will fail unless a "known good" password is available (9) [pap] = noop (9) } # authorize = ok (9) Found Auth-Type = Rest (9) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (9) Auth-Type Rest { rlm_rest (rest): Reserved connection (15) (9) rest: Expanding URI components (9) rest: EXPAND http://127.0.0.1:1337 (9) rest: --> http://127.0.0.1:1337 (9) rest: EXPAND /Radius/auth?username=%{User-Name}&password=%{User-Password} (9) rest: --> /Radius/auth?username=585c208457bf8c3820c9e431%40test.com &password=password (9) rest: Sending HTTP GET to " http://127.0.0.1:1337/Radius/auth?username=585c208457bf8c3820c9e431%40test.… " (9) rest: Processing response header (9) rest: Status : 201 (Created) (9) rest: Type : json (application/json) rlm_rest (rest): Released connection (15) (9) [rest] = ok (9) } # Auth-Type Rest = ok (9) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default (9) post-auth { (9) update { (9) No attributes updated (9) } # update = noop (9) [exec] = noop (9) policy remove_reply_message_if_eap { (9) if (&reply:EAP-Message && &reply:Reply-Message) { (9) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (9) else { (9) [noop] = noop (9) } # else = noop (9) } # policy remove_reply_message_if_eap = noop (9) } # post-auth = noop (9) Sent Access-Accept Id 17 from 127.0.0.1:1812 to 127.0.0.1:45433 length 0 (9) Finished request Waking up in 4.9 seconds. *exactly the same auth*, except I try return some values (8) Received Access-Request Id 178 from 127.0.0.1:41930 to 127.0.0.1:1812 length 77 (8) User-Name = "585c208457bf8c3820c9e431(a)test.com" (8) User-Password = "password" (8) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (8) authorize { rlm_rest (rest): Closing connection (13): Hit idle_timeout, was idle for 239 seconds rlm_rest (rest): You probably need to lower "min" rlm_rest (rest): Closing connection (14): Hit idle_timeout, was idle for 239 seconds rlm_rest (rest): You probably need to lower "min" rlm_rest (rest): Closing connection (12): Hit idle_timeout, was idle for 239 seconds rlm_rest (rest): You probably need to lower "min" rlm_rest (rest): 0 of 0 connections in use. You may need to increase "spare" rlm_rest (rest): Opening additional connection (15), 1 of 32 pending slots used rlm_rest (rest): Connecting to "http://127.0.0.1:1337" rlm_rest (rest): Reserved connection (15) (8) rest: Expanding URI components (8) rest: EXPAND http://127.0.0.1:1337 (8) rest: --> http://127.0.0.1:1337 (8) rest: EXPAND /Radius/auth?username=%{User-Name}&password=%{User-Password} (8) rest: --> /Radius/auth?username=585c208457bf8c3820c9e431%40test.com &password=password (8) rest: Sending HTTP GET to " http://127.0.0.1:1337/Radius/auth?username=585c208457bf8c3820c9e431%40test.… " (8) rest: Processing response header (8) rest: Status : 201 (Created) (8) rest: Type : json (application/json) (8) rest: Parsing attribute "Mikrotik-Address-List" (8) rest: EXPAND myList (8) rest: --> myList (8) rest: Mikrotik-Address-List := "myList" rlm_rest (rest): Released connection (15) rlm_rest (rest): Need 2 more connections to reach 10 spares rlm_rest (rest): Opening additional connection (16), 1 of 31 pending slots used rlm_rest (rest): Connecting to "http://127.0.0.1:1337" (8) [rest] = updated (8) if (ok || updated) { (8) if (ok || updated) -> TRUE (8) if (ok || updated) { (8) update control { (8) Auth-Type := Rest (8) } # update control = noop (8) } # if (ok || updated) = noop (8) policy filter_username { (8) if (&User-Name) { (8) if (&User-Name) -> TRUE (8) if (&User-Name) { (8) if (&User-Name =~ / /) { (8) if (&User-Name =~ / /) -> FALSE (8) if (&User-Name =~ /@[^@]*@/ ) { (8) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (8) if (&User-Name =~ /\.\./ ) { (8) if (&User-Name =~ /\.\./ ) -> FALSE (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (8) if (&User-Name =~ /\.$/) { (8) if (&User-Name =~ /\.$/) -> FALSE (8) if (&User-Name =~ /(a)\./) { (8) if (&User-Name =~ /(a)\./) -> FALSE (8) } # if (&User-Name) = updated (8) } # policy filter_username = updated (8) [preprocess] = ok (8) [chap] = noop (8) [mschap] = noop (8) [digest] = noop (8) suffix: Checking for suffix after "@" (8) suffix: Looking up realm "test.com" for User-Name = " 585c208457bf8c3820c9e431(a)test.com" (8) suffix: No such realm "test.com" (8) [suffix] = noop (8) eap: No EAP-Message, not doing EAP (8) [eap] = noop (8) [files] = noop (8) [expiration] = noop (8) [logintime] = noop (8) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type (8) pap: WARNING: Authentication will fail unless a "known good" password is available (8) [pap] = noop (8) } # authorize = updated (8) Found Auth-Type = Rest (8) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (8) Auth-Type Rest { rlm_rest (rest): Reserved connection (15) (8) rest: Expanding URI components (8) rest: EXPAND http://127.0.0.1:1337 (8) rest: --> http://127.0.0.1:1337 (8) rest: EXPAND /Radius/auth?username=%{User-Name}&password=%{User-Password} (8) rest: --> /Radius/auth?username=585c208457bf8c3820c9e431%40test.com &password=password (8) rest: Sending HTTP GET to " http://127.0.0.1:1337/Radius/auth?username=585c208457bf8c3820c9e431%40test.… " (8) rest: Processing response header (8) rest: Status : 201 (Created) (8) rest: Type : json (application/json) (8) rest: Parsing attribute "Mikrotik-Address-List" (8) rest: EXPAND myList (8) rest: --> myList (8) rest: Mikrotik-Address-List := "myList" rlm_rest (rest): Released connection (15) (8) [rest] = updated (8) } # Auth-Type Rest = updated (8) Failed to authenticate the user (8) Using Post-Auth-Type Reject (8) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (8) Post-Auth-Type REJECT { (8) attr_filter.access_reject: EXPAND %{User-Name} (8) attr_filter.access_reject: --> 585c208457bf8c3820c9e431(a)test.com (8) attr_filter.access_reject: Matched entry DEFAULT at line 11 (8) [attr_filter.access_reject] = updated (8) [eap] = noop (8) policy remove_reply_message_if_eap { (8) if (&reply:EAP-Message && &reply:Reply-Message) { (8) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (8) else { (8) [noop] = noop (8) } # else = noop (8) } # policy remove_reply_message_if_eap = noop (8) } # Post-Auth-Type REJECT = updated (8) Delaying response for 1.000000 seconds Waking up in 0.2 seconds. Waking up in 0.7 seconds. (8) Sending delayed response (8) Sent Access-Reject Id 178 from 127.0.0.1:1812 to 127.0.0.1:41930 length 20 Waking up in 3.9 seconds. It seems that because rest updated the user that it now fails for some reason (8) [rest] = updated (8) } # Auth-Type Rest = updated (8) Failed to authenticate the user What do I need to change to allow this process to go through? I would appreciate any light shedding.

2 3

3.0.4: binary LDAP attributes
by Nikolai Kondrashov 24 Mar '17

24 Mar '17

Hi everyone, Our (Red Hat) QA was testing the effect of this entry in 3.0.4 ChangeLog: * Modify pairparsevalue to deal with embedded NULLs better, and use the binary versions of attribute values in rlm_ldap. They have noticed that binary LDAP values get truncated on embedded zero characters (\0) in RADIUS replies, in radiusReplyMessage in particular. I.e. for radiusReplyMessage:: cmVwbHkgd2l0aCBhAGI= The response output by radtest was Reply-Message = 'reply with a' The network capture also showed that RADIUS reply packets contained truncated values. Is this intended, or was there a fix for this? In related discoveries, it seems that backslashes get removed from LDAP attribute values in RADIUS replies, so radiusReplyMessage: reply with a\0b becomes Reply-Message = 'reply with a0b' in radtest output. Is this intended? Thank you. Nick

4 12

user-group for rejected users
by Fabricio Viana 21 Mar '17

21 Mar '17

Hello! Let´s suppose the following situations: 1) User exists but the password is wrong 2) User does not exist In both cases the answer is REJECT. It happens that certain hardware is making endless attempts that eventually saturating the server. - It is possible to cause the server, instead of rejecting the users, accept the login but responds ACCEPT with "framed-pool = pool-block" ? or/and - Is there any way to put REJECT users in a given group by default? Thanks! Fabricio

3 3

Update on 3.0, 3.1, and 3.2.
by Alan DeKok 16 Feb '17

16 Feb '17

We plan on releasing 3.0.12 on Monday. it's stable, and there no new issues being reported for it. This will ideally be the last release of the 3.0 series. Version 3.0 was released almost three years ago, and it's time for a new major version of the server. 3.1 supports a "map" keyword, redis cluster, and many other useful features. Many people have been using the 3.1 branch in production, so we're confident that it is stable and functional. To keep things simple, we don't release an official 3.1 version. Instead, we will call 3.1 a "development / experimental" branch. Once we're ready (later this summer), we'll release an official 3.2 release. The v3.1.x branch will then be frozen, and no further development will occur on it. All new development will then start with a 3.3 branch, which will likely turn into version 4.0. There are enough architecture changes needed that it warrants a 4.0. In summary: 2.1 and earlier: dead. Don't use them. 2.2: Only critical security fixes. We expect this won't happen. 3.0: stable. New installations can use 3.0. 3.1: development. Use it only if you know what you're doing. 3.2: (future stable). Mid 2016 on, new installations should use this. 3.3. (future development), more changes, with a goal of increasing performance substantially.

4 6

buffered-sql problem
by Jouni Soini 07 Feb '17

07 Feb '17

there seems to be a problem with buffered-sql it sometimes doesn't pick the accounting request from detail file and just skip it. this happens once in a few million requests and I had to debug and monitor this for several days to find one (looking for a user who remains online) nothing special exists in debug logs. the accounting request is logged to detail file but the sql statement part doesn't exits. following is the debug logs as you can see the accounting request is logged to detail file (in my tests to two separate files for extra monitoring) but it is not sent to sql database tested with 3.0.12 version on Ubuntu 16.04 as you can see the sql query for user 'test1' is skipped (494090) Wed Jan 25 12:04:10 2017: Debug: Received Accounting-Request Id 188 from 82.21.11.91:28850 to 82.21.11.50:1813 length 107 (494090) Wed Jan 25 12:04:10 2017: Debug: User-Name = "test1" (494090) Wed Jan 25 12:04:10 2017: Debug: NAS-IP-Address = 82.21.11.91 (494090) Wed Jan 25 12:04:10 2017: Debug: NAS-Port = 23449 (494090) Wed Jan 25 12:04:10 2017: Debug: Acct-Status-Type = Stop (494090) Wed Jan 25 12:04:10 2017: Debug: Framed-IP-Address = 10.8.0.98 (494090) Wed Jan 25 12:04:10 2017: Debug: Acct-Input-Gigawords = 0 (494090) Wed Jan 25 12:04:10 2017: Debug: Acct-Input-Octets = 8323 (494090) Wed Jan 25 12:04:10 2017: Debug: Acct-Output-Octets = 8111 (494090) Wed Jan 25 12:04:10 2017: Debug: Acct-Session-Id = "68r3xt2pb8y8" (494090) Wed Jan 25 12:04:10 2017: Debug: Acct-Output-Gigawords = 0 (494090) Wed Jan 25 12:04:10 2017: Debug: Calling-Station-Id = "127.0.0.1" (494090) Wed Jan 25 12:04:10 2017: Debug: # Executing section preacct from file /etc/freeradius/sites-enabled/default (494090) Wed Jan 25 12:04:10 2017: Debug: preacct { (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[preacct]: calling preprocess (rlm_preprocess) (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[preacct]: returned from preprocess (rlm_preprocess) (494090) Wed Jan 25 12:04:10 2017: Debug: [preprocess] = ok (494090) Wed Jan 25 12:04:10 2017: Debug: policy acct_unique { (494090) Wed Jan 25 12:04:10 2017: Debug: update request { (494090) Wed Jan 25 12:04:10 2017: Debug: Tmp-String-9 := "ai:" (494090) Wed Jan 25 12:04:10 2017: Debug: } # update request = noop (494090) Wed Jan 25 12:04:10 2017: Debug: if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) { (494090) Wed Jan 25 12:04:10 2017: Debug: EXPAND %{hex:&Class} (494090) Wed Jan 25 12:04:10 2017: Debug: --> (494090) Wed Jan 25 12:04:10 2017: Debug: EXPAND ^%{hex:&Tmp-String-9} (494090) Wed Jan 25 12:04:10 2017: Debug: --> ^61693a (494090) Wed Jan 25 12:04:10 2017: Debug: if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE (494090) Wed Jan 25 12:04:10 2017: Debug: else { (494090) Wed Jan 25 12:04:10 2017: Debug: update request { (494090) Wed Jan 25 12:04:10 2017: Debug: EXPAND %{md5:%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (494090) Wed Jan 25 12:04:10 2017: Debug: --> b1cbd13cc01616d5f451e33b24aeb893 (494090) Wed Jan 25 12:04:10 2017: Debug: &Acct-Unique-Session-Id := b1cbd13cc01616d5f451e33b24aeb893 (494090) Wed Jan 25 12:04:10 2017: Debug: } # update request = noop (494090) Wed Jan 25 12:04:10 2017: Debug: } # else = noop (494090) Wed Jan 25 12:04:10 2017: Debug: } # policy acct_unique = noop (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[preacct]: calling suffix (rlm_realm) (494090) Wed Jan 25 12:04:10 2017: Debug: suffix: Checking for suffix after "@" (494090) Wed Jan 25 12:04:10 2017: Debug: suffix: No '@' in User-Name = "test1", looking up realm NULL (494090) Wed Jan 25 12:04:10 2017: Debug: suffix: No such realm "NULL" (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[preacct]: returned from suffix (rlm_realm) (494090) Wed Jan 25 12:04:10 2017: Debug: [suffix] = noop (494090) Wed Jan 25 12:04:10 2017: Debug: } # preacct = ok (494090) Wed Jan 25 12:04:10 2017: Debug: # Executing section accounting from file /etc/freeradius/sites-enabled/default (494090) Wed Jan 25 12:04:10 2017: Debug: accounting { (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: calling detail (rlm_detail) (494090) Wed Jan 25 12:04:10 2017: Debug: detail: EXPAND /var/log/freeradius/radacct/detail-%Y%m%d (494090) Wed Jan 25 12:04:10 2017: Debug: detail: --> /var/log/freeradius/radacct/detail-20170125 (494090) Wed Jan 25 12:04:10 2017: Debug: detail: /var/log/freeradius/radacct/detail-%Y%m%d expands to /var/log/freeradius/radacct/detail-20170125 (494090) Wed Jan 25 12:04:10 2017: Debug: detail: EXPAND %t (494090) Wed Jan 25 12:04:10 2017: Debug: detail: --> Wed Jan 25 12:04:10 2017 (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: returned from detail (rlm_detail) (494090) Wed Jan 25 12:04:10 2017: Debug: [detail] = ok (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: calling detail2 (rlm_detail) (494090) Wed Jan 25 12:04:10 2017: Debug: detail2: EXPAND /var/log/freeradius/radacct/debug/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (494090) Wed Jan 25 12:04:10 2017: Debug: detail2: --> /var/log/freeradius/radacct/debug/82.21.11.91/detail-20170125 (494090) Wed Jan 25 12:04:10 2017: Debug: detail2: /var/log/freeradius/radacct/debug/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/debug/82.21.11.91/detail-20170125 (494090) Wed Jan 25 12:04:10 2017: Debug: detail2: EXPAND %t (494090) Wed Jan 25 12:04:10 2017: Debug: detail2: --> Wed Jan 25 12:04:10 2017 (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: returned from detail2 (rlm_detail) (494090) Wed Jan 25 12:04:10 2017: Debug: [detail2] = ok (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: calling exec (rlm_exec) (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: returned from exec (rlm_exec) (494090) Wed Jan 25 12:04:10 2017: Debug: [exec] = noop (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: calling attr_filter.accounting_response (rlm_attr_filter) (494090) Wed Jan 25 12:04:10 2017: Debug: attr_filter.accounting_response: EXPAND %{User-Name} (494090) Wed Jan 25 12:04:10 2017: Debug: attr_filter.accounting_response: --> test1 (494090) Wed Jan 25 12:04:10 2017: Debug: attr_filter.accounting_response: Matched entry DEFAULT at line 12 (494090) Wed Jan 25 12:04:10 2017: Debug: modsingle[accounting]: returned from attr_filter.accounting_response (rlm_attr_filter) (494090) Wed Jan 25 12:04:10 2017: Debug: [attr_filter.accounting_response] = updated (494090) Wed Jan 25 12:04:10 2017: Debug: } # accounting = updated (494090) Wed Jan 25 12:04:10 2017: Debug: Sent Accounting-Response Id 188 from 82.21.11.50:1813 to 82.21.11.91:28850 length 0 (494090) Wed Jan 25 12:04:10 2017: Debug: Finished request (494091) Wed Jan 25 12:04:10 2017: Debug: Received Accounting-Request Id 189 from 82.21.11.91:57448 to 82.21.11.50:1813 length 79 ... logs for next request "test2" ... (494090) Wed Jan 25 12:04:10 2017: Debug: Cleaning up request packet ID 188 with timestamp +243824 (494091) Wed Jan 25 12:04:10 2017: Debug: Cleaning up request packet ID 189 with timestamp +243824 (494092) Wed Jan 25 12:04:11 2017: Debug: Empty preacct section in virtual server "buffered-sql". Using default return values. (494092) Wed Jan 25 12:04:11 2017: Debug: # Executing section accounting from file /etc/freeradius/sites-enabled/buffered-sql (494092) Wed Jan 25 12:04:11 2017: Debug: accounting { (494092) Wed Jan 25 12:04:11 2017: Debug: modsingle[accounting]: calling sql (rlm_sql) (494092) Wed Jan 25 12:04:11 2017: Debug: sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} (494092) Wed Jan 25 12:04:11 2017: Debug: sql: --> type.start.query (494092) Wed Jan 25 12:04:11 2017: Debug: sql: Using query template 'query' (494092) Wed Jan 25 12:04:11 2017: Debug: sql: EXPAND %{User-Name} (494092) Wed Jan 25 12:04:11 2017: Debug: sql: --> test2

3 24

RE: Freeradius 3.0.12 problems - mysql pool connections
by Michal Tomaszewski 02 Feb '17

02 Feb '17

Hi Alan, As you can see the problem described below was not exactly - as you previously stated - caused by SQL library but somehow FR itself... I understand that your fixes solved the problem, e.g.: https://github.com/FreeRADIUS/freeradius-server/commit/8aaf545d6c011dd5d4a2… Unfortunately current build of freeradius 3.0.13 makes (in our server once a minute) segmentation fault after SQL INSERT command user@server:~$ sudo freeradius -Xx > log20170127b.txt Segmentation fault (core dumped) Last lines in log: ... Fri Jan 27 13:27:28 2017 : Debug: %{User-Name} Fri Jan 27 13:27:28 2017 : Debug: Parsed xlat tree: Fri Jan 27 13:27:28 2017 : Debug: attribute --> User-Name Fri Jan 27 13:27:28 2017 : Debug: (19) EXPAND %{User-Name} Fri Jan 27 13:27:28 2017 : Debug: (19) --> h274_free Fri Jan 27 13:27:28 2017 : Debug: (19) SQL-User-Name set to 'h274_free' Fri Jan 27 13:27:28 2017 : Debug: rlm_sql (sql): Reserved connection (2) Fri Jan 27 13:27:28 2017 : Debug: (19) Executing select query: INSERT INTO radius_radacct_active ( acctsessionid, acctuniqueid, username, hotspot_id, device_id, felogin_id, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress ) VALUES ('588b3ca500000003', '477164ffa8f0efb5af020028af87b6fc', 'user_user', 'hotspotid-2', 'deviceis-36', '4988732', '', '192.168.176.1', '00000003', 'Wireless-802.11', FROM_UNIXTIME(1485520048), FROM_UNIXTIME(1485520048 + 1800), '', '', '', '0' << 32 | '0', '0' << 32 | '0', 'calledid', 'A4-70-D6-82-4C-82', 'Login-User', '', '192.168.176.83') Regards, Mike > -----Original Message----- > From: Freeradius-Users [mailto:freeradius-users- > bounces+michal.tomaszewski=cca.pl(a)lists.freeradius.org] On Behalf Of > Michal Tomaszewski > Sent: Wednesday, December 28, 2016 3:54 PM > To: FreeRadius users mailing list <freeradius-users(a)lists.freeradius.org> > Subject: RE: Freeradius 3.0.12 problems - redis and mysql pool connections > > Alan, > Some more Information in the subject. > > > >> I don't see that ERROR as much of a problem. The server tried to > > >> use an > > old connection, it failed, and when the server tried another > > connection, that one failed, too. > > > Yes. But connection has expired and probably something in > > > connection's > > pool management can be improved. > > > > How? Make a concrete suggestion. Or send a patch. > > > > There is an ERROR in case the data is written to the MySQL correctly. > As I understand this is not an ERROR situation. > Error shall be thrown where there is no possibility to write data. > > > > Server is not down. Server is working perfectly all the time. Those > > messages are not because MySQL server is down. They are appearing in > > normal operation when server is 100% available. They are probably > > because idle_timeout closes the connection and freeradius does not > > record the fact that such connection does not exist. > > > > No. And why guess? The source is available to you. > > I've checked the source and deeply checked the problem. > The problem exists on Ubuntu 16.04 and MySQL client library 5.7 and newest > build of freeradius. > The same situation we can observe on our stage environment: freeradius > 3.12 on Ubuntu 14.04 and MySQL client library 5.5.46. > So suggested bug in the SQL library or its newer/older version seems to be > not a real cause of the problem. > > There is 'ERROR: SQL query failed: no connection' ONLY in case of INSERTs or > REPLACEs to Mysql database. > Error is thrown but each INSERT and REPLACE is SUCCESSFUL. > > We made a lot of tests and: > 1. EVERY (even simple) INSERT or REPLACE throws ERROR. MySQL is available > during query. Insert or replace is successful. > We made temporary table and tested inserts in accounting start/stop > section: > Tue Dec 27 14:42:02 2016 : Debug: (2) Executing select query: > INSERT INTO debug_log (`data`) VALUES ('AAAAAAA') > Tue Dec 27 14:42:02 2016 : ERROR: (2) SQL query failed: no connection > > 2. When you change insert query to select query - there are no errors. > > 3. Nor SELECT neither DELETE query throws error (to be sure we checked > deletes with 0 rows deleted and 1 row deleted). Only INSERT and REPLACE. > Each INSERT and each REPLACE. > > 3. There is also no error thrown when you change the insert query into: > "INSERT INTO debug_log (`data`) VALUES ('AAAAAAA'); SELECT 1;" > > > Examples: > > #1 real situation: > > Mon Nov 28 21:53:09 2016 : Debug: rlm_sql (sql): Reserved connection (10) > Mon Nov 28 21:53:09 2016 : Debug: (12) Executing select query: > INSERT INTO radius_radacct_closed ( > acctsessionid, acctuniqueid, username, additional_id, > device_id, realm, nasipaddress, > nasportid, nasporttype, acctstarttime, > acctupdatetime, acctstoptime, acctsessiontime, > acctauthentic, connectinfo_start, connectinfo_stop, > acctinputoctets, acctoutputoctets, calledstationid, > callingstationid, acctterminatecause, servicetype, > framedprotocol, framedipaddress ) > VALUES ('583c98d000000001', > '79ffcccafc3b54e87403444481bf65e5', 'z555', > '555', '2', '', > '192.168.176.1', '00000001', 'Wireless- > 802.11', FROM_UNIXTIME(1480366389 - 49), > FROM_UNIXTIME(1480366389), > FROM_UNIXTIME(1480366389), 49, '', > '', '', '0' << 32 | '413029', > '0' << 32 | '3533411', > 'z5-d2', '90-B0-ED-E6-AE-15', > 'User-Request', '', '', > '192.168.176.2') > Mon Nov 28 21:53:09 2016 : ERROR: (12) SQL query failed: no connection > -- > -- > -- > -- > Mon Nov 28 21:54:45 2016 : Debug: rlm_sql (sql): Reserved connection (13) > Mon Nov 28 21:54:45 2016 : Debug: (14) Executing select query: > INSERT INTO radius_radacct_active ( > acctsessionid, acctuniqueid, username, > additional_id, device_id, realm, > nasipaddress, nasportid, nasporttype, > acctstarttime, acctstoptime, acctauthentic, > connectinfo_start, connectinfo_stop, acctinputoctets, > acctoutputoctets, calledstationid, callingstationid, > servicetype, framedprotocol, framedipaddress > ) VALUES ('583c996300000001', > '3c96a44b069782db0d7076274139e521', 'z555', > '5555', '2', '', > '192.168.176.1', '00000001', 'Wireless- > 802.11', FROM_UNIXTIME(1480366485), > FROM_UNIXTIME(1480366485 + 2700), '', > '', '', '0' << 32 | '0', > '0' << 32 | '0', 'z5-d2', '90-B0-ED-E6- > AE-15', 'Login-User', '', > '192.168.176.2') > Mon Nov 28 21:54:45 2016 : ERROR: (14) SQL query failed: no connection > > > #2 > Test scenarios: > > Tue Dec 27 14:42:02 2016 : Debug: %{sql: INSERT INTO > debug_log (`data`) VALUES ('AAAAAAA') } > Tue Dec 27 14:42:02 2016 : Debug: Parsed xlat tree: > Tue Dec 27 14:42:02 2016 : Debug: xlat --> sql Tue Dec 27 14:42:02 2016 : > Debug: { > Tue Dec 27 14:42:02 2016 : Debug: literal --> INSERT INTO > debug_log (`data`) VALUES ('AAAAAAA') > Tue Dec 27 14:42:02 2016 : Debug: } > Tue Dec 27 14:42:02 2016 : Debug: %{User-Name} Tue Dec 27 14:42:02 2016 : > Debug: Parsed xlat tree: > Tue Dec 27 14:42:02 2016 : Debug: attribute --> User-Name > Tue Dec 27 14:42:02 2016 : Debug: (2) EXPAND %{User-Name} > Tue Dec 27 14:42:02 2016 : Debug: (2) --> z555 > Tue Dec 27 14:42:02 2016 : Debug: (2) SQL-User-Name set to 'z555' > Tue Dec 27 14:42:02 2016 : Debug: rlm_sql (sql): Reserved connection (1) > Tue Dec 27 14:42:02 2016 : Debug: (2) Executing select query: > INSERT INTO debug_log (`data`) VALUES ('AAAAAAA') > **************************Tue Dec 27 14:42:02 2016 : ERROR: (2) > SQL query failed: no connection > Tue Dec 27 14:42:02 2016 : Debug: rlm_sql (sql): Released connection (1) Tue > Dec 27 14:42:02 2016 : Info: Need 2 more connections to reach min > connections (5) Tue Dec 27 14:42:02 2016 : Info: rlm_sql (sql): Opening > additional connection (3), 1 of 29 pending slots used Tue Dec 27 14:42:02 2016 > : Debug: rlm_sql_mysql: Starting connect to MySQL server Tue Dec 27 > 14:42:02 2016 : Debug: rlm_sql_mysql: Connected to database 'Radius' on > 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, protocol version 10 > Tue Dec 27 14:42:02 2016 : Debug: (2) EXPAND %{sql: INSERT > INTO debug_log (`data`) VALUES ('AAAAAAA') } > Tue Dec 27 14:42:02 2016 : Debug: (2) --> > > > Wed Dec 28 10:56:08 2016 : Debug: rlm_sql (sql): Reserved connection (0) > Wed Dec 28 10:56:08 2016 : Debug: (0) Executing select query: INSERT INTO > debug_log (data) VALUES > ('CCCCCCCCCCCCCCCCCCCCCCC') > **************************Wed Dec 28 10:56:08 2016 : ERROR: (0) > SQL query failed: no connection > -- > Wed Dec 28 10:56:08 2016 : Debug: Parsed xlat tree: > Wed Dec 28 10:56:08 2016 : Debug: attribute --> User-Name > Wed Dec 28 10:56:08 2016 : Debug: (0) EXPAND %{User-Name} > Wed Dec 28 10:56:08 2016 : Debug: (0) --> z555 > Wed Dec 28 10:56:08 2016 : Debug: (0) SQL-User-Name set to 'z555' > Wed Dec 28 10:56:08 2016 : Debug: rlm_sql (sql): Reserved connection (0) > Wed Dec 28 10:56:08 2016 : Debug: (0) Executing select query: INSERT INTO > debug_log (data) VALUES ('AAAAAAAAAAAAAAAAAAAA') > **************************Wed Dec 28 10:56:08 2016 : ERROR: (0) > SQL query failed: no connection > > > Wed Dec 28 11:11:15 2016 : Debug: literal --> INSERT INTO debug_log > (data) VALUES ('BBBBBBBBBBBBBBB');SELECT 1 > Wed Dec 28 11:11:15 2016 : Debug: (0) Executing select query: INSERT INTO > debug_log (data) VALUES ('BBBBBBBBBBBBBBB');SELECT 1 > Wed Dec 28 11:11:15 2016 : Debug: (0) EXPAND %{sql: INSERT INTO > debug_log (data) VALUES ('BBBBBBBBBBBBBBB');SELECT 1 > } > Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log > (data) VALUES ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 } > Wed Dec 28 11:13:15 2016 : Debug: literal --> INSERT INTO debug_log > (data) VALUES ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) EXPAND %{sql: INSERT INTO > debug_log (data) VALUES > ('CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 } > Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log (data) > VALUES ('FFFFFFFFFFF');SELECT 1} > Wed Dec 28 11:13:15 2016 : Debug: literal --> INSERT INTO debug_log > (data) VALUES ('FFFFFFFFFFF');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) EXPAND %{sql: INSERT INTO > debug_log (data) VALUES ('FFFFFFFFFFF');SELECT 1} > Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log > (data) VALUES ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 } > Wed Dec 28 11:13:15 2016 : Debug: literal --> INSERT INTO debug_log > (data) VALUES ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > > > In case of replace: > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (0) > Wed Dec 28 15:14:01 2016 : Debug: (0) Executing select query: REPLACE > INTO debug_log (id,data) VALUES > (1,'CCCCCCCCCCCCCCCCCCCCCCC') > **************************Wed Dec 28 15:14:01 2016 : ERROR: (0) > SQL query failed: no connection > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (0) > Wed Dec 28 15:14:01 2016 : Info: Need 4 more connections to reach min > connections (5) Wed Dec 28 15:14:01 2016 : Info: rlm_sql (sql): Opening > additional connection (1), 1 of 31 pending slots used Wed Dec 28 15:14:01 > 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server Wed Dec 28 > 15:14:01 2016 : Debug: rlm_sql_mysql: Connected to database 'WiFi-Spot- > Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, protocol > version 10 > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{sql: REPLACE INTO > debug_log (id,data) VALUES > (1,'CCCCCCCCCCCCCCCCCCCCCCC') } > Wed Dec 28 15:14:01 2016 : Debug: (0) --> > Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log > (id,data) VALUES (3,'CCCCCCCCCCCCCCCCCCCCCCC') } > Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql Wed Dec 28 15:14:01 2016 : > Debug: { > Wed Dec 28 15:14:01 2016 : Debug: literal --> REPLACE INTO debug_log > (id,data) VALUES (3,'CCCCCCCCCCCCCCCCCCCCCCC') > Wed Dec 28 15:14:01 2016 : Debug: } > Wed Dec 28 15:14:01 2016 : Debug: %{User-Name} Wed Dec 28 15:14:01 2016 > : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{User-Name} > Wed Dec 28 15:14:01 2016 : Debug: (0) --> z555 > Wed Dec 28 15:14:01 2016 : Debug: (0) SQL-User-Name set to 'z555' > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (0) > Wed Dec 28 15:14:01 2016 : Debug: (0) Executing select query: REPLACE > INTO debug_log (id,data) VALUES > (3,'CCCCCCCCCCCCCCCCCCCCCCC') > **************************Wed Dec 28 15:14:01 2016 : ERROR: (0) > SQL query failed: no connection > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (0) > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{sql: REPLACE INTO > debug_log (id,data) VALUES > (3,'CCCCCCCCCCCCCCCCCCCCCCC') } > Wed Dec 28 15:14:01 2016 : Debug: (0) --> > Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log > (id,data) VALUES (4,'CCCCCCCCCCCCCCCCCCCCCCC') } > Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql Wed Dec 28 15:14:01 2016 : > Debug: { > Wed Dec 28 15:14:01 2016 : Debug: literal --> REPLACE INTO debug_log > (id,data) VALUES (4,'CCCCCCCCCCCCCCCCCCCCCCC') > Wed Dec 28 15:14:01 2016 : Debug: } > Wed Dec 28 15:14:01 2016 : Debug: %{User-Name} Wed Dec 28 15:14:01 2016 > : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{User-Name} > Wed Dec 28 15:14:01 2016 : Debug: (0) --> z555 > Wed Dec 28 15:14:01 2016 : Debug: (0) SQL-User-Name set to 'z555' > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (1) > Wed Dec 28 15:14:01 2016 : Debug: (0) Executing select query: REPLACE > INTO debug_log (id,data) VALUES > (4,'CCCCCCCCCCCCCCCCCCCCCCC') > **************************Wed Dec 28 15:14:01 2016 : ERROR: (0) > SQL query failed: no connection > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (1) > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{sql: REPLACE INTO > debug_log (id,data) VALUES > (4,'CCCCCCCCCCCCCCCCCCCCCCC') } > Wed Dec 28 15:14:01 2016 : Debug: (0) --> > Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log > (id,data) VALUES (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 } > Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql Wed Dec 28 15:14:01 2016 : > Debug: { > Wed Dec 28 15:14:01 2016 : Debug: literal --> REPLACE INTO debug_log > (id,data) VALUES (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 > Wed Dec 28 15:14:01 2016 : Debug: } > Wed Dec 28 15:14:01 2016 : Debug: %{User-Name} Wed Dec 28 15:14:01 2016 > : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{User-Name} > Wed Dec 28 15:14:01 2016 : Debug: (0) --> z555 > Wed Dec 28 15:14:01 2016 : Debug: (0) SQL-User-Name set to 'z555' > **************************Wed Dec 28 15:14:01 2016 : Debug: rlm_sql > (sql): Reserved connection (0) > Wed Dec 28 15:14:01 2016 : Debug: (0) Executing select query: REPLACE > INTO debug_log (id,data) VALUES > (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (0) > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{sql: REPLACE INTO > debug_log (id,data) VALUES > (5,'CCCCCCCCCCCCCCCCCCCCCCC');SELECT 1 } > Wed Dec 28 15:14:01 2016 : Debug: (0) --> 1 > Wed Dec 28 15:14:01 2016 : Debug: %{sql: REPLACE INTO debug_log > (id,data) VALUES (6,'CCCCCCCCCCCCCCCCCCCCCCC') } > Wed Dec 28 15:14:01 2016 : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: xlat --> sql Wed Dec 28 15:14:01 2016 : > Debug: { > Wed Dec 28 15:14:01 2016 : Debug: literal --> REPLACE INTO debug_log > (id,data) VALUES (6,'CCCCCCCCCCCCCCCCCCCCCCC') > Wed Dec 28 15:14:01 2016 : Debug: } > Wed Dec 28 15:14:01 2016 : Debug: %{User-Name} Wed Dec 28 15:14:01 2016 > : Debug: Parsed xlat tree: > Wed Dec 28 15:14:01 2016 : Debug: attribute --> User-Name > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{User-Name} > Wed Dec 28 15:14:01 2016 : Debug: (0) --> z555 > Wed Dec 28 15:14:01 2016 : Debug: (0) SQL-User-Name set to 'z555' > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Reserved connection (1) > Wed Dec 28 15:14:01 2016 : Debug: (0) Executing select query: REPLACE > INTO debug_log (id,data) VALUES > (6,'CCCCCCCCCCCCCCCCCCCCCCC') > **************************Wed Dec 28 15:14:01 2016 : ERROR: (0) > SQL query failed: no connection > Wed Dec 28 15:14:01 2016 : Debug: rlm_sql (sql): Released connection (1) > Wed Dec 28 15:14:01 2016 : Debug: (0) EXPAND %{sql: REPLACE INTO > debug_log (id,data) VALUES > (6,'CCCCCCCCCCCCCCCCCCCCCCC') } > > > > > #3 > Same query log analysis: > > WITH ERROR: > Wed Dec 28 11:01:33 2016 : Debug: %{sql: INSERT INTO debug_log > (data) VALUES ('AAAAAAAAAAAAAAAAAAAA') } > Wed Dec 28 11:01:33 2016 : Debug: Parsed xlat tree: > Wed Dec 28 11:01:33 2016 : Debug: xlat --> sql Wed Dec 28 11:01:33 2016 : > Debug: { > Wed Dec 28 11:01:33 2016 : Debug: literal --> INSERT INTO debug_log > (data) VALUES ('AAAAAAAAAAAAAAAAAAAA') > Wed Dec 28 11:01:33 2016 : Debug: } > Wed Dec 28 11:01:33 2016 : Debug: %{User-Name} Wed Dec 28 11:01:33 2016 > : Debug: Parsed xlat tree: > Wed Dec 28 11:01:33 2016 : Debug: attribute --> User-Name > Wed Dec 28 11:01:33 2016 : Debug: (0) EXPAND %{User-Name} > Wed Dec 28 11:01:33 2016 : Debug: (0) --> z555 > Wed Dec 28 11:01:33 2016 : Debug: (0) SQL-User-Name set to 'z555' > Wed Dec 28 11:01:33 2016 : Debug: rlm_sql (sql): Reserved connection (1) > Wed Dec 28 11:01:33 2016 : Debug: (0) Executing select query: INSERT INTO > debug_log (data) VALUES ('AAAAAAAAAAAAAAAAAAAA') > Wed Dec 28 11:01:33 2016 : ERROR: (0) SQL query failed: no connection > Wed Dec 28 11:01:33 2016 : Debug: rlm_sql (sql): Released connection (1) > Wed Dec 28 11:01:33 2016 : Debug: (0) EXPAND %{sql: INSERT INTO > debug_log (data) VALUES ('AAAAAAAAAAAAAAAAAAAA') > } > Wed Dec 28 11:01:33 2016 : Debug: (0) --> > Wed Dec 28 11:01:33 2016 : Debug: (0) policy wifi-sessions.accounting { > Wed Dec 28 11:01:33 2016 : Debug: (0) if (&Acct-Status-Type == start){ > Wed Dec 28 11:01:33 2016 : Debug: (0) if (&Acct-Status-Type == start) -> > FALSE > Wed Dec 28 11:01:33 2016 : Debug: (0) elsif (&Acct-Status-Type == stop){ > Wed Dec 28 11:01:33 2016 : Debug: (0) elsif (&Acct-Status-Type == stop) -> > TRUE > Wed Dec 28 11:01:33 2016 : Debug: (0) elsif (&Acct-Status-Type == stop) { > > > WITHOUT ERROR (query modified to have select 1 on the end): > Wed Dec 28 11:13:15 2016 : Debug: %{sql: INSERT INTO debug_log > (data) VALUES ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 } > Wed Dec 28 11:13:15 2016 : Debug: Parsed xlat tree: > Wed Dec 28 11:13:15 2016 : Debug: xlat --> sql Wed Dec 28 11:13:15 2016 : > Debug: { > Wed Dec 28 11:13:15 2016 : Debug: literal --> INSERT INTO debug_log > (data) VALUES ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: } > Wed Dec 28 11:13:15 2016 : Debug: %{User-Name} Wed Dec 28 11:13:15 2016 > : Debug: Parsed xlat tree: > Wed Dec 28 11:13:15 2016 : Debug: attribute --> User-Name > Wed Dec 28 11:13:15 2016 : Debug: (1) EXPAND %{User-Name} > Wed Dec 28 11:13:15 2016 : Debug: (1) --> z555 > Wed Dec 28 11:13:15 2016 : Debug: (1) SQL-User-Name set to 'z555' > Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Reserved connection (1) > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Socket destructor called, > closing socket Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Reconnecting > (1) Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Starting connect to > MySQL server Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Connected > to database 'Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, > protocol version 10 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Released connection (1) > Wed Dec 28 11:13:15 2016 : Debug: (1) EXPAND %{sql: INSERT INTO > debug_log (data) VALUES > ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 } > Wed Dec 28 11:13:15 2016 : Debug: (1) --> 1 > Wed Dec 28 11:13:15 2016 : Debug: (1) policy wifi-sessions.accounting { > Wed Dec 28 11:13:15 2016 : Debug: (1) if (&Acct-Status-Type == start){ > Wed Dec 28 11:13:15 2016 : Debug: (1) if (&Acct-Status-Type == start) -> > FALSE > Wed Dec 28 11:13:15 2016 : Debug: (1) elsif (&Acct-Status-Type == stop){ > Wed Dec 28 11:13:15 2016 : Debug: (1) elsif (&Acct-Status-Type == stop) -> > TRUE > Wed Dec 28 11:13:15 2016 : Debug: (1) elsif (&Acct-Status-Type == stop) { > > > As you can in second case see in place of: > Wed Dec 28 11:01:33 2016 : ERROR: (0) SQL query failed: no connection > Wed Dec 28 11:01:33 2016 : Debug: rlm_sql (sql): Released connection (1) > > after changing the query we have no ERROR message and in case of socket > unavailable there is: > Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Socket destructor called, > closing socket Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Reconnecting > (1) Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Starting connect to > MySQL server Wed Dec 28 11:13:15 2016 : Debug: rlm_sql_mysql: Connected > to database 'Radius' on 127.0.0.1 via TCP/IP, server version 5.6.34-79.1-56-log, > protocol version 10 > Wed Dec 28 11:13:15 2016 : Debug: (1) Executing select query: INSERT INTO > debug_log (data) VALUES > ('AAAAAAAAAAAAAAAAAAAA');SELECT 1 > Wed Dec 28 11:13:15 2016 : Debug: rlm_sql (sql): Released connection (1) > what - I suppose - is normal and desired situation. > ________________________________________ 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. ________________________________

4 11

Re: AD Group Check - multi SSID - Pass "Require-membership-of" to NTLM_AUTH as variable.
by Pierre de Jong 31 Jan '17

31 Jan '17

Hi, Could someone give me some "ways to go" with LDAP module? Online tutos ? that goes from A to Z ? What about "FreeRadius" flow.... difference between default, inner-tunnel? Authentication and authorization? :shy: Thanks in advance Have a nice day 2017-01-30 10:39 GMT+01:00 <A.L.M.Buxey(a)lboro.ac.uk>: > Hi, > > > So, for exemple, SSID-Corp-Employee is only accessible to a certain > users, > > member of ADgroupA , and SSID-Corp-Direction, only accessible to users, > > member of ADgroupB > > > > When only authenticating with 1 single AD group, there is no problem, > the : > > > > > ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key > > > --require-membership-of=GALAXY\rad01 --username=%{%{Stripped-User- > Name}:-%{%{User-Name}:-None}} > > > --domain=%{%{mschap:NT-Domain}:-GALAXY.PRIV} > > > --challenge=%{%{mschap:Challenge}:-00} --nt-response=%{%{mschap:NT-Re > > > sponse}:-00}" > > dont do that. leave authentication alone and use authorization > > > so, use simple LDAP check to verify if someone can connect - this scales > because you match > the SSID to the LDAP group..so , configure the LDAP module so it can query > your LDAP (which is AD) > for the users group and then > > if ( ldap_stuff_here != &Called-Station-SSID) { > reject > } > > LDAP stuff can either be an LDAP-Group call or a %{ldap:} call. basically, > get value from LDAP > and check against that supplied in the RADIUS request > > alan > - > List info/subscribe/unsubscribe? See http://www.freeradius.org/ > list/users.html >

2 1

Releasing 3.0.13 soon?
by Alan DeKok 31 Jan '17

31 Jan '17

We plan on releasing 3.0.13 soon. Is anyone using the v3.0.x head? Are there objections to releasing 3.0.13? Alan DeKok.

7 15