April 2008 - Freeradius-Users - lists.freeradius.org

regular expression
by Kevin J 16 Apr '08

16 Apr '08

Is there a way that I can use for a regular expression to validate the username attribute? Something like User-Name =~ [0-9a-zA-Z.#_] I think . or # does not work. ____________________________________________________________________________________ Be a better friend, newshound, and know-it-all with Yahoo! Mobile. Try it now. http://mobile.yahoo.com/;_ylt=Ahu06i62sR8HDtDypao8Wcj9tAcJ

2 1

Assistance with Compiling pam_radius_auth Please.
by chase pettet 16 Apr '08

16 Apr '08

Greetings list, This host is running CentOS 4.3. uname -r output "2.6.9-67.0.4.plus.c4smp". I have tried looking for an already compiled module for PAM on centos without success, my google-foo is weak apparently. I downloaded the tar file straight from freeradius.org. When I unpacked and tried using "make" (as root) in the folder I get the following output. I am not much of a programmer so this error looks very confusing to me. Any help would be greatly appreciated. > [root@host pam_radius-1.3.17]# make > cc -Wall -fPIC -c pam_radius_auth.c -o pam_radius_auth.o > pam_radius_auth.c:63:34: security/pam_modules.h: No such file or directory > pam_radius_auth.c:156: error: syntax error before '*' token > pam_radius_auth.c: In function `_int_free': > pam_radius_auth.c:158: error: `x' undeclared (first use in this function) > pam_radius_auth.c:158: error: (Each undeclared identifier is reported only > once > pam_radius_auth.c:158: error: for each function it appears in.) > pam_radius_auth.c: In function `host2server': > pam_radius_auth.c:270: error: `PAM_AUTHINFO_UNAVAIL' undeclared (first use > in this function) > pam_radius_auth.c:312: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c: In function `initialize': > pam_radius_auth.c:600: error: `PAM_ABORT' undeclared (first use in this > function) > pam_radius_auth.c:659: error: `PAM_AUTHINFO_UNAVAIL' undeclared (first use > in this function) > pam_radius_auth.c:691: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c: In function `talk_radius': > pam_radius_auth.c:798: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c:995: error: `PAM_IGNORE' undeclared (first use in this > function) > pam_radius_auth.c:997: error: `PAM_AUTHINFO_UNAVAIL' undeclared (first use > in this function) > pam_radius_auth.c: At top level: > pam_radius_auth.c:1014: error: syntax error before '*' token > pam_radius_auth.c: In function `rad_converse': > pam_radius_auth.c:1017: error: storage size of 'resp_msg' isn't known > pam_radius_auth.c:1022: error: `msg_style' undeclared (first use in this > function) > pam_radius_auth.c:1023: error: `message' undeclared (first use in this > function) > pam_radius_auth.c:1027: warning: implicit declaration of function > `pam_get_item' > pam_radius_auth.c:1027: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c:1027: error: `PAM_CONV' undeclared (first use in this > function) > pam_radius_auth.c:1028: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c:1030: error: dereferencing pointer to incomplete type > pam_radius_auth.c:1030: error: dereferencing pointer to incomplete type > pam_radius_auth.c:1033: error: `password' undeclared (first use in this > function) > pam_radius_auth.c:1042: error: dereferencing pointer to incomplete type > pam_radius_auth.c:1017: warning: unused variable `resp_msg' > pam_radius_auth.c: At top level: > pam_radius_auth.c:1061: error: syntax error before "int" > pam_radius_auth.c:1062: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_sm_authenticate': > pam_radius_auth.c:1070: error: `PAM_AUTH_ERR' undeclared (first use in > this function) > pam_radius_auth.c:1078: error: `argc' undeclared (first use in this > function) > pam_radius_auth.c:1078: error: `argv' undeclared (first use in this > function) > pam_radius_auth.c:1081: warning: implicit declaration of function > `pam_get_user' > pam_radius_auth.c:1081: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c:1082: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c:1082: warning: implicit declaration of function > `pam_set_data' > pam_radius_auth.c:1088: error: `PAM_USER_UNKNOWN' undeclared (first use in > this function) > pam_radius_auth.c:1097: error: `PAM_RUSER' undeclared (first use in this > function) > pam_radius_auth.c:1102: warning: assignment from incompatible pointer type > pam_radius_auth.c:1121: error: `PAM_SERVICE' undeclared (first use in this > function) > pam_radius_auth.c:1135: error: `PAM_AUTHTOK' undeclared (first use in this > function) > pam_radius_auth.c:1152: error: `PAM_PROMPT_ECHO_OFF' undeclared (first use > in this function) > pam_radius_auth.c:1168: error: `PAM_RHOST' undeclared (first use in this > function) > pam_radius_auth.c:1199: error: `PAM_AUTHINFO_UNAVAIL' undeclared (first > use in this function) > pam_radius_auth.c:1216: error: `PAM_PROMPT_ECHO_ON' undeclared (first use > in this function) > pam_radius_auth.c:1241: warning: implicit declaration of function > `pam_set_item' > pam_radius_auth.c: At top level: > pam_radius_auth.c:1268: error: syntax error before "int" > pam_radius_auth.c:1269: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_sm_setcred': > pam_radius_auth.c:1273: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c:1275: warning: implicit declaration of function > `pam_get_data' > pam_radius_auth.c:1275: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c: At top level: > pam_radius_auth.c:1283: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_private_session': > pam_radius_auth.c:1289: error: `PAM_AUTH_ERR' undeclared (first use in > this function) > pam_radius_auth.c:1297: error: `argc' undeclared (first use in this > function) > pam_radius_auth.c:1297: error: `argv' undeclared (first use in this > function) > pam_radius_auth.c:1300: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c:1301: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c:1301: error: `PAM_SESSION_ERR' undeclared (first use in > this function) > pam_radius_auth.c:1306: error: `PAM_USER_UNKNOWN' undeclared (first use in > this function) > pam_radius_auth.c:1321: error: `PAM_SERVICE' undeclared (first use in this > function) > pam_radius_auth.c:1336: error: `status' undeclared (first use in this > function) > pam_radius_auth.c:1355: error: `PAM_PERM_DENIED' undeclared (first use in > this function) > pam_radius_auth.c: At top level: > pam_radius_auth.c:1369: error: syntax error before "int" > pam_radius_auth.c:1370: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_sm_open_session': > pam_radius_auth.c:1373: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c:1373: error: `flags' undeclared (first use in this > function) > pam_radius_auth.c:1373: error: `argc' undeclared (first use in this > function) > pam_radius_auth.c:1373: error: `argv' undeclared (first use in this > function) > pam_radius_auth.c: At top level: > pam_radius_auth.c:1376: error: syntax error before "int" > pam_radius_auth.c:1377: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_sm_close_session': > pam_radius_auth.c:1380: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c:1380: error: `flags' undeclared (first use in this > function) > pam_radius_auth.c:1380: error: `argc' undeclared (first use in this > function) > pam_radius_auth.c:1380: error: `argv' undeclared (first use in this > function) > pam_radius_auth.c: At top level: > pam_radius_auth.c:1387: error: syntax error before "int" > pam_radius_auth.c:1388: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_sm_chauthtok': > pam_radius_auth.c:1395: error: `PAM_AUTHTOK_ERR' undeclared (first use in > this function) > pam_radius_auth.c:1404: error: `argc' undeclared (first use in this > function) > pam_radius_auth.c:1404: error: `argv' undeclared (first use in this > function) > pam_radius_auth.c:1407: error: `pamh' undeclared (first use in this > function) > pam_radius_auth.c:1408: error: `PAM_SUCCESS' undeclared (first use in this > function) > pam_radius_auth.c:1413: error: `PAM_USER_UNKNOWN' undeclared (first use in > this function) > pam_radius_auth.c:1428: error: `PAM_SERVICE' undeclared (first use in this > function) > pam_radius_auth.c:1437: error: `PAM_OLDAUTHTOK' undeclared (first use in > this function) > pam_radius_auth.c:1442: error: `PAM_AUTHTOK' undeclared (first use in this > function) > pam_radius_auth.c:1447: error: `flags' undeclared (first use in this > function) > pam_radius_auth.c:1447: error: `PAM_PRELIM_CHECK' undeclared (first use in > this function) > pam_radius_auth.c:1449: error: `PAM_PROMPT_ECHO_OFF' undeclared (first use > in this function) > pam_radius_auth.c:1475: error: `PAM_PERM_DENIED' undeclared (first use in > this function) > pam_radius_auth.c:1500: error: `PAM_ERROR_MSG' undeclared (first use in > this function) > pam_radius_auth.c:1552: error: `PAM_UPDATE_AUTHTOK' undeclared (first use > in this function) > pam_radius_auth.c: At top level: > pam_radius_auth.c:1616: error: syntax error before "int" > pam_radius_auth.c:1617: error: syntax error before '*' token > pam_radius_auth.c: In function `pam_sm_acct_mgmt': > pam_radius_auth.c:1620: error: `PAM_SUCCESS' undeclared (first use in this > function) > make: *** [pam_radius_auth.o] Error 1 Thanks, Chase

2 1

Re: newbie on radiustesting
by Si St 16 Apr '08

16 Apr '08

> ----- Original Message ----- > From: A.L.M.Buxey(a)lboro.ac.uk > To: "FreeRadius users mailing list" <freeradius-users(a)lists.freeradius.org> > Subject: Re: newbie on radiustesting > Date: Wed, 16 Apr 2008 18:51:12 +0100 > > > Hi, > > FreeRADIUS Version 1.0.4, for host , built on Sep 13 2005 > > > > I might not know what I am doing, but what is the first thing for > > me do to here? > > ...update to 2.0.3? ;-) > > > But changing no other tings, leaving the test-setup (unchanged > > files in /etc/raddb/certs from the installation of radius-package > > in YaST) as it was. > > you need to ensure that the process you run freeradius (radiusd daemon) as > (which is probably 'radiusd' id) has permission to read the /etc/raddb/certs > directory. > > alan > - ------------------------------------------ Answ to Alan: I think it has the permissions: linux:/etc/raddb # id radiusd uid=105(radiusd) gid=104(radiusd) Gruppen=104(radiusd) ls -l: drw-r----- 3 root radiusd 472 2008-03-31 22:53 certs/ /etc/group: radiusd:!:104: -- _______________________________________________ Surf the Web in a faster, safer and easier way: Download Opera 9 at http://www.opera.com Powered by Outblaze

2 1

newbie on radiustesting
by Si St 16 Apr '08

16 Apr '08

