- Freeradius-Users - lists.freeradius.org

rlm_python and threading
by Andrew Parisio 25 Mar '15

25 Mar '15

I'm working with rlm_python in FreeRadius 2.2.6 and with 20 simultaneous eapol_test threads running I was only getting 5-6 requests/second. This got me wondering how FreeRadius and rlm_python handle threading. So to make sure it wasn't related to my database calls or anything else I wrote a simple radiusd_module.py with no external dependencies/calls that instantly returned OK and it was handling 275 requests/second. Now I'm doubting my requests are being processed in parallel so I modified my radiusd_module.py to have a 1 second sleep between starting to process a request and returning OK. The module looks something like this: import radiusd import time def instantiate(p): # do something return 0 def array_to_dict(array): my_dict = {} for t in array: # strip any quotes off of the beginning & end my_dict[t[0]] = t[1].lstrip('"').rstrip('"') return my_dict def post_auth(p): my_dict = array_to_dict(p) print "***** Start %s" % my_dict['NAS-Port-Id'] time.sleep(1) print "***** End %s" % my_dict['NAS-Port-Id'] return radiusd.RLM_MODULE_OK Then I set two copies of eapol_test in an infinite loop sending NAS-Port-Id's of 1 and 2 so I could see what radius.log looked like. The hypothesis being if it's properly threaded I should get this: ***** Start 1 ***** Start 2 ==== Pause 1 second ***** End 1 ***** End 2 ... repeat I ran the the two eapol_test threads against radius and the output looks like this: tail radius.log -f | grep "\*\*\*\*\*" ***** Start 1 ==== Pause 1 second <-- not output, just a literal 1 second wait from time.sleep() ***** End 1 ***** Start 2 ==== Pause 1 second <-- not output, just a literal 1 second wait from time.sleep() ***** End 2 .... and so on, >From this I can see that requests handled by rlm_python are being served by a single thread rather than multiple/parallel threads. Does anybody have any experience with rlm_python.py and/or know what I might be doing wrong? Thanks! Andrew P.S. Latency from my development machine at my desk to Dynamodb in AWS is ~80ms, **which won't be the case for prod**, which is why I was only getting 5-6 requests/second. but I'd still like to be able to handle hundreds of requests/s per production host (obviously the hosts will need to be sized appropriately).

3 2

freeradius clients are only pingable
by mohammed farouk 25 Mar '15

25 Mar '15

Dear all, I am using freeradius on the server and i installed also a zoneminder, the cam's are getting auth by MAC and that works fine. no i am trying to let zm control the cams but it seems that it can't because some routing issue. i tried then to log to the server and http another ubuntu laptop and can't still open the page. what is the missing with me ? *Best regards,* *Mohammed Farouk*

1 0

Ldap check attribute
by Khapare Joshi 25 Mar '15

25 Mar '15

I have a ldapserver which has a objectClass = eduPerson in eduPersonPrimaryAffiliation we have staff and student I did the ldapsearch from the radius server command line as: ldapsearch -h ldapserver "dc=EXAMPLE,dc=COM" -x -s sub uid=tom eduPersonPrimaryAffiliation # extended LDIF # # LDAPv3 # base <dc=EXAMPLE,dc=COM> with scope subtree # filter: uid=tom # requesting: eduPersonPrimaryAffiliation # # tom, People, example.com dn: uid=tom,ou=People,dc=example,dc=com eduPersonPrimaryAffiliation: staff # search result search: 2 result: 0 Success # numResponses: 2 # numEntries: 1 [tom@radiusserver ~]# What I am trying to do is : if person (user)'s eduPersonPrimaryAffiliation=staff he/she can have 5 simultaneous connection else 1 simultaneous connection. I have configured ldap in /etc/raddb/modules/ldap so ldap bind is okay [ldap] performing user authorization for tom [ldap] expand: %{Stripped-User-Name} -> tom [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=tom) [ldap] expand: dc=EXAMPLE,dc=CIN -> dc=EXAMPLE,dc=COM [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] attempting LDAP reconnection [ldap] (re)connect to ldapserver:389, authentication 0 [ldap] bind as cn=tom,ou=People,dc=EXAMPLE,dc=COM/KEYBOARD to ldapserver:389 [ldap] waiting for bind result ... [ldap] Bind was successful [ldap] performing search in dc=EXAMPLE,dc=COM, with filter (uid=tom) [ldap] looking for check items in directory... [ldap] looking for reply items in directory... WARNING: No "known good" password was found in LDAP. Are you sure that the user is configured correctly? [ldap] ldap_release_conn: Release Id: 0 ++[ldap] = ok Where do I add the ldapchcek for eduPersonPrimaryAffiliation: staff/student or the right way of doing ? K