FreeRADIUS Version 1.0.4, for host , built on Sep 13 2005 I might not know what I am doing, but what is the first thing for me do to here? (take a look at the /linux:~ # radiusd -X / part further down) Are these errors in the debugmode caused by not running the script saying in eap.conf: ## EAP-TLS # # To generate ctest certificates, run the script # # ../scripts/certs.sh Or are the errors caused by other tings? What I simply have done is to uncomment the EAP part in eap.conf in this way: tls { private_key_password = whatever private_key_file = ${raddbdir}/certs/cert-srv.pem # If Private key & Certificate are located in # the same file, then private_key_file & # certificate_file must contain the same file # name. certificate_file = ${raddbdir}/certs/cert-srv.pem # Trusted Root CA list CA_file = ${raddbdir}/certs/demoCA/cacert.pem dh_file = ${raddbdir}/certs/dh random_file = ${raddbdir}/certs/random # # This can never exceed the size of a RADIUS # packet (4096 bytes), and is preferably half # that, to accomodate other attributes in # RADIUS packet. On most APs the MAX packet # length is configured between 1500 - 1600 # In these cases, fragment size should be # 1024 or less. # fragment_size = 1024 # include_length is a flag which is # by default set to yes If set to # yes, Total Length of the message is # included in EVERY packet we send. # If set to no, Total Length of the # message is included ONLY in the # First packet of a fragment series. # include_length = yes # Check the Certificate Revocation List # # 1) Copy CA certificates and CRLs to same directory. # 2) Execute 'c_rehash <CA certs&CRLs Directory>'. # 'c_rehash' is OpenSSL's command. # 3) Add 'CA_path=<CA certs&CRLs directory>' # to radiusd.conf's tls section. # 4) uncomment the line below. # 5) Restart radiusd check_crl = yes # # If check_cert_cn is set, the value will # be xlat'ed and checked against the CN # in the client certificate. If the values # do not match, the certificate verification # will fail rejecting the user. # check_cert_cn = %{User-Name} } But changing no other tings, leaving the test-setup (unchanged files in /etc/raddb/certs from the installation of radius-package in YaST) as it was. ----------------------------------------------------------------------------------- linux:~ # radiusd -X Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /etc/raddb/proxy.conf Config: including file: /etc/raddb/clients.conf Config: including file: /etc/raddb/snmp.conf Config: including file: /etc/raddb/eap.conf Config: including file: /etc/raddb/sql.conf main: prefix = "/usr" main: localstatedir = "/var" main: logdir = "/var/log/radius" main: libdir = "/usr/lib/freeradius" main: radacctdir = "/var/log/radius/radacct" main: hostname_lookups = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 0 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/var/log/radius/radius.log" main: log_auth = no main: log_auth_badpass = no main: log_auth_goodpass = no main: pidfile = "/var/run/radiusd/radiusd.pid" main: user = "radiusd" main: group = "radiusd" main: usercollide = no main: lower_user = "no" main: lower_pass = "no" main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/sbin/checkrad" main: proxy_requests = yes proxy: retry_delay = 5 proxy: retry_count = 3 proxy: synchronous = no proxy: default_fallback = yes proxy: dead_time = 120 proxy: post_proxy_authorize = yes proxy: wake_all_if_all_dead = no security: max_attributes = 200 security: reject_delay = 1 security: status_server = no main: debug_level = 0 read_config_files: reading dictionary read_config_files: reading naslist read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Module: Library search path is /usr/lib/freeradius Module: Loaded exec exec: wait = yes exec: program = "(null)" exec: input_pairs = "request" exec: output_pairs = "(null)" exec: packet_type = "(null)" rlm_exec: Wait=yes but no output defined. Did you mean output=none? Module: Instantiated exec (exec) Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded PAP pap: encryption_scheme = "crypt" Module: Instantiated pap (pap) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = no mschap: require_strong = no mschap: with_ntdomain_hack = no mschap: passwd = "(null)" mschap: authtype = "MS-CHAP" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) Module: Loaded System unix: cache = no unix: passwd = "(null)" unix: shadow = "(null)" unix: group = "(null)" unix: radwtmp = "/var/log/radius/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded eap eap: default_eap_type = "md5" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no eap: cisco_accounting_username_bug = no rlm_eap: Loaded and initialized type md5 rlm_eap: Loaded and initialized type leap gtc: challenge = "Password: " gtc: auth_type = "PAP" rlm_eap: Loaded and initialized type gtc tls: rsa_key_exchange = no tls: dh_key_exchange = yes tls: rsa_key_length = 512 tls: dh_key_length = 512 tls: verify_depth = 0 tls: CA_path = "(null)" tls: pem_file_type = yes tls: private_key_file = "/etc/raddb/certs/cert-srv.pem" tls: certificate_file = "/etc/raddb/certs/cert-srv.pem" tls: CA_file = "/etc/raddb/certs/demoCA/cacert.pem" tls: private_key_password = "whatever" tls: dh_file = "/etc/raddb/certs/dh" tls: random_file = "/etc/raddb/certs/random" tls: fragment_size = 1024 tls: include_length = yes tls: check_crl = yes tls: check_cert_cn = "%{User-Name}" 21278:error:0200100D:system library:fopen:Permission denied:bss_file.c:104:fopen('/etc/raddb/certs/demoCA/cacert.pem','r') 21278:error:2006D002:BIO routines:BIO_new_file:system lib:bss_file.c:109: 21278:error:0B084002:x509 certificate routines:X509_load_cert_crl_file:system lib:by_file.c:274: rlm_eap_tls: Error reading Trusted root CA list rlm_eap: Failed to initialize type tls radiusd.conf[9]: eap: Module instantiation failed. ------------------------------------------------------------- Here is another output after the reconfiguration of eap.conf: linux:/etc/raddb # rcradiusd status Checking for service radiusd unused linux:/etc/raddb # rcradiusd start Starting RADIUS daemon 21816:error:0200100D:system library:fopen:Permission denied:bss_file.c:104:fopen('/etc/raddb/certs/demoCA/cacert.pem','r') 21816:error:2006D002:BIO routines:BIO_new_file:system lib:bss_file.c:109: 21816:error:0B084002:x509 certificate routines:X509_load_cert_crl_file:system lib:by_file.c:274: startproc: exit status of parent of /usr/sbin/radiusd: 1 failed -- _______________________________________________ Surf the Web in a faster, safer and easier way: Download Opera 9 at http://www.opera.com Powered by Outblaze

2 1

ENV variables in external scripts
by rsg 16 Apr '08

16 Apr '08

Hi, I need to check an environmental varible with an external script. For example to capture Calling-Station-Id and check it in an external database using a perl script # ../users : . DEFAULT Auth-Type = None Exec-Program-Wait = "/root/check.pl %i", Reply-Message := "Valid Caller-Id, access granted -> %{Calling-station-Id}", Fall-Through = Yes : . How could I call this ENV variable in my perl script ("/root/check.pl) ? I unsuccessfully attempted the options given by ../docs/variables.txt. Please help with the correct syntax. Thanks in advance. rsg

5 27

Cisco NAS and 4GB Problem
by Andreas M. 16 Apr '08

16 Apr '08

Hello, i have some troubles with a cisco NAS, with a 4GB problem in the Accounting Data. First i have gigawords enabled, also the sql queries, but this is not the reason. I have also accounting for the upstream interface enabled, but the error exists only for users, that are connected via virtual-interfaces (pptp dialup). Maybe this problem is not realy radius related, but i hope to find an answer. I included some log entries and config examples, maybe someone has any experience with this errors. regards, Andreas M. Here is the last interim update: Tue Apr 15 23:23:46 2008 Acct-Session-Id = "00000006" Tunnel-Medium-Type:0 = IPv4 Tunnel-Assignment-Id:0 = "1" Tunnel-Server-Auth-Id:0 = "A_Router" Acct-Tunnel-Connection = "40682" Framed-Protocol = PPP Framed-IP-Address = 10.1.0.1 User-Name = "6543765" Acct-Session-Time = 28088 Acct-Input-Octets = 18615686 Acct-Output-Octets = 218389141 Acct-Input-Packets = 226199 Acct-Output-Packets = 305451 Acct-Authentic = RADIUS Acct-Status-Type = Interim-Update NAS-Port-Type = Virtual NAS-Port = 3 NAS-Port-Id = "Uniq-Sess-ID3" Service-Type = Framed-User NAS-IP-Address = 192.168.1.11 Acct-Delay-Time = 0 Client-IP-Address = 192.168.1.11 Acct-Unique-Session-Id = "ba144af9c3c26fc1" Timestamp = 1208294626 Here is the last stop record from the nas: Tue Apr 15 23:26:28 2008 Acct-Session-Id = "00000006" Tunnel-Medium-Type:0 = IPv4 Tunnel-Assignment-Id:0 = "1" Tunnel-Server-Auth-Id:0 = "A_Router" Acct-Tunnel-Connection = "40682" Framed-Protocol = PPP Framed-IP-Address = 10.1.0.1 User-Name = "6543765" Acct-Authentic = RADIUS Acct-Session-Time = 28250 Acct-Input-Octets = 4294967295 Acct-Output-Octets = 4294966951 Acct-Input-Packets = 0 Acct-Output-Packets = 4294967290 Acct-Terminate-Cause = NAS-Error Acct-Status-Type = Stop NAS-Port-Type = Virtual NAS-Port = 3 NAS-Port-Id = "Uniq-Sess-ID3" Service-Type = Framed-User NAS-IP-Address = 192.168.1.11 Acct-Delay-Time = 0 Client-IP-Address = 192.168.1.11 Acct-Unique-Session-Id = "ba144af9c3c26fc1" Timestamp = 1208294788 Cisco config: System image file is "flash:c180x-advipservicesk9-mz.124-11.XW6.bin" A_Router#sh aaa attributes | inc giga Type=118 Name=input-giga-words Format=Ulong Type=250 Name=output-giga-words Format=Ulong aaa new-model ! ! aaa authentication login default local aaa authentication ppp default group radius local aaa authorization exec default local aaa authorization commands 15 default local aaa authorization network default group radius local aaa accounting delay-start aaa accounting nested aaa accounting update periodic 3 aaa accounting network default start-stop group radius interface Virtual-Template1 ip unnumbered Loopback0 ip nat inside no ip virtual-reassembly no logging event link-status no snmp trap link-status ppp encrypt mppe 128 required ppp authentication ms-chap ms-chap-v2

2 4

detail sql logging problem
by A.L.M.Buxey＠lboro.ac.uk 16 Apr '08

16 Apr '08

hi, further to last email, heres example packet: Tue Apr 15 12:20:56 2008 User-Name = "xxxxx" NAS-Port = 29 NAS-IP-Address = 192.168.1.28 Framed-IP-Address = 192.168.0.3 NAS-Identifier = "wism" Airespace-Wlan-Id = 1 Acct-Session-Id = "48048f97/00:11:12:12:14:11/8514" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "222" Acct-Status-Type = Stop Acct-Input-Octets = 1942107 Acct-Output-Octets = 5085070 Acct-Input-Packets = 9162 Acct-Output-Packets = 8299 Acct-Terminate-Cause = Lost-Service Acct-Session-Time = 0 Acct-Delay-Time = 0 Calling-Station-Id = "192.168.0.3" Called-Station-Id = "192.168.1.28" Acct-Unique-Session-Id = "f7ebd89424c03437" Timestamp = 1208258456 Request-Authenticator = Verified as you can see, Stop request, due to lost service. however, sessio-time is 0 - i suspect this is because of mobility. they've moved from one wism controller to another or from one AP to another and then left the network altogther. either way, kit is reporting the value. in our SQL logging we look for the Acct-Session-Id, and the Timestamp and then use those to create the session time due to wierdnesses (see the example UPDATE comand in sql/postgresl/dialup.conf to get what I mean) so hope we dont actually care about what the kit tells us(!) alan

2 4

encrypted passwords in users file
by ashish verma 16 Apr '08

16 Apr '08

Hi all, Is it possible to keep encrypted passwords in users file? For e.g. test Cleartext-Password := "test" Service-type = NAS-Prompt-User instead of cleartext can we have encrypted passwords here. Thanks. On Thu, Mar 13, 2008 at 4:32 PM, < freeradius-users-owner(a)lists.freeradius.org> wrote: > You are not allowed to post to this mailing list, and your message has > been automatically rejected. If you think that your messages are > being rejected in error, contact the mailing list owner at > freeradius-users-owner(a)lists.freeradius.org. > > > > ---------- Forwarded message ---------- > From: "ashish verma" <ashish.scit(a)gmail.com> > To: freeradius-users(a)lists.freeradius.org > Date: Thu, 13 Mar 2008 16:32:21 +0530 > Subject: encrypted passwords in users file > Hi all, > > Is it possible to keep encrypted passwords in users file? > > For e.g. test Cleartext-Password := "test" > Service-type = NAS-Prompt-User > > instead of cleartext can we have encrypted passwords here. > > Thanks. > > > > On Tue, Oct 23, 2007 at 2:03 PM, < > freeradius-users-request(a)lists.freeradius.org> wrote: > > > Send Freeradius-Users mailing list submissions to > > freeradius-users(a)lists.freeradius.org > > > > To subscribe or unsubscribe via the World Wide Web, visit > > http://lists.freeradius.org/mailman/listinfo/freeradius-users > > or, via email, send a message with subject or body 'help' to > > freeradius-users-request(a)lists.freeradius.org > > > > You can reach the person managing the list at > > freeradius-users-owner(a)lists.freeradius.org > > > > When replying, please edit your Subject line so it is more specific > > than "Re: Contents of Freeradius-Users digest..." > > > > > > Today's Topics: > > > > 1. Are SHA-256 certificates supported? (hannu.lammi(a)wipsl.com) > > 2. Re: Freeradius doesn't detect EAP when authenticating against > > MySQL (Alan DeKok) > > 3. Re: TTLS with Mutual Authentication (Alan DeKok) > > 4. Re: Are SHA-256 certificates supported? (Alan DeKok) > > 5. FreeRADIUS and SNMP questions (Geoffroy Arnoud) > > 6. Re: Freeradius doesn't detect EAP when authenticating against > > MySQL (primoz) > > 7. Re: FreeRADIUS and SNMP questions (Alan DeKok) > > 8. Re: Freeradius doesn't detect EAP when authenticating against > > MySQL (Alan DeKok) > > > > > > ---------------------------------------------------------------------- > > > > Message: 1 > > Date: Tue, 23 Oct 2007 10:10:05 +0300 (EEST) > > From: hannu.lammi(a)wipsl.com > > Subject: Are SHA-256 certificates supported? > > To: freeradius-users(a)lists.freeradius.org > > Message-ID: <14671.192.100.116.143.1193123405.squirrel(a)mail.wipsl.com> > > Content-Type: text/plain;charset=utf-8 > > > > Hi, > > > > I need to set up a RADIUS server that accepts certificates which use > > SHA-256 as signature algorithm (OID sha256WithRSAEncryption). I have set > > up a FreeRADIUS 2.0.0-pre2 server to see if this would work out of the > > box. > > > > After verifying that EAP-TLS authentication works with SHA-1 > > certificates > > I switched to SHA-256 certificate that was created with OpenSSL 0.9.8b, > > the same that FreeRADIUS was compiled against. > > > > Here's a snippet of the log I got from my SHA-256 test: > > > > ===== > > --> verify error:num=7:certificate signature failure > > rlm_eap_tls: >>> TLS 1.0 Alert [length 0002], fatal decrypt_error > > TLS Alert write:fatal:decrypt error > > TLS_accept:error in SSLv3 read client certificate B > > rlm_eap: SSL error error:0D0C50A1:asn1 encoding > > routines:ASN1_item_verify:unknown message digest algorithm > > ===== > > > > It would seem there's a problem somewhere. It may very well be in the > > client I'm using. > > > > So, I'd like to know if FreeRADIUS supports SHA-256 certificates? > > If it doesn't, is the support for them planned? > > > > thanks in advance, > > - Hannu > > > > > > > > ------------------------------ > > > > Message: 2 > > Date: Tue, 23 Oct 2007 09:12:03 +0200 > > From: Alan DeKok <aland(a)deployingradius.com> > > Subject: Re: Freeradius doesn't detect EAP when authenticating against > > MySQL > > To: FreeRadius users mailing list > > <freeradius-users(a)lists.freeradius.org> > > Message-ID: <471D9EC3.4090609(a)deployingradius.com> > > Content-Type: text/plain; charset=ISO-8859-1 > > > > preem wrote: > > > So, what is a common practice to do this then? > > > > It's not. > > > > People store MD5 or crypt'd passwords when the ONLY authentication > > they're doing is PAP. i.e. Unix logins, where the user supplies a > > clear-text password to the authentication system. > > > > For many EAP types, people do NOT store MD5 or crypt'd passwords, > > because they're useless. > > > > > I understand its not very > > > safe nor sane to store passwords in clear text, thats why I wanted to > > avoid > > > that, however it seems inevitable. > > > > It is safe, sane, and common practice to store passwords in clear text. > > > > > I am managing a wired network for some 300 users, its a student dorm > > and the > > > university owns the network and they require authentication for the > > ease of > > > management and control. 802.1x felt like the right way to go, because > > we are > > > planning some wireless access points as well. There are HP's Procurve > > 2650 > > > switches in use. I choose mysql db backend, because I also created set > > of > > > PHP scripts, where users can change their passwords and admin can > > > add/del/modify user info. > > > So what can one do to avoid storing passes in clear text or is it sane > > > enough? The server also serves some web pages and dhcp requests. > > > > Ensure that no one has physical access to the system storing the > > passwords. Ensure that no one has network access to the system storing > > the passwords. > > > > I would also suggest running the RADIUS server and/or the MySQL server > > with passwords on a separate machine from the web/dhcp server. That > > way, if someone breaks into the web server, they won't have access to > > the passwords. > > > > Alan DeKok. > > > > > > ------------------------------ > > > > Message: 3 > > Date: Tue, 23 Oct 2007 09:23:50 +0200 > > From: Alan DeKok <aland(a)deployingradius.com> > > Subject: Re: TTLS with Mutual Authentication > > To: FreeRadius users mailing list > > <freeradius-users(a)lists.freeradius.org> > > Message-ID: <471DA186.5030601(a)deployingradius.com> > > Content-Type: text/plain; charset=UTF-8 > > > > Zolotov, Eyal wrote: > > > By ?mutual authentication? I refer to the following authentication > > process: > > > > > > 1. The client authenticate the server > > > > Give the client the CA cert used to sign the server cert. > > > > > 2. The server authenticate the client > > > > Create a client cert, signed by the server cert. > > > > > 3. Only than ? the clients sends username + password using > > MSCHAPv2 > > > > In unlang, set: > > > > update control { > > EAP-TLS-Require-Client-Cert = yes > > } > > > > This forces the server to validate the client cert, which is normally > > not required for TTLS. > > > > Alan DeKok. > > > > > > ------------------------------ > > > > Message: 4 > > Date: Tue, 23 Oct 2007 09:25:33 +0200 > > From: Alan DeKok <aland(a)deployingradius.com> > > Subject: Re: Are SHA-256 certificates supported? > > To: FreeRadius users mailing list > > <freeradius-users(a)lists.freeradius.org> > > Message-ID: <471DA1ED.9050806(a)deployingradius.com> > > Content-Type: text/plain; charset=ISO-8859-1 > > > > hannu.lammi(a)wipsl.com wrote: > > > I need to set up a RADIUS server that accepts certificates which use > > > SHA-256 as signature algorithm (OID sha256WithRSAEncryption). I have > > set > > > up a FreeRADIUS 2.0.0-pre2 server to see if this would work out of the > > > box. > > > > If OpenSSL supports it, AND the client supplicant supports it, it > > should work. > > > > > Here's a snippet of the log I got from my SHA-256 test: > > > > > > ===== > > > --> verify error:num=7:certificate signature failure > > > rlm_eap_tls: >>> TLS 1.0 Alert [length 0002], fatal decrypt_error > > > TLS Alert write:fatal:decrypt error > > > TLS_accept:error in SSLv3 read client certificate B > > > rlm_eap: SSL error error:0D0C50A1:asn1 encoding > > > routines:ASN1_item_verify:unknown message digest algorithm > > > > That would seem to be an SSL issue. > > > > > So, I'd like to know if FreeRADIUS supports SHA-256 certificates? > > > If it doesn't, is the support for them planned? > > > > FreeRADIUS doesn't support SSL. It uses OpenSSL, which *does* support > > SSL. So if there are SSL issues, find out why OpenSSL doesn't like the > > TLS session. > > > > Alan DeKok. > > > > > > ------------------------------ > > > > Message: 5 > > Date: Tue, 23 Oct 2007 10:04:23 +0200 (CEST) > > From: Geoffroy Arnoud <garnoud(a)yahoo.co.uk> > > Subject: FreeRADIUS and SNMP questions > > To: FreeRADIUS users <freeradius-users(a)lists.freeradius.org> > > Message-ID: <626622.60897.qm(a)web27314.mail.ukl.yahoo.com> > > Content-Type: text/plain; charset=iso-8859-1 > > > > Hi all, > > > > I have 2 questions regarding FreeRADIUS and SNMP: > > > > 1/ Is it possible to run 2 FreeRADIUS servers on the > > same box, with SNMP support activated? I understand > > it's possible, using distinct values for smux_password > > parameter. > > > > 2/ Connecting FreeRADIUS to Net-SNMP using SMUX is > > quite easy. Has anyone connected FreeRADIUS with BMC > > PAtrol agent using SMUX? > > > > Thanks for any answer > > > > Geoff. > > > > > > > > _____________________________________________________________________________ > > Ne gardez plus qu'une seule adresse mail ! Copiez vos mails vers Yahoo! > > Mail > > > > > > ------------------------------ > > > > Message: 6 > > Date: Tue, 23 Oct 2007 10:08:22 +0200 > > From: primoz <primski(a)gmail.com> > > Subject: Re: Freeradius doesn't detect EAP when authenticating against > > MySQL > > To: "FreeRadius users mailing list" > > <freeradius-users(a)lists.freeradius.org> > > Message-ID: > > <ead364dc0710230108u752b2593h4a7885ca04e61ce7(a)mail.gmail.com> > > Content-Type: text/plain; charset="iso-8859-1" > > > > On 10/23/07, Alan DeKok <aland(a)deployingradius.com> wrote: > > > > > > preem wrote: > > > > So, what is a common practice to do this then? > > > > > > It's not. > > > > > > People store MD5 or crypt'd passwords when the ONLY authentication > > > they're doing is PAP. i.e. Unix logins, where the user supplies a > > > clear-text password to the authentication system. > > > > > > > > And PAP is not very safe and smart way to go as i read it. > > > > For many EAP types, people do NOT store MD5 or crypt'd passwords, > > > because they're useless. > > > > > > > > So, crypted passwords are usefull only in web applications? I read a lot > > lately about, how one should never store passwords in clear text, i > > guess > > that applies only to web apps. > > > > > I understand its not very > > > > safe nor sane to store passwords in clear text, thats why I wanted > > to > > > avoid > > > > that, however it seems inevitable. > > > > > > It is safe, sane, and common practice to store passwords in clear > > text. > > > > > > > > I do not have many experience with this, in fact its my first project on > > the > > matter. > > > > > I am managing a wired network for some 300 users, its a student dorm > > and > > > the > > > > university owns the network and they require authentication for the > > ease > > > of > > > > management and control. 802.1x felt like the right way to go, > > because we > > > are > > > > planning some wireless access points as well. There are HP's > > Procurve > > > 2650 > > > > switches in use. I choose mysql db backend, because I also created > > set > > > of > > > > PHP scripts, where users can change their passwords and admin can > > > > add/del/modify user info. > > > > So what can one do to avoid storing passes in clear text or is it > > sane > > > > enough? The server also serves some web pages and dhcp requests. > > > > > > Ensure that no one has physical access to the system storing the > > > passwords. Ensure that no one has network access to the system > > storing > > > the passwords. > > > > > > > > That will be no problem, since I'm the only one with physical access. > > > > I would also suggest running the RADIUS server and/or the MySQL server > > > with passwords on a separate machine from the web/dhcp server. That > > > way, if someone breaks into the web server, they won't have access to > > > the passwords. > > > > > > I am using VMWare server, so that won't require much work. > > > > Alan DeKok. > > > - > > > List info/subscribe/unsubscribe? See > > > http://www.freeradius.org/list/users.html > > > > > > > > Thanks again, for clearing this up. > > > > primski > >

3 9

pam_radius authentication problem - no password?
by Enno 16 Apr '08

16 Apr '08

Hi, I have problems using pam_radius to authenticate users using our freeradius server. I want to use it with openvpn but tested it with ssh. The new part of my /etc/pam.d/ssh looks like: # /etc/security/pam_env.conf. auth required pam_env.so # [1] auth sufficient /lib/security/pam_radius_auth.so debug try_first_pass To nail the problem down I added some debug info to pam_radius_auth.c: /* grab the password (if any) from the previous authentication layer */ retval = pam_get_item(pamh, PAM_AUTHTOK, (CONST void **) &password); DPRINT(LOG_DEBUG, "Get password retval: %d, %d", retval, PAM_SUCCESS); PAM_FAIL_CHECK; DPRINT(LOG_DEBUG, "X Got password %s", password); if(password) { password = strdup(password); DPRINT(LOG_DEBUG, "Got password %s", password); } My auth.log file then says: Apr 15 13:55:04 openvpnserver sshd[29747]: pam_radius_auth: Got user name enno Apr 15 13:55:04 openvpnserver sshd[29747]: pam_radius_auth: Get password retval: 0, 0 Apr 15 13:55:04 openvpnserver sshd[29747]: pam_radius_auth: X Got password (null) Apr 15 13:55:04 openvpnserver sshd[29747]: pam_radius_auth: Sending RADIUS request code 1 Apr 15 13:55:09 openvpnserver sshd[29747]: pam_radius_auth: RADIUS server <our_radius_server> failed to respond Apr 15 13:55:09 openvpnserver sshd[29747]: pam_radius_auth: All RADIUS servers failed to respond. Apr 15 13:55:09 openvpnserver sshd[29747]: pam_radius_auth: authentication failed There seem to be problems connecting to the radius server sometimes, but I think this isn't the problem here. When the connection works, I get radius response code 3 (afair). I'm testing this on the target machine (openvpn server) using "ssh -l enno 127.0.0.1" and some random password (first I tried with the correct password and then started debugging). Looking at the code of pam_radius_auth.c and at the output of auth.log I would say the call to pam seems to not return the AUTHTOK. The call succedes, but the password pointer is NULL. Any ideas? Thanks in advance Enno Gröper

2 1

Re: exec-program-wait problem with freeradius 2.0.3
by Emmanuel Willems 16 Apr '08

16 Apr '08

Here is a relevant part of the debug log: > Tue Apr 15 14:36:10 2008 : Info: FreeRADIUS Version 2.0.3, for host > i686-pc-linux-gnu, built on Apr 11 2008 at 17:11:07 > Tue Apr 15 14:36:10 2008 : Info: Copyright (C) 1999-2008 The > FreeRADIUS server project and contributors. > Tue Apr 15 14:36:10 2008 : Info: There is NO warranty; not even for > MERCHANTABILITY or FITNESS FOR A > Tue Apr 15 14:36:10 2008 : Info: PARTICULAR PURPOSE. > Tue Apr 15 14:36:10 2008 : Info: You may redistribute copies of > FreeRADIUS under the terms of the > Tue Apr 15 14:36:10 2008 : Info: GNU General Public License. > Tue Apr 15 14:36:10 2008 : Info: Starting - reading configuration > files ... > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/radiusd.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/proxy.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/clients.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/snmp.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/eap.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/sql.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/sql/mysql/dialup.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/sql/mysql/counter.conf > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/policy.conf > Tue Apr 15 14:36:10 2008 : Debug: including files in directory > /usr/local/freeradius203/etc/raddb/sites-enabled/ > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/sites-enabled/default > Tue Apr 15 14:36:10 2008 : Debug: including configuration file > /usr/local/freeradius203/etc/raddb/sites-enabled/inner-tunnel > Tue Apr 15 14:36:10 2008 : Debug: including dictionary file > /usr/local/freeradius203/etc/raddb/dictionary > Tue Apr 15 14:36:10 2008 : Debug: main { > Tue Apr 15 14:36:10 2008 : Debug: prefix = "/usr/local/freeradius203" > Tue Apr 15 14:36:10 2008 : Debug: localstatedir = > "/usr/local/freeradius203/var" > Tue Apr 15 14:36:10 2008 : Debug: logdir = > "/usr/local/freeradius203/var/log/radius" > Tue Apr 15 14:36:10 2008 : Debug: libdir = > "/usr/local/freeradius203/lib" > Tue Apr 15 14:36:10 2008 : Debug: radacctdir = > "/usr/local/freeradius203/var/log/radius/radacct" > Tue Apr 15 14:36:10 2008 : Debug: hostname_lookups = no > Tue Apr 15 14:36:10 2008 : Debug: max_request_time = 30 > Tue Apr 15 14:36:10 2008 : Debug: cleanup_delay = 5 > Tue Apr 15 14:36:10 2008 : Debug: max_requests = 1024 > Tue Apr 15 14:36:10 2008 : Debug: allow_core_dumps = no > Tue Apr 15 14:36:10 2008 : Debug: pidfile = > "/usr/local/freeradius203/var/run/radiusd/radiusd.pid" > Tue Apr 15 14:36:10 2008 : Debug: user = "radiusd" > Tue Apr 15 14:36:10 2008 : Debug: group = "radiusd" > Tue Apr 15 14:36:10 2008 : Debug: checkrad = > "/usr/local/freeradius203/sbin/checkrad" > Tue Apr 15 14:36:10 2008 : Debug: debug_level = 0 > Tue Apr 15 14:36:10 2008 : Debug: proxy_requests = yes > Tue Apr 15 14:36:10 2008 : Debug: security { > Tue Apr 15 14:36:10 2008 : Debug: max_attributes = 200 > Tue Apr 15 14:36:10 2008 : Debug: reject_delay = 1 > Tue Apr 15 14:36:10 2008 : Debug: status_server = yes > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: client localhost { > Tue Apr 15 14:36:10 2008 : Debug: ipaddr = 127.0.0.1 > Tue Apr 15 14:36:10 2008 : Debug: require_message_authenticator = no > Tue Apr 15 14:36:10 2008 : Debug: secret = "testing123" > Tue Apr 15 14:36:10 2008 : Debug: nastype = "other" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: client 192.168.1.0/24 { > Tue Apr 15 14:36:10 2008 : Debug: require_message_authenticator = no > Tue Apr 15 14:36:10 2008 : Debug: secret = "wlansenbel" > Tue Apr 15 14:36:10 2008 : Debug: shortname = "wlan-sen" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: radiusd: #### Loading Realms and > Home Servers #### > Tue Apr 15 14:36:10 2008 : Debug: proxy server { > Tue Apr 15 14:36:10 2008 : Debug: retry_delay = 5 > Tue Apr 15 14:36:10 2008 : Debug: retry_count = 3 > Tue Apr 15 14:36:10 2008 : Debug: default_fallback = no > Tue Apr 15 14:36:10 2008 : Debug: dead_time = 120 > Tue Apr 15 14:36:10 2008 : Debug: wake_all_if_all_dead = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: home_server localhost { > Tue Apr 15 14:36:10 2008 : Debug: ipaddr = 127.0.0.1 > Tue Apr 15 14:36:10 2008 : Debug: port = 1812 > Tue Apr 15 14:36:10 2008 : Debug: type = "auth" > Tue Apr 15 14:36:10 2008 : Debug: secret = "testing123" > Tue Apr 15 14:36:10 2008 : Debug: response_window = 20 > Tue Apr 15 14:36:10 2008 : Debug: max_outstanding = 65536 > Tue Apr 15 14:36:10 2008 : Debug: zombie_period = 40 > Tue Apr 15 14:36:10 2008 : Debug: status_check = "status-server" > Tue Apr 15 14:36:10 2008 : Debug: ping_check = "none" > Tue Apr 15 14:36:10 2008 : Debug: ping_interval = 30 > Tue Apr 15 14:36:10 2008 : Debug: check_interval = 30 > Tue Apr 15 14:36:10 2008 : Debug: num_answers_to_alive = 3 > Tue Apr 15 14:36:10 2008 : Debug: num_pings_to_alive = 3 > Tue Apr 15 14:36:10 2008 : Debug: revive_interval = 120 > Tue Apr 15 14:36:10 2008 : Debug: status_check_timeout = 4 > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: home_server_pool my_auth_failover { > Tue Apr 15 14:36:10 2008 : Debug: type = fail-over > Tue Apr 15 14:36:10 2008 : Debug: home_server = localhost > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: realm example.com { > Tue Apr 15 14:36:10 2008 : Debug: auth_pool = my_auth_failover > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: realm LOCAL { > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: radiusd: #### Instantiating modules #### > Tue Apr 15 14:36:10 2008 : Debug: instantiate { > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_exec, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_exec > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating exec > Tue Apr 15 14:36:10 2008 : Debug: exec { > Tue Apr 15 14:36:10 2008 : Debug: wait = yes > Tue Apr 15 14:36:10 2008 : Debug: input_pairs = "request" > Tue Apr 15 14:36:10 2008 : Debug: shell_escape = yes > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_expr, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_expr > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating expr > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_expiration, checking > if it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_expiration > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating expiration > Tue Apr 15 14:36:10 2008 : Debug: expiration { > Tue Apr 15 14:36:10 2008 : Debug: reply-message = "Password Has > Expired " > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_logintime, checking > if it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_logintime > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating logintime > Tue Apr 15 14:36:10 2008 : Debug: logintime { > Tue Apr 15 14:36:10 2008 : Debug: reply-message = "You are calling > outside your allowed timespan " > Tue Apr 15 14:36:10 2008 : Debug: minimum-timeout = 60 > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: radiusd: #### Loading Virtual > Servers #### > Tue Apr 15 14:36:10 2008 : Debug: server proxy-inner-tunnel { > Tue Apr 15 14:36:10 2008 : Debug: modules { > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking authenticate {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_eap, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_eap > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap > Tue Apr 15 14:36:10 2008 : Debug: eap { > Tue Apr 15 14:36:10 2008 : Debug: default_eap_type = "ttls" > Tue Apr 15 14:36:10 2008 : Debug: timer_expire = 60 > Tue Apr 15 14:36:10 2008 : Debug: ignore_unknown_eap_types = no > Tue Apr 15 14:36:10 2008 : Debug: cisco_accounting_username_bug = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_md5 > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-md5 > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_leap > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-leap > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_gtc > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-gtc > Tue Apr 15 14:36:10 2008 : Debug: gtc { > Tue Apr 15 14:36:10 2008 : Debug: challenge = "Password: " > Tue Apr 15 14:36:10 2008 : Debug: auth_type = "PAP" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_tls > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-tls > Tue Apr 15 14:36:10 2008 : Debug: tls { > Tue Apr 15 14:36:10 2008 : Debug: rsa_key_exchange = no > Tue Apr 15 14:36:10 2008 : Debug: dh_key_exchange = yes > Tue Apr 15 14:36:10 2008 : Debug: rsa_key_length = 512 > Tue Apr 15 14:36:10 2008 : Debug: dh_key_length = 512 > Tue Apr 15 14:36:10 2008 : Debug: verify_depth = 0 > Tue Apr 15 14:36:10 2008 : Debug: pem_file_type = yes > Tue Apr 15 14:36:10 2008 : Debug: private_key_file = > "/usr/local/freeradius203/etc/raddb/certs/cert-srv.pem" > Tue Apr 15 14:36:10 2008 : Debug: certificate_file = > "/usr/local/freeradius203/etc/raddb/certs/cert-srv.pem" > Tue Apr 15 14:36:10 2008 : Debug: CA_file = > "/usr/local/freeradius203/etc/raddb/certs/root.pem" > Tue Apr 15 14:36:10 2008 : Debug: private_key_password = "XXXXX" > Tue Apr 15 14:36:10 2008 : Debug: dh_file = > "/usr/local/freeradius203/etc/raddb/certs/dh" > Tue Apr 15 14:36:10 2008 : Debug: random_file = > "/usr/local/freeradius203/etc/raddb/certs/random" > Tue Apr 15 14:36:10 2008 : Debug: fragment_size = 1024 > Tue Apr 15 14:36:10 2008 : Debug: include_length = yes > Tue Apr 15 14:36:10 2008 : Debug: check_crl = no > Tue Apr 15 14:36:10 2008 : Debug: cipher_list = "DEFAULT" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_ttls > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-ttls > Tue Apr 15 14:36:10 2008 : Debug: ttls { > Tue Apr 15 14:36:10 2008 : Debug: default_eap_type = "md5" > Tue Apr 15 14:36:10 2008 : Debug: copy_request_to_tunnel = no > Tue Apr 15 14:36:10 2008 : Debug: use_tunneled_reply = no > Tue Apr 15 14:36:10 2008 : Debug: virtual_server = "inner-tunnel" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_peap > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-peap > Tue Apr 15 14:36:10 2008 : Debug: peap { > Tue Apr 15 14:36:10 2008 : Debug: default_eap_type = "mschapv2" > Tue Apr 15 14:36:10 2008 : Debug: copy_request_to_tunnel = no > Tue Apr 15 14:36:10 2008 : Debug: use_tunneled_reply = no > Tue Apr 15 14:36:10 2008 : Debug: proxy_tunneled_request_as_eap = yes > Tue Apr 15 14:36:10 2008 : Debug: virtual_server = "inner-tunnel" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to sub-module > rlm_eap_mschapv2 > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating eap-mschapv2 > Tue Apr 15 14:36:10 2008 : Debug: mschapv2 { > Tue Apr 15 14:36:10 2008 : Debug: with_ntdomain_hack = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking authorize {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking post-proxy {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking post-auth {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: server { > Tue Apr 15 14:36:10 2008 : Debug: modules { > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking authenticate {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_pap, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_pap > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating pap > Tue Apr 15 14:36:10 2008 : Debug: pap { > Tue Apr 15 14:36:10 2008 : Debug: encryption_scheme = "auto" > Tue Apr 15 14:36:10 2008 : Debug: auto_header = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_chap, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_chap > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating chap > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_mschap, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_mschap > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating mschap > Tue Apr 15 14:36:10 2008 : Debug: mschap { > Tue Apr 15 14:36:10 2008 : Debug: use_mppe = yes > Tue Apr 15 14:36:10 2008 : Debug: require_encryption = no > Tue Apr 15 14:36:10 2008 : Debug: require_strong = no > Tue Apr 15 14:36:10 2008 : Debug: with_ntdomain_hack = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_unix, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_unix > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating unix > Tue Apr 15 14:36:10 2008 : Debug: unix { > Tue Apr 15 14:36:10 2008 : Debug: radwtmp = > "/usr/local/freeradius203/var/log/radius/radwtmp" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking authorize {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_preprocess, checking > if it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_preprocess > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating preprocess > Tue Apr 15 14:36:10 2008 : Debug: preprocess { > Tue Apr 15 14:36:10 2008 : Debug: huntgroups = > "/usr/local/freeradius203/etc/raddb/huntgroups" > Tue Apr 15 14:36:10 2008 : Debug: hints = > "/usr/local/freeradius203/etc/raddb/hints" > Tue Apr 15 14:36:10 2008 : Debug: with_ascend_hack = no > Tue Apr 15 14:36:10 2008 : Debug: ascend_channels_per_line = 23 > Tue Apr 15 14:36:10 2008 : Debug: with_ntdomain_hack = no > Tue Apr 15 14:36:10 2008 : Debug: with_specialix_jetstream_hack = no > Tue Apr 15 14:36:10 2008 : Debug: with_cisco_vsa_hack = yes > Tue Apr 15 14:36:10 2008 : Debug: with_alvarion_vsa_hack = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_realm, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_realm > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating suffix > Tue Apr 15 14:36:10 2008 : Debug: realm suffix { > Tue Apr 15 14:36:10 2008 : Debug: format = "suffix" > Tue Apr 15 14:36:10 2008 : Debug: delimiter = "@" > Tue Apr 15 14:36:10 2008 : Debug: ignore_default = no > Tue Apr 15 14:36:10 2008 : Debug: ignore_null = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_files, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_files > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating files > Tue Apr 15 14:36:10 2008 : Debug: files { > Tue Apr 15 14:36:10 2008 : Debug: usersfile = > "/usr/local/freeradius203/etc/raddb/users" > Tue Apr 15 14:36:10 2008 : Debug: acctusersfile = > "/usr/local/freeradius203/etc/raddb/acct_users" > Tue Apr 15 14:36:10 2008 : Debug: preproxy_usersfile = > "/usr/local/freeradius203/etc/raddb/preproxy_users" > Tue Apr 15 14:36:10 2008 : Debug: compat = "no" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_sql, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_sql > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating sql > Tue Apr 15 14:36:10 2008 : Debug: sql { > Tue Apr 15 14:36:10 2008 : Debug: driver = "rlm_sql_mysql" > Tue Apr 15 14:36:10 2008 : Debug: server = "localhost" > Tue Apr 15 14:36:10 2008 : Debug: port = "" > Tue Apr 15 14:36:10 2008 : Debug: login = "radius" > Tue Apr 15 14:36:10 2008 : Debug: password = "XXXXX" > Tue Apr 15 14:36:10 2008 : Debug: radius_db = "radius" > Tue Apr 15 14:36:10 2008 : Debug: read_groups = yes > Tue Apr 15 14:36:10 2008 : Debug: sqltrace = yes > Tue Apr 15 14:36:10 2008 : Debug: sqltracefile = > "/usr/local/freeradius203/var/log/radius/sqltrace.sql" > Tue Apr 15 14:36:10 2008 : Debug: readclients = no > Tue Apr 15 14:36:10 2008 : Debug: deletestalesessions = yes > Tue Apr 15 14:36:10 2008 : Debug: num_sql_socks = 5 > Tue Apr 15 14:36:10 2008 : Debug: sql_user_name = "%{User-Name}" > Tue Apr 15 14:36:10 2008 : Debug: default_user_profile = "" > Tue Apr 15 14:36:10 2008 : Debug: nas_query = "SELECT id, nasname, > shortname, type, secret FROM nas" > Tue Apr 15 14:36:10 2008 : Debug: authorize_check_query = "SELECT > id, username, attribute, value, op FROM radcheck > WHERE username = '%{SQL-User-Name}' ORDER BY id" > Tue Apr 15 14:36:10 2008 : Debug: authorize_reply_query = "SELECT > id, username, attribute, value, op FROM radreply > WHERE username = '%{SQL-User-Name}' ORDER BY id" > Tue Apr 15 14:36:10 2008 : Debug: authorize_group_check_query = > "SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = > '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupName > ORDER BY radgroupcheck.id" > Tue Apr 15 14:36:10 2008 : Debug: authorize_group_reply_query = > "SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = > '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupName > ORDER BY radgroupreply.id" > Tue Apr 15 14:36:10 2008 : Debug: accounting_onoff_query = > " UPDATE radacct SET > acctstoptime = '%S', acctsessiontime = > unix_timestamp('%S') - > unix_timestamp(acctstarttime), acctterminatecause = > '%{Acct-Terminate-Cause}', acctstopdelay = > %{%{Acct-Delay-Time}:-0} WHERE acctsessiontime = > 0 AND acctstoptime = NULL AND > nasipaddress = '%{NAS-IP-Address}' AND > acctstarttime <= '%S'" > Tue Apr 15 14:36:10 2008 : Debug: accounting_update_query = > " UPDATE radacct SET framedipaddress > = '%{Framed-IP-Address}', acctsessiontime = > '%{Acct-Session-Time}', acctinputoctets = > '%{%{Acct-Input-Gigawords}:-0}' << 32 > | > '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = > '%{%{Acct-Output-Gigawords}:-0}' << 32 > | > '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = > '%{Acct-Session-Id}' AND username = > '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" > Tue Apr 15 14:36:10 2008 : Debug: accounting_update_query_alt = > " INSERT INTO radacct (acctsessionid, > acctuniqueid, username, realm, > nasipaddress, nasportid, nasporttype, > acctstarttime, acctsessiontime, acctauthentic, > connectinfo_start, acctinputoctets, acctoutputoctets, > calledstationid, callingstationid, servicetype, > framedprotocol, framedipaddress, acctstartdelay, > xascendsessionsvrkey) VALUES > ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', > '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', > '%{NAS-Port}', '%{NAS-Port-Type}', > DATE_SUB('%S', INTERVAL > (%{%{Acct-Session-Time}:-0} + > %{%{Acct-Delay-Time}:-0}) SECOND), > '%{Acct-Session-Time}', '%{Acct-Authentic}', > '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | > '%{%{Acct-Input-Octets}:-0}', > '%{%{Acct-Output-Gigawords}:-0}' << 32 | > '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', > '%{Calling-Station-Id}', '%{Service-Type}', > '%{Framed-Protocol}', > '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')" > Tue Apr 15 14:36:10 2008 : Debug: accounting_start_query = > " INSERT INTO radacct (acctsessionid, > acctuniqueid, username, realm, > nasipaddress, nasportid, nasporttype, > acctstarttime, acctstoptime, acctsessiontime, > acctauthentic, connectinfo_start, connectinfo_stop, > acctinputoctets, acctoutputoctets, calledstationid, > callingstationid, acctterminatecause, servicetype, > framedprotocol, framedipaddress, acctstartdelay, > acctstopdelay, xascendsessionsvrkey) VALUES > ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', > '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', > '%{NAS-Port}', '%{NAS-Port-Type}', '%S', > NULL, '0', '%{Acct-Authentic}', > '%{Connect-Info}', '', '0', '0', > '%{Called-Station-Id}', '%{Calling-Station-Id}', '', > '%{Service-Type}', '%{Framed-Protocol}', > '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', > '%{X-Ascend-Session-Svr-Key}')" > Tue Apr 15 14:36:10 2008 : Debug: accounting_start_query_alt = > " UPDATE radacct SET acctstarttime = > '%S', acctstartdelay = > '%{%{Acct-Delay-Time}:-0}', connectinfo_start = > '%{Connect-Info}' WHERE acctsessionid = > '%{Acct-Session-Id}' AND username = > '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" > Tue Apr 15 14:36:10 2008 : Debug: accounting_stop_query = > " UPDATE radacct SET acctstoptime = > '%S', acctsessiontime = > '%{Acct-Session-Time}', acctinputoctets = > '%{%{Acct-Input-Gigawords}:-0}' << 32 > | > '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = > '%{%{Acct-Output-Gigawords}:-0}' << 32 > | > '%{%{Acct-Output-Octets}:-0}', acctterminatecause = > '%{Acct-Terminate-Cause}', acctstopdelay = > '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = > '%{Connect-Info}' WHERE acctsessionid = > '%{Acct-Session-Id}' AND username = > '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" > Tue Apr 15 14:36:10 2008 : Debug: accounting_stop_query_alt = > " INSERT INTO radacct (acctsessionid, > acctuniqueid, username, realm, nasipaddress, > nasportid, nasporttype, acctstarttime, > acctstoptime, acctsessiontime, acctauthentic, > connectinfo_start, connectinfo_stop, acctinputoctets, > acctoutputoctets, calledstationid, callingstationid, > acctterminatecause, servicetype, framedprotocol, > framedipaddress, acctstartdelay, acctstopdelay) > VALUES ('%{Acct-Session-Id}', > '%{Acct-Unique-Session-Id}', > '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', > '%{NAS-Port}', '%{NAS-Port-Type}', > DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} > + %{%{Acct-Delay-Time}:-0}) SECOND), > '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', > '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 > | '%{%{Acct-Input-Octets}:-0}', > '%{%{Acct-Output-Gigawords}:-0}' << 32 | > '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', > '%{Calling-Station-Id}', > '%{Acct-Terminate-Cause}', '%{Service-Type}', > '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', > '%{%{Acct-Delay-Time}:-0}')" > Tue Apr 15 14:36:10 2008 : Debug: group_membership_query = "SELECT > groupname FROM usergroup WHERE username = > '%{SQL-User-Name}' ORDER BY priority" > Tue Apr 15 14:36:10 2008 : Debug: connect_failure_retry_delay = 60 > Tue Apr 15 14:36:10 2008 : Debug: simul_count_query = "" > Tue Apr 15 14:36:10 2008 : Debug: simul_verify_query = "SELECT > radacctid, acctsessionid, username, > nasipaddress, nasportid, > framedipaddress, callingstationid, > framedprotocol FROM > radacct WHERE username = > '%{SQL-User-Name}' AND acctstoptime = NULL" > Tue Apr 15 14:36:10 2008 : Debug: postauth_query = "INSERT INTO > radpostauth (username, pass, reply, > authdate) VALUES ( > '%{User-Name}', > '%{%{User-Password}:-%{Chap-Password}}', > '%{reply:Packet-Type}', '%S')" > Tue Apr 15 14:36:10 2008 : Debug: safe-characters = > "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Info: rlm_sql (sql): Driver rlm_sql_mysql > (module rlm_sql_mysql) loaded and linked > Tue Apr 15 14:36:10 2008 : Info: rlm_sql (sql): Attempting to connect > to radius@localhost:/radius > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): starting 0 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Attempting to connect > rlm_sql_mysql #0 > Tue Apr 15 14:36:10 2008 : Info: rlm_sql_mysql: Starting connect to > MySQL server for #0 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Connected new DB > handle, #0 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): starting 1 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Attempting to connect > rlm_sql_mysql #1 > Tue Apr 15 14:36:10 2008 : Info: rlm_sql_mysql: Starting connect to > MySQL server for #1 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Connected new DB > handle, #1 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): starting 2 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Attempting to connect > rlm_sql_mysql #2 > Tue Apr 15 14:36:10 2008 : Info: rlm_sql_mysql: Starting connect to > MySQL server for #2 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Connected new DB > handle, #2 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): starting 3 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Attempting to connect > rlm_sql_mysql #3 > Tue Apr 15 14:36:10 2008 : Info: rlm_sql_mysql: Starting connect to > MySQL server for #3 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Connected new DB > handle, #3 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): starting 4 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Attempting to connect > rlm_sql_mysql #4 > Tue Apr 15 14:36:10 2008 : Info: rlm_sql_mysql: Starting connect to > MySQL server for #4 > Tue Apr 15 14:36:10 2008 : Debug: rlm_sql (sql): Connected new DB > handle, #4 > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking preacct {...} for > more modules to load > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_acct_unique, > checking if it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module > rlm_acct_unique > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating acct_unique > Tue Apr 15 14:36:10 2008 : Debug: acct_unique { > Tue Apr 15 14:36:10 2008 : Debug: key = "User-Name, > Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking accounting {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_detail, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_detail > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating detail > Tue Apr 15 14:36:10 2008 : Debug: detail { > Tue Apr 15 14:36:10 2008 : Debug: detailfile = > "/usr/local/freeradius203/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" > Tue Apr 15 14:36:10 2008 : Debug: header = "%t" > Tue Apr 15 14:36:10 2008 : Debug: detailperm = 384 > Tue Apr 15 14:36:10 2008 : Debug: dirperm = 493 > Tue Apr 15 14:36:10 2008 : Debug: locking = no > Tue Apr 15 14:36:10 2008 : Debug: log_packet_header = no > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_radutmp, checking if > it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module rlm_radutmp > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating radutmp > Tue Apr 15 14:36:10 2008 : Debug: radutmp { > Tue Apr 15 14:36:10 2008 : Debug: filename = > "/usr/local/freeradius203/var/log/radius/radutmp" > Tue Apr 15 14:36:10 2008 : Debug: username = "%{User-Name}" > Tue Apr 15 14:36:10 2008 : Debug: case_sensitive = yes > Tue Apr 15 14:36:10 2008 : Debug: check_with_nas = yes > Tue Apr 15 14:36:10 2008 : Debug: perm = 384 > Tue Apr 15 14:36:10 2008 : Debug: callerid = yes > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: (Loaded rlm_attr_filter, > checking if it's valid) > Tue Apr 15 14:36:10 2008 : Debug: Module: Linked to module > rlm_attr_filter > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating > attr_filter.accounting_response > Tue Apr 15 14:36:10 2008 : Debug: attr_filter > attr_filter.accounting_response { > Tue Apr 15 14:36:10 2008 : Debug: attrsfile = > "/usr/local/freeradius203/etc/raddb/attrs.accounting_response" > Tue Apr 15 14:36:10 2008 : Debug: key = "%{User-Name}" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking session {...} for > more modules to load > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking post-proxy {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: Module: Checking post-auth {...} > for more modules to load > Tue Apr 15 14:36:10 2008 : Debug: Module: Instantiating > attr_filter.access_reject > Tue Apr 15 14:36:10 2008 : Debug: attr_filter > attr_filter.access_reject { > Tue Apr 15 14:36:10 2008 : Debug: attrsfile = > "/usr/local/freeradius203/etc/raddb/attrs.access_reject" > Tue Apr 15 14:36:10 2008 : Debug: key = "%{User-Name}" > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: radiusd: #### Opening IP addresses > and Ports #### > Tue Apr 15 14:36:10 2008 : Debug: listen { > Tue Apr 15 14:36:10 2008 : Debug: type = "auth" > Tue Apr 15 14:36:10 2008 : Debug: ipaddr = * > Tue Apr 15 14:36:10 2008 : Debug: port = 0 > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: listen { > Tue Apr 15 14:36:10 2008 : Debug: type = "acct" > Tue Apr 15 14:36:10 2008 : Debug: ipaddr = * > Tue Apr 15 14:36:10 2008 : Debug: port = 0 > Tue Apr 15 14:36:10 2008 : Debug: } > Tue Apr 15 14:36:10 2008 : Debug: Listening on authentication address > * port 1812 > Tue Apr 15 14:36:10 2008 : Debug: Listening on accounting address * > port 1813 > Tue Apr 15 14:36:10 2008 : Debug: Listening on proxy address * port 1814 > Tue Apr 15 14:36:10 2008 : Debug: Ready to process requests. > User-Name = "000d2885af3e" > User-Password = "000d2885af3e" > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "737" > NAS-Port = 737 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:27 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: rlm_realm: No '@' in User-Name = > "000d2885af3e", looking up realm NULL > Tue Apr 15 14:36:27 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: rlm_eap: No EAP-Message, not doing EAP > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[eap] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling unix > (rlm_unix) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from unix (rlm_unix) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[unix] returns notfound > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling > files (rlm_files) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from files (rlm_files) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[files] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling sql > (rlm_sql) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: expand: %{User-Name} -> 000d2885af3e > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql (sql): sql_set_user escaped > user --> '000d2885af3e' > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql (sql): Reserving sql socket > id: 4 > Tue Apr 15 14:36:27 2008 : Debug: expand: SELECT id, username, > attribute, value, op FROM radcheck WHERE username > = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, > attribute, value, op FROM radcheck WHERE username > = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql_mysql: query: SELECT id, > username, attribute, value, op FROM radcheck WHERE > username = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:27 2008 : Debug: WARNING: Found User-Password == "...". > Tue Apr 15 14:36:27 2008 : Debug: WARNING: Are you sure you don't mean > Cleartext-Password? > Tue Apr 15 14:36:27 2008 : Debug: WARNING: See "man rlm_pap" for more > information. > Tue Apr 15 14:36:27 2008 : Debug: WARNING: Found User-Password == "...". > Tue Apr 15 14:36:27 2008 : Debug: WARNING: Are you sure you don't mean > Cleartext-Password? > Tue Apr 15 14:36:27 2008 : Debug: WARNING: See "man rlm_pap" for more > information. > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql (sql): User found in > radcheck table > Tue Apr 15 14:36:27 2008 : Debug: expand: SELECT id, username, > attribute, value, op FROM radreply WHERE username > = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, > attribute, value, op FROM radreply WHERE username > = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql_mysql: query: SELECT id, > username, attribute, value, op FROM radreply WHERE > username = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:27 2008 : Debug: expand: SELECT > groupname FROM usergroup WHERE username = > '%{SQL-User-Name}' ORDER BY priority -> SELECT > groupname FROM usergroup WHERE username = > '000d2885af3e' ORDER BY priority > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql_mysql: query: SELECT > groupname FROM usergroup WHERE username = > '000d2885af3e' ORDER BY priority > Tue Apr 15 14:36:27 2008 : Debug: expand: SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = > '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupName > ORDER BY radgroupcheck.id -> SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY > radgroupcheck.id > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql_mysql: query: SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY > radgroupcheck.id > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql (sql): User found in group wifi > Tue Apr 15 14:36:27 2008 : Debug: expand: SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = > '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupName > ORDER BY radgroupreply.id -> SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupreply.GroupName ORDER BY > radgroupreply.id > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql_mysql: query: SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupreply.GroupName ORDER BY > radgroupreply.id > Tue Apr 15 14:36:27 2008 : Debug: rlm_sql (sql): Released sql socket id: 4 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from sql (rlm_sql) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[sql] returns ok > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling > expiration (rlm_expiration) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from expiration (rlm_expiration) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[expiration] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling > logintime (rlm_logintime) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from logintime (rlm_logintime) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[logintime] returns noop > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: calling pap > (rlm_pap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authorize]: returned > from pap (rlm_pap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[pap] returns updated > Tue Apr 15 14:36:27 2008 : Debug: rad_check_password: Found Auth-Type > Tue Apr 15 14:36:27 2008 : Debug: > !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! > Tue Apr 15 14:36:27 2008 : Debug: !!! Replacing User-Password in > config items with Cleartext-Password. !!! > Tue Apr 15 14:36:27 2008 : Debug: > !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! > Tue Apr 15 14:36:27 2008 : Debug: !!! Please update your configuration > so that the "known good" !!! > Tue Apr 15 14:36:27 2008 : Debug: !!! clear text password is in > Cleartext-Password, and not in User-Password. !!! > Tue Apr 15 14:36:27 2008 : Debug: > !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! > Tue Apr 15 14:36:27 2008 : Debug: auth: type "PAP" > Tue Apr 15 14:36:27 2008 : Debug: +- entering group PAP > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authenticate]: calling > pap (rlm_pap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: rlm_pap: login attempt with password > "000d2885af3e" > Tue Apr 15 14:36:27 2008 : Debug: rlm_pap: Using clear text password > "000d2885af3e" > Tue Apr 15 14:36:27 2008 : Debug: rlm_pap: User authenticated successfully > Tue Apr 15 14:36:27 2008 : Debug: modsingle[authenticate]: returned > from pap (rlm_pap) for request 0 > Tue Apr 15 14:36:27 2008 : Debug: ++[pap] returns ok > Tue Apr 15 14:36:27 2008 : Auth: Login OK: [000d2885af3e/000d2885af3e] > (from client wlan-sen port 737 cli 000d.2885.af3e) > Tue Apr 15 14:36:27 2008 : Debug: +- entering group post-auth > Tue Apr 15 14:36:27 2008 : Debug: modsingle[post-auth]: calling exec > (rlm_exec) for request 0 > Tue Apr 15 14:36:28 2008 : Debug: Exec-Program output: > Tue Apr 15 14:36:28 2008 : Debug: Exec-Program: returned: 0 > Tue Apr 15 14:36:28 2008 : Debug: modsingle[post-auth]: returned > from exec (rlm_exec) for request 0 > Tue Apr 15 14:36:28 2008 : Debug: ++[exec] returns noop > Tue Apr 15 14:36:28 2008 : Debug: Finished request 0. > Tue Apr 15 14:36:28 2008 : Debug: Going to the next request > Tue Apr 15 14:36:28 2008 : Debug: Waking up in 4.9 seconds. > User-Name = "iti-adsl" > Framed-MTU = 1400 > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > Message-Authenticator = 0x583a69bc84045763a4fe0ebfbfffad63 > EAP-Message = 0x0202000d016974692d6164736c > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "737" > NAS-Port = 737 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No '@' in User-Name = > "iti-adsl", looking up realm NULL > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP packet type response > id 2 length 13 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: No EAP Start, assuming > it's an on-going EAP conversation > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns updated > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling unix > (rlm_unix) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from unix (rlm_unix) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[unix] returns notfound > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > files (rlm_files) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from files (rlm_files) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[files] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling sql > (rlm_sql) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: expand: %{User-Name} -> iti-adsl > Tue Apr 15 14:36:31 2008 : Debug: rlm_sql (sql): sql_set_user escaped > user --> 'iti-adsl' > Tue Apr 15 14:36:31 2008 : Debug: rlm_sql (sql): Reserving sql socket > id: 3 > Tue Apr 15 14:36:31 2008 : Debug: expand: SELECT id, username, > attribute, value, op FROM radcheck WHERE username > = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, > attribute, value, op FROM radcheck WHERE username > = 'iti-adsl' ORDER BY id > Tue Apr 15 14:36:31 2008 : Debug: rlm_sql_mysql: query: SELECT id, > username, attribute, value, op FROM radcheck WHERE > username = 'iti-adsl' ORDER BY id > Tue Apr 15 14:36:31 2008 : Debug: expand: SELECT > groupname FROM usergroup WHERE username = > '%{SQL-User-Name}' ORDER BY priority -> SELECT > groupname FROM usergroup WHERE username = > 'iti-adsl' ORDER BY priority > Tue Apr 15 14:36:31 2008 : Debug: rlm_sql_mysql: query: SELECT > groupname FROM usergroup WHERE username = > 'iti-adsl' ORDER BY priority > Tue Apr 15 14:36:31 2008 : Debug: rlm_sql (sql): Released sql socket id: 3 > Tue Apr 15 14:36:31 2008 : Debug: rlm_sql (sql): User iti-adsl not found > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from sql (rlm_sql) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[sql] returns notfound > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > expiration (rlm_expiration) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from expiration (rlm_expiration) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[expiration] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > logintime (rlm_logintime) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from logintime (rlm_logintime) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[logintime] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling pap > (rlm_pap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: rlm_pap: WARNING! No "known good" > password found for the user. Authentication may fail because of this. > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from pap (rlm_pap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[pap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: rad_check_password: Found > Auth-Type EAP > Tue Apr 15 14:36:31 2008 : Debug: auth: type "EAP" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authenticate > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: calling > eap (rlm_eap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP Identity > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: processing type tls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: Initiate > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: Start returned 1 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: returned > from eap (rlm_eap) for request 1 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns handled > EAP-Message = 0x010300061520 > Message-Authenticator = 0x00000000000000000000000000000000 > State = 0x34f6a43b34f5b18aae78afacd454dce9 > Tue Apr 15 14:36:31 2008 : Debug: Finished request 1. > Tue Apr 15 14:36:31 2008 : Debug: Going to the next request > Tue Apr 15 14:36:31 2008 : Debug: Waking up in 1.7 seconds. > User-Name = "iti-adsl" > Framed-MTU = 1400 > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > Message-Authenticator = 0x2d3e53f084cf58829f768f2749f27a1a > EAP-Message = > 0x0203003c158000000032160301002d010000290301c3a4f793f0ee849b7285f2b7734e75a6199e5ce283b2bb932c130c0d92d0936e000002000a0100 > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "737" > NAS-Port = 737 > State = 0x34f6a43b34f5b18aae78afacd454dce9 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No '@' in User-Name = > "iti-adsl", looking up realm NULL > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP packet type response > id 3 length 60 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Continuing tunnel setup. > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns ok > Tue Apr 15 14:36:31 2008 : Debug: rad_check_password: Found > Auth-Type EAP > Tue Apr 15 14:36:31 2008 : Debug: auth: type "EAP" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authenticate > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: calling > eap (rlm_eap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Request found, released > from the list > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP/ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: processing type ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_ttls: Authenticate > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: processing TLS > Tue Apr 15 14:36:31 2008 : Debug: TLS Length 50 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: Length Included > Tue Apr 15 14:36:31 2008 : Debug: eaptls_verify returned 11 > Tue Apr 15 14:36:31 2008 : Debug: (other): before/accept > initialization > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: before/accept > initialization > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake > [length 002d], ClientHello > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 read client > hello A > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake > [length 004a], ServerHello > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 write server > hello A > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake > [length 05d0], Certificate > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 write > certificate A > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake > [length 0004], ServerHelloDone > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 write server > done A > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 flush data > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: Need to read more > data: SSLv3 read client certificate A > Tue Apr 15 14:36:31 2008 : Debug: In SSL Handshake Phase > Tue Apr 15 14:36:31 2008 : Debug: In SSL Accept mode > Tue Apr 15 14:36:31 2008 : Debug: eaptls_process returned 13 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: returned > from eap (rlm_eap) for request 2 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns handled > EAP-Message = > 0x0104040015c00000062d160301004a0200004603014804a14f03405808f80efd689b16fd48c086f6998ccb91e7ce31c66d6bebc8b62092f827b2e4dfb176a999d0ceff8c436ed65acf3d35e7b1bcdf27f3591336b0d1000a0016030105d00b0005cc0005c90002913082028d308201f6a0030201020209009b4c355fc730b340300d06092a864886f70d0101050500306e310b3009060355040613024245310a3008060355040813012d31173015060355040a130e42656c6769616e2053656e617465310c300a060355040b1303494354310f300d0603550403130653454e42454c311b301906092a864886f70d010901160c65774073656e6174652e > EAP-Message = > 0x6265301e170d3038303430343132303030385a170d3039303430343132303030385a308189310b3009060355040613024245310a3008060355040813012d3111300f060355040713084272757373656c7331173015060355040a130e42656c6769616e2053656e617465310c300a060355040b1303494354311730150603550403130e776966692e73656e6174652e6265311b301906092a864886f70d010901160c65774073656e6174652e626530819f300d06092a864886f70d010101050003818d0030818902818100f468ade3112865f474ffaf100681888d5884c3820307cccddbd320f6cde2ae8d6c0e65d7943ac29a379025237c9a94de1fce > EAP-Message = > 0xef6996f4601060f1e511309ece0c6439a2fe733b287ea222a600d9702a91460fb5e7bc9ec0745654955a8e23bbd43b429fd9ca517edee32c6f959f1afe468020b98dacb27489aea9ee5109bbc18d0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000381810094b832d0e01efc00262169ec6f9fac129c2134822e878b7205359774d793a1ef52e891875bedafe868037724774bb3202b2e606b318f67cd3c19275f96037219aaa469f84be30c121f46c3568863aebf970d4460891a417c09b4a58fe24408058dac50f9260f3a65dec2afedfc3bb17645b8689f16614e7d8fee1150cf13 > EAP-Message = > 0x24280003323082032e30820297a0030201020209009b4c355fc730b33e300d06092a864886f70d0101050500306e310b3009060355040613024245310a3008060355040813012d31173015060355040a130e42656c6769616e2053656e617465310c300a060355040b1303494354310f300d0603550403130653454e42454c311b301906092a864886f70d010901160c65774073656e6174652e6265301e170d3038303430343131353931355a170d3132303430333131353931355a306e310b3009060355040613024245310a3008060355040813012d31173015060355040a130e42656c6769616e2053656e617465310c300a060355040b13034943 > EAP-Message = 0x54310f300d06035504031306 > Message-Authenticator = 0x00000000000000000000000000000000 > State = 0x34f6a43b35f2b18aae78afacd454dce9 > Tue Apr 15 14:36:31 2008 : Debug: Finished request 2. > Tue Apr 15 14:36:31 2008 : Debug: Going to the next request > Tue Apr 15 14:36:31 2008 : Debug: Waking up in 1.7 seconds. > User-Name = "iti-adsl" > Framed-MTU = 1400 > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > Message-Authenticator = 0xc78aa2bce8b1b4622c908f338417907c > EAP-Message = 0x020400061500 > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "737" > NAS-Port = 737 > State = 0x34f6a43b35f2b18aae78afacd454dce9 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No '@' in User-Name = > "iti-adsl", looking up realm NULL > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP packet type response > id 4 length 6 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Continuing tunnel setup. > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns ok > Tue Apr 15 14:36:31 2008 : Debug: rad_check_password: Found > Auth-Type EAP > Tue Apr 15 14:36:31 2008 : Debug: auth: type "EAP" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authenticate > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: calling > eap (rlm_eap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Request found, released > from the list > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP/ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: processing type ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_ttls: Authenticate > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: processing TLS > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK > message > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: ack handshake > fragment handler > Tue Apr 15 14:36:31 2008 : Debug: eaptls_verify returned 1 > Tue Apr 15 14:36:31 2008 : Debug: eaptls_process returned 13 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: returned > from eap (rlm_eap) for request 3 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns handled > EAP-Message = > 0x0105024115800000062d53454e42454c311b301906092a864886f70d010901160c65774073656e6174652e626530819f300d06092a864886f70d010101050003818d0030818902818100bf322c0fe8f317e2de850810f2dcfd2a172d16d4d3ef14a2c49b6bba3ba6d8d13d9b51336b6915d1c28e3e59e48f9d73896b1c66f67c80856d61b2db16706f1f3d91890a796c21137acd951f0763b1052b3955cd8902d230cf25dde50cc9f0d202fcd9834f9f1ba64fd2af92ade9fdcc66d089c8930554ee3da2092878463b330203010001a381d33081d0301d0603551d0e041604143253b8ff54d50cb877865c7818f38eaafbd60fb33081a00603551d2304 > EAP-Message = > 0x819830819580143253b8ff54d50cb877865c7818f38eaafbd60fb3a172a470306e310b3009060355040613024245310a3008060355040813012d31173015060355040a130e42656c6769616e2053656e617465310c300a060355040b1303494354310f300d0603550403130653454e42454c311b301906092a864886f70d010901160c65774073656e6174652e62658209009b4c355fc730b33e300c0603551d13040530030101ff300d06092a864886f70d010105050003818100a5fb290f87afd03e46ffac99dc526494bd08f9cab64018884f55cf7ec81445adf3667aaee0b0332844ed0504846b440cb6a3507dfc767491b99324c3801aec16f74d > EAP-Message = > 0x16e9fad21aae6de23e698ede300a9e917cb83410fd2390b21c3ef3246aeb0cf517bfdce3c658944c66b4c671ce052ed12e051de9b8e50f1693fa1d35c93e16030100040e000000 > Message-Authenticator = 0x00000000000000000000000000000000 > State = 0x34f6a43b36f3b18aae78afacd454dce9 > Tue Apr 15 14:36:31 2008 : Debug: Finished request 3. > Tue Apr 15 14:36:31 2008 : Debug: Going to the next request > Tue Apr 15 14:36:31 2008 : Debug: Waking up in 1.7 seconds. > User-Name = "iti-adsl" > Framed-MTU = 1400 > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > Message-Authenticator = 0xdedcf150fd3e3faa5c45383dcf851109 > EAP-Message = > 0x020500c81580000000be1603010086100000820080a783e9c770fcf3ae5e2510476beeaeb3e6a35f32046a627b0f508bd73ba3555335ed4205bd2a2b7de82f1b872f2dffcccef08341736d1e13a23669dcc2e6919c2f01cb068fbd72ea0eb20879632b10e4c8fa066443ae88ef9f224d998acd6001d84a8735ae27b7d515458215dd6eeba284816c02a18f4e4d30b5a853a4fa435d1403010001011603010028c2ff7430b77a3e79ed73b16ce555f749949bc5ff6bd5e59cc4746db0e8d75821e9b71831d6644977 > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "737" > NAS-Port = 737 > State = 0x34f6a43b36f3b18aae78afacd454dce9 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No '@' in User-Name = > "iti-adsl", looking up realm NULL > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP packet type response > id 5 length 200 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Continuing tunnel setup. > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns ok > Tue Apr 15 14:36:31 2008 : Debug: rad_check_password: Found > Auth-Type EAP > Tue Apr 15 14:36:31 2008 : Debug: auth: type "EAP" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authenticate > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: calling > eap (rlm_eap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Request found, released > from the list > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP/ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: processing type ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_ttls: Authenticate > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: processing TLS > Tue Apr 15 14:36:31 2008 : Debug: TLS Length 190 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: Length Included > Tue Apr 15 14:36:31 2008 : Debug: eaptls_verify returned 11 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake > [length 0086], ClientKeyExchange > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 read client > key exchange A > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 > ChangeCipherSpec [length 0001] > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake > [length 0010], Finished > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 read finished A > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 > ChangeCipherSpec [length 0001] > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 write change > cipher spec A > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake > [length 0010], Finished > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 write finished A > Tue Apr 15 14:36:31 2008 : Debug: TLS_accept: SSLv3 flush data > Tue Apr 15 14:36:31 2008 : Debug: (other): SSL negotiation > finished successfully > Tue Apr 15 14:36:31 2008 : Debug: SSL Connection Established > Tue Apr 15 14:36:31 2008 : Debug: eaptls_process returned 13 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: returned > from eap (rlm_eap) for request 4 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns handled > EAP-Message = > 0x0106003d1580000000331403010001011603010028d3454caad7ea42704da45ef294919c050d0ca2c1132b0c86b4e4a5495a938842ee1fac9833c1c356 > Message-Authenticator = 0x00000000000000000000000000000000 > State = 0x34f6a43b37f0b18aae78afacd454dce9 > Tue Apr 15 14:36:31 2008 : Debug: Finished request 4. > Tue Apr 15 14:36:31 2008 : Debug: Going to the next request > Tue Apr 15 14:36:31 2008 : Debug: Waking up in 1.5 seconds. > User-Name = "iti-adsl" > Framed-MTU = 1400 > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > Message-Authenticator = 0xff5184884f621ac8b13f7ca8d6537687 > EAP-Message = > 0x0206004715800000003d1703010038e4e1c576ac5b647fe37888f18217d1fcefbb6e64bd33f8299a3dd4a688ca0749c876db7581411c2be08cfdddea6835ceed4ec47f9bfb0efc > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "737" > NAS-Port = 737 > State = 0x34f6a43b37f0b18aae78afacd454dce9 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No '@' in User-Name = > "iti-adsl", looking up realm NULL > Tue Apr 15 14:36:31 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP packet type response > id 6 length 71 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Continuing tunnel setup. > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns ok > Tue Apr 15 14:36:31 2008 : Debug: rad_check_password: Found > Auth-Type EAP > Tue Apr 15 14:36:31 2008 : Debug: auth: type "EAP" > Tue Apr 15 14:36:31 2008 : Debug: +- entering group authenticate > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: calling > eap (rlm_eap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Request found, released > from the list > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: EAP/ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: processing type ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_ttls: Authenticate > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: processing TLS > Tue Apr 15 14:36:31 2008 : Debug: TLS Length 61 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_tls: Length Included > Tue Apr 15 14:36:31 2008 : Debug: eaptls_verify returned 11 > Tue Apr 15 14:36:31 2008 : Debug: eaptls_process returned 7 > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap_ttls: Session > established. Proceeding to decode tunneled attributes. > Tue Apr 15 14:36:31 2008 : Debug: auth: No authenticate method > (Auth-Type) configuration found for the request: Rejecting the user > Tue Apr 15 14:36:31 2008 : Debug: auth: Failed to validate the user. > Tue Apr 15 14:36:31 2008 : Auth: Login incorrect: [ew/bloccentre] > (from client wlan-sen port 0) > Tue Apr 15 14:36:31 2008 : Debug: TTLS: Got tunneled Access-Reject > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Handler failed in EAP/ttls > Tue Apr 15 14:36:31 2008 : Debug: rlm_eap: Failed in EAP select > Tue Apr 15 14:36:31 2008 : Debug: modsingle[authenticate]: returned > from eap (rlm_eap) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[eap] returns invalid > Tue Apr 15 14:36:31 2008 : Debug: auth: Failed to validate the user. > Tue Apr 15 14:36:31 2008 : Auth: Login incorrect: [iti-adsl/<via > Auth-Type = EAP>] (from client wlan-sen port 737 cli 000d.2885.af3e) > Tue Apr 15 14:36:31 2008 : Debug: Found Post-Auth-Type Reject > Tue Apr 15 14:36:31 2008 : Debug: +- entering group REJECT > Tue Apr 15 14:36:31 2008 : Debug: modsingle[post-auth]: calling > attr_filter.access_reject (rlm_attr_filter) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: expand: %{User-Name} -> iti-adsl > Tue Apr 15 14:36:31 2008 : Debug: attr_filter: Matched entry DEFAULT > at line 11 > Tue Apr 15 14:36:31 2008 : Debug: modsingle[post-auth]: returned > from attr_filter.access_reject (rlm_attr_filter) for request 5 > Tue Apr 15 14:36:31 2008 : Debug: ++[attr_filter.access_reject] > returns updated > Tue Apr 15 14:36:31 2008 : Debug: Delaying reject of request 5 for 1 > seconds > Tue Apr 15 14:36:31 2008 : Debug: Going to the next request > Tue Apr 15 14:36:31 2008 : Debug: Waking up in 0.9 seconds. > Tue Apr 15 14:36:32 2008 : Debug: Sending delayed reject for request 5 > EAP-Message = 0x04060004 > Message-Authenticator = 0x00000000000000000000000000000000 > Tue Apr 15 14:36:32 2008 : Debug: Waking up in 0.5 seconds. > User-Name = "000d2885af3e" > User-Password = "000d2885af3e" > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "738" > NAS-Port = 738 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:32 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: rlm_realm: No '@' in User-Name = > "000d2885af3e", looking up realm NULL > Tue Apr 15 14:36:32 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: rlm_eap: No EAP-Message, not doing EAP > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[eap] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling unix > (rlm_unix) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from unix (rlm_unix) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[unix] returns notfound > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > files (rlm_files) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from files (rlm_files) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[files] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling sql > (rlm_sql) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: expand: %{User-Name} -> 000d2885af3e > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): sql_set_user escaped > user --> '000d2885af3e' > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): Reserving sql socket > id: 2 > Tue Apr 15 14:36:32 2008 : Debug: expand: SELECT id, username, > attribute, value, op FROM radcheck WHERE username > = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, > attribute, value, op FROM radcheck WHERE username > = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql_mysql: query: SELECT id, > username, attribute, value, op FROM radcheck WHERE > username = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:32 2008 : Debug: WARNING: Found User-Password == "...". > Tue Apr 15 14:36:32 2008 : Debug: WARNING: Are you sure you don't mean > Cleartext-Password? > Tue Apr 15 14:36:32 2008 : Debug: WARNING: See "man rlm_pap" for more > information. > Tue Apr 15 14:36:32 2008 : Debug: WARNING: Found User-Password == "...". > Tue Apr 15 14:36:32 2008 : Debug: WARNING: Are you sure you don't mean > Cleartext-Password? > Tue Apr 15 14:36:32 2008 : Debug: WARNING: See "man rlm_pap" for more > information. > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): User found in > radcheck table > Tue Apr 15 14:36:32 2008 : Debug: expand: SELECT id, username, > attribute, value, op FROM radreply WHERE username > = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, > attribute, value, op FROM radreply WHERE username > = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql_mysql: query: SELECT id, > username, attribute, value, op FROM radreply WHERE > username = '000d2885af3e' ORDER BY id > Tue Apr 15 14:36:32 2008 : Debug: expand: SELECT > groupname FROM usergroup WHERE username = > '%{SQL-User-Name}' ORDER BY priority -> SELECT > groupname FROM usergroup WHERE username = > '000d2885af3e' ORDER BY priority > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql_mysql: query: SELECT > groupname FROM usergroup WHERE username = > '000d2885af3e' ORDER BY priority > Tue Apr 15 14:36:32 2008 : Debug: expand: SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = > '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupName > ORDER BY radgroupcheck.id -> SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY > radgroupcheck.id > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql_mysql: query: SELECT > radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op > FROM radgroupcheck,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY > radgroupcheck.id > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): User found in group wifi > Tue Apr 15 14:36:32 2008 : Debug: expand: SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = > '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupName > ORDER BY radgroupreply.id -> SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupreply.GroupName ORDER BY > radgroupreply.id > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql_mysql: query: SELECT > radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op > FROM radgroupreply,usergroup WHERE usergroup.Username = '000d2885af3e' > AND usergroup.GroupName = radgroupreply.GroupName ORDER BY > radgroupreply.id > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): Released sql socket id: 2 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from sql (rlm_sql) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[sql] returns ok > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > expiration (rlm_expiration) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from expiration (rlm_expiration) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[expiration] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > logintime (rlm_logintime) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from logintime (rlm_logintime) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[logintime] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling pap > (rlm_pap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from pap (rlm_pap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[pap] returns updated > Tue Apr 15 14:36:32 2008 : Debug: rad_check_password: Found Auth-Type > Tue Apr 15 14:36:32 2008 : Debug: > !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! > Tue Apr 15 14:36:32 2008 : Debug: !!! Replacing User-Password in > config items with Cleartext-Password. !!! > Tue Apr 15 14:36:32 2008 : Debug: > !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! > Tue Apr 15 14:36:32 2008 : Debug: !!! Please update your configuration > so that the "known good" !!! > Tue Apr 15 14:36:32 2008 : Debug: !!! clear text password is in > Cleartext-Password, and not in User-Password. !!! > Tue Apr 15 14:36:32 2008 : Debug: > !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! > Tue Apr 15 14:36:32 2008 : Debug: auth: type "PAP" > Tue Apr 15 14:36:32 2008 : Debug: +- entering group PAP > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authenticate]: calling > pap (rlm_pap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: rlm_pap: login attempt with password > "000d2885af3e" > Tue Apr 15 14:36:32 2008 : Debug: rlm_pap: Using clear text password > "000d2885af3e" > Tue Apr 15 14:36:32 2008 : Debug: rlm_pap: User authenticated successfully > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authenticate]: returned > from pap (rlm_pap) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[pap] returns ok > Tue Apr 15 14:36:32 2008 : Auth: Login OK: [000d2885af3e/000d2885af3e] > (from client wlan-sen port 738 cli 000d.2885.af3e) > Tue Apr 15 14:36:32 2008 : Debug: +- entering group post-auth > Tue Apr 15 14:36:32 2008 : Debug: modsingle[post-auth]: calling exec > (rlm_exec) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: Exec-Program output: > Tue Apr 15 14:36:32 2008 : Debug: Exec-Program: returned: 0 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[post-auth]: returned > from exec (rlm_exec) for request 6 > Tue Apr 15 14:36:32 2008 : Debug: ++[exec] returns noop > Tue Apr 15 14:36:32 2008 : Debug: Finished request 6. > Tue Apr 15 14:36:32 2008 : Debug: Going to the next request > Tue Apr 15 14:36:32 2008 : Debug: Waking up in 0.2 seconds. > User-Name = "iti-adsl" > Framed-MTU = 1400 > Called-Station-Id = "001e.4a06.0650" > Calling-Station-Id = "000d.2885.af3e" > Cisco-AVPair = "ssid=adsl" > Service-Type = Login-User > Message-Authenticator = 0x35a1a659fe02b2e62f8cbd3e242992d2 > EAP-Message = 0x0201000d016974692d6164736c > NAS-Port-Type = Wireless-802.11 > Cisco-NAS-Port = "738" > NAS-Port = 738 > NAS-IP-Address = 192.168.1.110 > NAS-Identifier = "wlan_sen_10" > Tue Apr 15 14:36:32 2008 : Debug: +- entering group authorize > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > preprocess (rlm_preprocess) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from preprocess (rlm_preprocess) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[preprocess] returns ok > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling chap > (rlm_chap) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from chap (rlm_chap) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[chap] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > mschap (rlm_mschap) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from mschap (rlm_mschap) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[mschap] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > suffix (rlm_realm) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: rlm_realm: No '@' in User-Name = > "iti-adsl", looking up realm NULL > Tue Apr 15 14:36:32 2008 : Debug: rlm_realm: No such realm "NULL" > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from suffix (rlm_realm) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[suffix] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling eap > (rlm_eap) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: rlm_eap: EAP packet type response > id 1 length 13 > Tue Apr 15 14:36:32 2008 : Debug: rlm_eap: No EAP Start, assuming > it's an on-going EAP conversation > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from eap (rlm_eap) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[eap] returns updated > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling unix > (rlm_unix) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from unix (rlm_unix) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[unix] returns notfound > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling > files (rlm_files) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: returned > from files (rlm_files) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: ++[files] returns noop > Tue Apr 15 14:36:32 2008 : Debug: modsingle[authorize]: calling sql > (rlm_sql) for request 7 > Tue Apr 15 14:36:32 2008 : Debug: expand: %{User-Name} -> iti-adsl > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): sql_set_user escaped > user --> 'iti-adsl' > Tue Apr 15 14:36:32 2008 : Debug: rlm_sql (sql): Reserving sql socket > id: 1

2 1