1 1

Re: Freeradius-Users Digest, Vol 119, Issue 83
by Rui Ribeiro 25 Mar '15

25 Mar '15

Hi Alan, Thanks for the superb work. I have deployed it in my test server, and I can confirm it is working now. > Message: 6 > Date: Tue, 24 Mar 2015 16:13:45 -0500 > From: Alan DeKok <aland(a)deployingradius.com> > To: FreeRadius users mailing list > <freeradius-users(a)lists.freeradius.org> > Subject: Re: raddebug not working in 3.0.8 head / Debian 8.0 > Message-ID: <06788715-6E47-4E05-80AB-9D4CC4AF8067(a)deployingradius.com> > Content-Type: text/plain; charset=windows-1252 > > On Mar 24, 2015, at 3:47 PM, Rui Ribeiro <ruyrybeyro(a)gmail.com> wrote: > > raddebug was/is not working properly with Debian 8.0/FR 3.0.8 head > version > > 3.0.8 (git #bc5d0f2) > > I’ve pushed a fix. > > Alan DeKok. > > > -- Regards, -- Rui Ribeiro Senior Sysadm ISCTE-IUL https://www.linkedin.com/pub/rui-ribeiro/16/ab8/434

1 0

policy.conf => delete all attribute
by Olivier CALVANO 25 Mar '15

25 Mar '15

Hi i have a policy: if ((Tunnel-Server-Endpoint:0[0] != '172.20.10.10') && (User-Name =~ /my.realm.dsl/) && ("%{Packet-Src-IP-Address}" == "192.168.50.100")) { update reply { tunnel-Server-Endpoint:0 := '172.20.10.10' tunnel-Client-Auth-Id:0 := "LAC-172.20.10.10" tunnel-Server-Auth-Id:0 := "LNS-172.20.10.10" Tunnel-Preference !* "" Framed-MTU !* "" Cisco-AVPair !* "" MS-Primary-DNS-Server !* "" MS-Secondary-DNS-Server !* "" Framed-IP-Address !* "" Framed-IP-Netmask !* "" Service-Type !* "" Framed-Protocol !* "" Tunnel-Type := "L2TP" Tunnel-Medium-Type := "IPv4" } Actually, i delete name by name the attribute (sample Cisco-AVPair, Tunnel-Preference etc ..) it's possible to start by delete all attribute and after add the attribute that i want ? sample (not tested): if ((Tunnel-Server-Endpoint:0[0] != '172.20.10.10') && (User-Name =~ /my.realm.dsl/) && ("%{Packet-Src-IP-Address}" == "192.168.50.100")) { update reply { * !* "" tunnel-Server-Endpoint:0 := '172.20.10.10' tunnel-Client-Auth-Id:0 := "LAC-172.20.10.10" tunnel-Server-Auth-Id:0 := "LNS-172.20.10.10" Tunnel-Type := "L2TP" Tunnel-Medium-Type := "IPv4" } i don't know if : * !* "" is correct and work Thanks for your help olivier

2 1

Fwd: Child is hung (max_request)
by srithar jeevadurai 25 Mar '15

25 Mar '15

Hi Team, We need your help to fix our radius server error. I kindly request you to help us on the same. We are facing 'Child is hung' message in our radius server and we have to restart radius server to become normal. As per our analysis the error message comes whenever there are more load on the server. *Configuration: * max_request_time = 30 cleanup_delay = 5 *max_requests = 12800* *max_queue_size = 131072* start_servers = 5 max_servers = 32 min_spare_servers = 3 max_spare_servers = 10 max_requests_per_server = 0 Our system TPS is 100 (at max 120). Since we have kept max_request as 12,800 and max_request_time as 30 seconds, we will be able to support max backlog 3000 (TPS x max_request_time). That is our system can clear first 3000 requests in the queue before it faces 'time expire' (max_request_time). However we have set max_request as 12,800 during high load, system is facing 'child is hung' when the backlog grows more than 3000. Is our above understanding correct? If it is correct, we can resolve our issue by setting max_request as 3000 i.e. during high load, we will not face 'child is hung ' and no need to restart radius server to become normal. Looking forward for your reply. -- Regards, Srithar Durairaj Alternate Mail I.D: srijeevadurai1(a)yahoo.co.in Mobile: +919886251852

8 32

Re: Traffic Volume Limit per Month cannot exceed 4Gbytes
by chenjiang 25 Mar '15

25 Mar '15

Hi! Herwin It works and thanks for your great help! BR! Chen Jiang Microshield Technology Co., Ltd åäº¬å¸æµ·æ·åºè¥¿ä¸ç¯åè·¯50å·è±ªæå¤§å¦C2åº§18-19å± 100048 (86)10-88518768 (86)18612696123 [1]chenjiang(a)microshield.com.cn åå§é®ä»¶ åä»¶äºº: Herwin Weststrate<herwin(a)quarantainenet.nl> æ¶ä»¶äºº: FreeRadius users mailing list<freeradius-users(a)lists.freeradius.org> åéæ¶é´: 2015å¹´3æ19æ¥(å¨å)â18:50 ä¸»é¢: Re: Traffic Volume Limit per Month cannot exceed 4Gbytes On 19-03-15 11:40, chenjiang wrote: > Hi! Experts > > I want to achieve user traffic volume limit per month, but found there > is a limit for user traffic to exceed 4Gbytes. > > Below is my DB structure, you could see the > "Max-Monthly-TrafficÃ¢ groupcheck attribute is 10Gbytes and it type > is Ã¢varchar", but it seems system deal it like a Ã¢integer" type, so it > cannot exceed 4Gbytes. > > mysql> select * from radgroupcheck; > > +----+--------------------+-----------------------+----+------------+ > | id | groupname | attribute | op | value | > +----+--------------------+-----------------------+----+------------+ > | 25 | group2 | Max-Monthly-Traffic | := | 10737418240| > +----+--------------------+-----------------------+----+------------+ > > 3 rows in set (0.00 sec) > > In FreeRADIUS debug mode, we could see that the rlm_sqlcounter > Ã¢check_itemÃ¢ is always warpped in 4294967296 just like below: > > [monthlytrafficcounter] > > expand: %{sql:SELECT SUM(acctinputoctets+acctoutputoctets) FROM radacct > WHERE username='lichan' AND UNIX_TIMESTAMP(acctstarttime) > > '1425139200'} -> 7250810110 Change the last query to "SUM(...)/1024", divide the value in radgroupcheck by 1024 as well. This way it's less accurate, but that wouldn't matter much when comparing these kind of values. -- Herwin Weststrate - List info/subscribe/unsubscribe? See [2]http://www.freeradius.org/list/users.htm l References 1. mailto:chenjiang@microshield.com.cn 2. http://www.freeradius.org/list/users.html

1 0

disable authentication logging
by Mohamed Lrhazi 25 Mar '15

25 Mar '15

I commented out auth_log from both my /etc/freeradius/sites-enabled/default and /etc/freeradius/sites-enabled/inner-tunnel authorize { ... #auth_log ... } radius.log still logs login events like: Tue Mar 24 19:19:44 2015 : Auth: (47) Login OK: [sbradius] (from client gu_net_10 port 0) I enabled linelog, and thought I could disabled this other logging... Where do I do that? Thanks a lot, Mohamed.

2 2

FreeRADIUS running out of file descriptors??
by Stefan Paetow 25 Mar '15

25 Mar '15

Hi, Alan, Arran, have you ever seen FreeRADIUS run out of file descriptors? One of our pilot sites reported this this evening: Tue Mar 24 02:15:02 2015 : Info: ... adding new socket auth from client (127.0.0.1, 44084) -> (*, 2083, virtual-server=abfab-idp) Tue Mar 24 02:15:02 2015 : Error: Failed opening proxy socket 'proxy (0.0.0.0, 0) -> home_server (212.219.179.131, 2083)' : Failed in connect(): No route to host Tue Mar 24 02:15:02 2015 : Error: Failed to insert request into the proxy list Tue Mar 24 02:15:07 2015 : Info: ... shutting down socket auth from client (127.0.0.1, 44084) -> (*, 2083, virtual-server=abfab-idp) Tue Mar 24 02:20:01 2015 : Info: ... adding new socket auth from client (127.0.0.1, 44086) -> (*, 2083, virtual-server=abfab-idp) Tue Mar 24 02:20:02 2015 : Error: Failed opening proxy socket 'proxy (0.0.0.0, 0) -> home_server (212.219.179.131, 2083)' : Failed finding socket, caller must allocate a new one Tue Mar 24 02:20:02 2015 : Error: Failed to insert request into the proxy list Tue Mar 24 02:20:07 2015 : Error: FATAL failure opening /dev/null: Too many open files I know it's just a short snippet, but is this at all helpful? This was a standard Moonshot IdP with a 'ping' every 5 minutes for around what... 2 weeks (since we resolved that socket proxy loss)... Anything you want me to try other than suggesting to my pilot site to run valgrind? Thanks very much :-) Stefan Paetow Moonshot Industry & Research Liaison Coordinator t: +44 (0)1235 822 125 gpg: 0x3FCE5142 xmpp: stefanp(a)jabber.dev.ja.net skype: stefan.paetow.janet Lumen House, Library Avenue, Harwell Oxford, Didcot, OX11 0SG jisc.ac.uk Jisc is a registered charity (number 1149740) and a company limited by guarantee which is registered in England under Company No. 5747339, VAT No. GB 197 0632 86. Jisc’s registered office is: One Castlepark, Tower Hill, Bristol, BS2 0JA. T 0203 697 5800. Jisc Collections and Janet Ltd. is a wholly owned Jisc subsidiary and a company limited by guarantee which is registered in England under Company No. number 2881024, VAT No. GB 197 0632 86. The registered office is: Lumen House, Library Avenue, Harwell, Didcot, Oxfordshire, OX11 0SG. T 01235 822200.

2 2

RadSec Authentication + Accounting Issue
by Donald Sherker 24 Mar '15

24 Mar '15

We are running FreeRADIUS 3.0.7 configured to send authentication and accounting to another AAA server. With just auth configured this works without a problem. When we configure it for both auth and accounting, authentication will work until the first attempt to sent an accounting packet. It does not appear that this packet is ever sent, and any further communication with the remote AAA server does not work. Our FreeRADIUS server has to be restarted to authenticate a user again. The remote server portion of the tls file is : home_server remote_server1 { ipaddr = z.z.z.z port = 2083 type = auth+acct secret = radsec proto = tcp status_check = none tls { private_key_file = ${certdir}/cert.key certificate_file = ${certdir}/cert.csrb64.cer ca_file = /usr/local/etc/raddb/certs/cert.crt dh_file = ${certdir}/dh random_file = ${certdir}/random fragment_size = 8192 ca_path = ${cadir} cipher_list = "DEFAULT" } } home_server_pool remote_server_pool { type = client-balance home_server = remote_server1 } realm test_realm { auth_pool = remote_server_pool acct_pool = remote_server_pool } Let me know if any other configuration files would be useful. Below is a portion of the logs when this happens: (0) Received Access-Request Id 77 from x.x.x.x:50204 to y.y.y.y:1812 length 266 (0) User-Name = 'user@realm' (0) NAS-IP-Address = x.x.x.x (0) NAS-Identifier = 'NAS' (0) Called-Station-Id = '000000000000:SSID' (0) NAS-Port-Type = Wireless-802.11 (0) NAS-Port = 0 (0) Calling-Station-Id = '111111111111' (0) Connect-Info = 'CONNECT 0Mbps 802.11b' (0) Acct-Session-Id = '5501AFCF-00000020' (0) Framed-MTU = 1400 (0) EAP-Message = 0x020f0038013033313032363039383235373236323240776c616e2e6d6e633236302e6d63633331302e336770706e6574776f726b2e6f7267 (0) Message-Authenticator = 0x02a8eda3497d667353ec8a96d14a2d8b (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (0) authorize { (0) [preprocess] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix: Checking for suffix after "@" (0) suffix: Looking up realm "realm" for User-Name = "user@realm" (0) suffix: Found realm "realm" (0) suffix: Adding Stripped-User-Name = "user" (0) suffix: Adding Realm = "realm" (0) suffix: Proxying request from user user to realm realm (0) suffix: Preparing to proxy authentication request to realm "realm" (0) [suffix] = updated (0) eap: Request is supposed to be proxied to Realm realm. Not doing EAP. (0) [eap] = noop (0) [files] = noop (0) [expiration] = noop (0) [logintime] = noop (0) } # authorize = updated Opening new proxy socket 'proxy (0.0.0.0, 0) -> home_server (z.z.z.z, 2083)' Trying SSL to port 2083 Requiring Server certificate (0) (other): before/connect initialization (0) TLS_connect: before/connect initialization (0) >>> Unknown TLS version [length 00f0] (0) TLS_connect: SSLv2/v3 write client hello A Waking up in 0.4 seconds. (0) <<< Unknown TLS version [length 0051] (0) TLS_connect: SSLv3 read server hello A (0) <<< Unknown TLS version [length 1612] (0) TLS Verify adding attributes (0) chain-depth=3, (0) error=0 (0) TLS Verify adding attributes (0) chain-depth=2, (0) error=0 (0) TLS Verify adding attributes (0) chain-depth=1, (0) error=0 (0) TLS Verify adding attributes (0) chain-depth=0, (0) error=0 (0) TLS_connect: SSLv3 read server certificate A (0) <<< Unknown TLS version [length 0004] (0) TLS_connect: SSLv3 read server done A (0) >>> Unknown TLS version [length 0106] (0) TLS_connect: SSLv3 write client key exchange A (0) >>> Unknown TLS version [length 0001] (0) TLS_connect: SSLv3 write change cipher spec A (0) >>> Unknown TLS version [length 0010] (0) TLS_connect: SSLv3 write finished A (0) TLS_connect: SSLv3 flush data (0) <<< Unknown TLS version [length 0001] (0) <<< Unknown TLS version [length 0010] (0) TLS_connect: SSLv3 read finished A (0) (other): SSL negotiation finished successfully Listening on proxy (y.y.y.y, 38309) -> home_server (z.z.z.z, 2083) (0) Proxying request to home server z.z.z.z port 2083 (TLS) timeout 30.000000 (0) Sent Access-Request Id 154 from y.y.y.y:38309 to z.z.z.z:2083 length 241 (0) User-Name = 'user' (0) NAS-IP-Address = x.x.x.x (0) NAS-Identifier = 'NAS' (0) Called-Station-Id = '000000000000:SSID' (0) NAS-Port-Type = Wireless-802.11 (0) NAS-Port = 0 (0) Calling-Station-Id = '111111111111' (0) Connect-Info = 'CONNECT 0Mbps 802.11b' (0) Acct-Session-Id = '5501AFCF-00000020' (0) Framed-MTU = 1400 (0) EAP-Message = 0x020f0038013033313032363039383235373236323240776c616e2e6d6e633236302e6d63633331302e336770706e6574776f726b2e6f7267 (0) Message-Authenticator = 0x02a8eda3497d667353ec8a96d14a2d8b (0) Event-Timestamp = 'Mar 12 2015 12:32:11 EDT' (0) Proxy-State = 0x3737 Thread 4 waiting to be assigned a request Waking up in 0.6 seconds. Waking up in 0.3 seconds. Thread 5 got semaphore Thread 5 handling request 0, (1 handled so far) (0) Clearing existing &reply: attributes (0) Received Access-Challenge Id 154 from z.z.z.z:2083 to y.y.y.y:38309 length 146 (0) EAP-Message = 0x011000441701000001050000cf2b3cef0a31f39b5014b7d4aa1f06c302050000610ede3617be0000d98e7d329d6162a20b050000bbc85cccebdcb3322314a4edf8a166e3 (0) Message-Authenticator = 0x68def4c1076bd78e494481bf9526bc66 (0) State = 0xffabd5a1e2e5fc51254946eda3439a4f92703fe4a5ecd73b05bfad82ee821f95 (0) Proxy-State = 0x3737 (0) # Executing section post-proxy from file /usr/local/etc/raddb/sites-enabled/default (0) post-proxy { (0) eap: No pre-existing handler found (0) [eap] = noop (0) } # post-proxy = noop (0) Using Post-Auth-Type Challenge (0) Post-Auth-Type sub-section not found. Ignoring. (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (0) Sent Access-Challenge Id 77 from y.y.y.y:1812 to x.x.x.x:50204 length 142 (0) EAP-Message = 0x011000441701000001050000cf2b3cef0a31f39b5014b7d4aa1f06c302050000610ede3617be0000d98e7d329d6162a20b050000bbc85cccebdcb3322314a4edf8a166e3 (0) Message-Authenticator = 0x68def4c1076bd78e494481bf9526bc66 (0) State = 0xffabd5a1e2e5fc51254946eda3439a4f92703fe4a5ecd73b05bfad82ee821f95 (0) Finished request Thread 5 waiting to be assigned a request Waking up in 4.6 seconds. Waking up in 0.3 seconds. Thread 2 got semaphore Thread 2 handling request 1, (1 handled so far) (1) Received Access-Request Id 78 from x.x.x.x:50204 to y.y.y.y:1812 length 288 (1) User-Name = 'user@realm' (1) NAS-IP-Address = x.x.x.x (1) NAS-Identifier = 'NAS' (1) Called-Station-Id = '000000000000:SSID' (1) NAS-Port-Type = Wireless-802.11 (1) NAS-Port = 0 (1) Calling-Station-Id = '111111111111' (1) Connect-Info = 'CONNECT 0Mbps 802.11b' (1) Acct-Session-Id = '5501AFCF-00000020' (1) Framed-MTU = 1400 (1) EAP-Message = 0x0210002c17010000030300406e414a35103ee4e0860100000b050000f27bc26235ef1b663594aadd343a6ab4 (1) State = 0xffabd5a1e2e5fc51254946eda3439a4f92703fe4a5ecd73b05bfad82ee821f95 (1) Message-Authenticator = 0xfc792a3aae3b5a6322f357a3821bc0f2 (1) session-state: No cached attributes (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (1) authorize { (1) [preprocess] = ok (1) [chap] = noop (1) [mschap] = noop (1) [digest] = noop (1) suffix: Checking for suffix after "@" (1) suffix: Looking up realm "realm" for User-Name = "user@realm" (1) suffix: Found realm "realm" (1) suffix: Adding Stripped-User-Name = "user" (1) suffix: Adding Realm = "realm" (1) suffix: Proxying request from user user to realm realm (1) suffix: Preparing to proxy authentication request to realm "realm" (1) [suffix] = updated (1) eap: Request is supposed to be proxied to Realm realm. Not doing EAP. (1) [eap] = noop (1) [files] = noop (1) [expiration] = noop (1) [logintime] = noop (1) } # authorize = updated (1) Proxying request to home server z.z.z.z port 2083 (TLS) timeout 30.000000 (1) Sent Access-Request Id 160 from y.y.y.y:38309 to z.z.z.z:2083 length 263 (1) User-Name = 'user' (1) NAS-IP-Address = x.x.x.x (1) NAS-Identifier = 'NAS' (1) Called-Station-Id = '000000000000:SSID' (1) NAS-Port-Type = Wireless-802.11 (1) NAS-Port = 0 (1) Calling-Station-Id = '111111111111' (1) Connect-Info = 'CONNECT 0Mbps 802.11b' (1) Acct-Session-Id = '5501AFCF-00000020' (1) Framed-MTU = 1400 (1) EAP-Message = 0x0210002c17010000030300406e414a35103ee4e0860100000b050000f27bc26235ef1b663594aadd343a6ab4 (1) State = 0xffabd5a1e2e5fc51254946eda3439a4f92703fe4a5ecd73b05bfad82ee821f95 (1) Message-Authenticator = 0xfc792a3aae3b5a6322f357a3821bc0f2 (1) Event-Timestamp = 'Mar 12 2015 12:32:12 EDT' (1) Proxy-State = 0x3738 Thread 2 waiting to be assigned a request (1) Clearing existing &reply: attributes (1) Received Access-Accept Id 160 from z.z.z.z:2083 to y.y.y.y:38309 length 243 (1) MS-MPPE-Recv-Key = 0xec24ffbb118c183ed6a30981ba20c9256c23246ea17013c8cb79cef2f3f2bf77 (1) MS-MPPE-Send-Key = 0xe67b0827ac08fa7f27a364f223684d30d7173ab8137a2a91e4547207148cac2c (1) EAP-Message = 0x03100004 (1) Message-Authenticator = 0x41cae584466f4d058da452161c4722a9 (1) Acct-Session-Id = '5501AFCF-00000020' (1) Reply-Message = 'Access accepted : 111111111111 - 000000000000:SSID' (1) Proxy-State = 0x3738 (1) # Executing section post-proxy from file /usr/local/etc/raddb/sites-enabled/default (1) post-proxy { (1) eap: No pre-existing handler found (1) [eap] = noop (1) } # post-proxy = noop (1) Found Auth-Type = Accept (1) Auth-Type = Accept, accepting the user (1) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default (1) post-auth { (1) update { (1) No attributes updated (1) } # update = noop (1) linelog: EXPAND Accounting-Request.%{%{Acct-Status-Type}:-unknown} (1) linelog: --> Accounting-Request.unknown (1) linelog: EXPAND /var/log/radius/linelog (1) linelog: --> /var/log/radius/linelog (1) linelog: EXPAND NAS %{Packet-Src-IP-Address} (%{NAS-IP-Address}) sent unknown Acct-Status-Type %{Acct-Status-Type} (1) linelog: --> NAS x.x.x.x (x.x.x.x) sent unknown Acct-Status-Type (1) [linelog] = ok (1) [exec] = noop (1) policy remove_reply_message_if_eap { (1) if (&reply:EAP-Message && &reply:Reply-Message) { (1) if (&reply:EAP-Message && &reply:Reply-Message) -> TRUE (1) if (&reply:EAP-Message && &reply:Reply-Message) { (1) update reply { (1) &Reply-Message !* ANY (1) } # update reply = noop (1) } # if (&reply:EAP-Message && &reply:Reply-Message) = noop (1) ... skipping else for request 1: Preceding "if" was taken (1) } # policy remove_reply_message_if_eap = noop (1) } # post-auth = ok (1) Sent Access-Accept Id 78 from y.y.y.y:1812 to x.x.x.x:50204 length 179 (1) MS-MPPE-Recv-Key = 0xec24ffbb118c183ed6a30981ba20c9256c23246ea17013c8cb79cef2f3f2bf77 (1) MS-MPPE-Send-Key = 0xe67b0827ac08fa7f27a364f223684d30d7173ab8137a2a91e4547207148cac2c (1) EAP-Message = 0x03100004 (1) Message-Authenticator = 0x41cae584466f4d058da452161c4722a9 (1) Acct-Session-Id = '5501AFCF-00000020' (1) Finished request Waking up in 0.1 seconds. Waking up in 4.1 seconds. Waking up in 0.3 seconds. Thread 3 got semaphore Thread 3 handling request 2, (1 handled so far) (2) Received Accounting-Request Id 79 from x.x.x.x:50205 to y.y.y.y:1813 length 233 (2) Acct-Session-Id = '5501AFCF-00000020' (2) Event-Timestamp = 'Mar 12 2015 12:32:14 EDT' (2) Acct-Status-Type = Start (2) Acct-Authentic = RADIUS (2) User-Name = 'user@realm' (2) NAS-IP-Address = x.x.x.x (2) NAS-Identifier = 'NAS' (2) Called-Station-Id = '000000000000:SSID' (2) NAS-Port-Type = Wireless-802.11 (2) NAS-Port = 0 (2) Calling-Station-Id = '111111111111' (2) Connect-Info = 'CONNECT 0Mbps 802.11b' (2) Acct-Session-Id = '5501AFCF-00000020' (2) Framed-IP-Address = 10.0.26.250 (2) Acct-Delay-Time = 0 (2) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (2) preacct { (2) [preprocess] = ok (2) policy acct_unique { (2) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (2) EXPAND %{string:Class} (2) --> (2) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (2) else { (2) update request { (2) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (2) --> e06f725dd6dcaefd689e573425e46b70 (2) &Acct-Unique-Session-Id := "e06f725dd6dcaefd689e573425e46b70" (2) } # update request = noop (2) } # else = noop (2) } # policy acct_unique = noop (2) suffix: Checking for suffix after "@" (2) suffix: Looking up realm "realm" for User-Name = "user@realm" (2) suffix: Found realm "realm" (2) suffix: Adding Stripped-User-Name = "user" (2) suffix: Adding Realm = "realm" (2) suffix: Proxying request from user user to realm realm (2) suffix: Preparing to proxy accounting request to realm "realm" (2) [suffix] = updated (2) [files] = noop (2) } # preacct = updated (2) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (2) accounting { (2) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (2) detail: --> /var/log/radius/radacct/x.x.x.x/detail-20150312 (2) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/x.x.x.x/detail-20150312 (2) detail: EXPAND %t (2) detail: --> Thu Mar 12 12:32:14 2015 (2) [detail] = ok (2) linelog: EXPAND Accounting-Request.%{%{Acct-Status-Type}:-unknown} (2) linelog: --> Accounting-Request.Start (2) linelog: EXPAND /var/log/radius/linelog (2) linelog: --> /var/log/radius/linelog (2) linelog: EXPAND %{Acct-Status-Type}|%{Acct-Unique-Session-Id}|%{Acct-Session-Id}|%{Called-Station-Id}|%{Called-Station-SSID}|%{Calling-Station-Id}|%{NAS-IP-Address}|%{Framed-IP-Address}|%{NAS-Identifier}|%{User-Name}|NULL|NULL|NULL|NULL|NULL|%{Event-Timestamp}|NULL (2) linelog: --> Start|e06f725dd6dcaefd689e573425e46b70|5501AFCF-00000020|000000000000:SSID||111111111111|x.x.x.x|10.0.26.250|NAS|user@realm|NULL|NULL|NULL|NULL|NULL|Mar 12 2015 12:32:14 EDT|NULL (2) [linelog] = ok (2) radutmp: EXPAND /var/log/radius/radutmp (2) radutmp: --> /var/log/radius/radutmp (2) radutmp: EXPAND %{User-Name} (2) radutmp: --> user@realm (2) [radutmp] = ok (2) sradutmp: EXPAND /var/log/radius/sradutmp (2) sradutmp: --> /var/log/radius/sradutmp (2) sradutmp: EXPAND %{User-Name} (2) sradutmp: --> user@realm (2) [sradutmp] = ok (2) [exec] = noop (2) attr_filter.accounting_response: EXPAND %{User-Name} (2) attr_filter.accounting_response: --> user@realm (2) attr_filter.accounting_response: Matched entry DEFAULT at line 14 (2) [attr_filter.accounting_response] = updated (2) } # accounting = updated Opening new proxy socket 'proxy (0.0.0.0, 0) -> home_server (z.z.z.z, 2084)' Waking up in 0.4 seconds. Waking up in 0.7 seconds. Waking up in 0.7 seconds. Received conflicting packet from client AP-Name port 50205 - ID: 79 due to unfinished request. Giving up on old request. Threads: total/active/spare threads = 5/1/4 Waking up in 0.3 seconds. Thread 1 got semaphore Thread 1 handling request 3, (1 handled so far) (3) Received Accounting-Request Id 79 from x.x.x.x:50205 to y.y.y.y:1813 length 233 (3) Acct-Session-Id = '5501AFCF-00000020' (3) Event-Timestamp = 'Mar 12 2015 12:32:14 EDT' (3) Acct-Status-Type = Start (3) Acct-Authentic = RADIUS (3) User-Name = 'user@realm' (3) NAS-IP-Address = x.x.x.x (3) NAS-Identifier = 'NAS' (3) Called-Station-Id = '000000000000:SSID' (3) NAS-Port-Type = Wireless-802.11 (3) NAS-Port = 0 (3) Calling-Station-Id = '111111111111' (3) Connect-Info = 'CONNECT 0Mbps 802.11b' (3) Acct-Session-Id = '5501AFCF-00000020' (3) Framed-IP-Address = 10.0.26.250 (3) Acct-Delay-Time = 2 (3) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (3) preacct { (3) [preprocess] = ok (3) policy acct_unique { (3) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (3) EXPAND %{string:Class} (3) --> (3) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (3) else { (3) update request { (3) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (3) --> e06f725dd6dcaefd689e573425e46b70 (3) &Acct-Unique-Session-Id := "e06f725dd6dcaefd689e573425e46b70" (3) } # update request = noop (3) } # else = noop (3) } # policy acct_unique = noop (3) suffix: Checking for suffix after "@" (3) suffix: Looking up realm "realm" for User-Name = "user@realm" (3) suffix: Found realm "realm" (3) suffix: Adding Stripped-User-Name = "user" (3) suffix: Adding Realm = "realm" (3) suffix: Proxying request from user user to realm realm (3) suffix: Preparing to proxy accounting request to realm "realm" (3) [suffix] = updated (3) [files] = noop (3) } # preacct = updated (3) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (3) accounting { (3) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d (3) detail: --> /var/log/radius/radacct/x.x.x.x/detail-20150312 (3) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/x.x.x.x/detail-20150312 (3) detail: EXPAND %t (3) detail: --> Thu Mar 12 12:32:16 2015 (3) [detail] = ok (3) linelog: EXPAND Accounting-Request.%{%{Acct-Status-Type}:-unknown} (3) linelog: --> Accounting-Request.Start (3) linelog: EXPAND /var/log/radius/linelog (3) linelog: --> /var/log/radius/linelog (3) linelog: EXPAND %{Acct-Status-Type}|%{Acct-Unique-Session-Id}|%{Acct-Session-Id}|%{Called-Station-Id}|%{Called-Station-SSID}|%{Calling-Station-Id}|%{NAS-IP-Address}|%{Framed-IP-Address}|%{NAS-Identifier}|%{User-Name}|NULL|NULL|NULL|NULL|NULL|%{Event-Timestamp}|NULL (3) linelog: --> Start|e06f725dd6dcaefd689e573425e46b70|5501AFCF-00000020|000000000000:SSID||111111111111|x.x.x.x|10.0.26.250|NAS|user@realm|NULL|NULL|NULL|NULL|NULL|Mar 12 2015 12:32:14 EDT|NULL (3) [linelog] = ok (3) radutmp: EXPAND /var/log/radius/radutmp (3) radutmp: --> /var/log/radius/radutmp (3) radutmp: EXPAND %{User-Name} (3) radutmp: --> user@realm rlm_radutmp: Login entry for NAS AP-Name port 0 duplicate (3) [radutmp] = ok (3) sradutmp: EXPAND /var/log/radius/sradutmp (3) sradutmp: --> /var/log/radius/sradutmp (3) sradutmp: EXPAND %{User-Name} (3) sradutmp: --> user@realm rlm_radutmp: Login entry for NAS AP-Name port 0 duplicate (3) [sradutmp] = ok (3) [exec] = noop (3) attr_filter.accounting_response: EXPAND %{User-Name} (3) attr_filter.accounting_response: --> user@realm (3) attr_filter.accounting_response: Matched entry DEFAULT at line 14 (3) [attr_filter.accounting_response] = updated (3) } # accounting = updated (0) <done>: Cleaning up request packet ID 77 with timestamp +5 Waking up in 0.4 seconds. Waking up in 0.1 seconds. (1) <done>: Cleaning up request packet ID 78 with timestamp +6 Failed opening proxy socket 'proxy (0.0.0.0, 0) -> home_server (z.z.z.z, 2084)' : Failed in connect(): Connection timed out Failed to insert request into the proxy list

3 9