- Freeradius-Users - lists.freeradius.org

more info in the log file
by Mike May 19 Oct '06

19 Oct '06

Hello everyone, I need some help on logging, I want to grab some more info out of the radius logs, I currently use the log options in radiusd.conf file, but wanted to get some time stamps. I am using radius and LDAP, and would like to be able to see when the radius server perfomed the search on the directory and when the response came back to the radius servers from the directory servers, in essence some time stamps on how long it was waiting for the downstream systems to respond. I am not sure if that is even in the packet, but thought I would ask Hope it does not sound to far out there. thanks

2 1

rlm_sqlippool load failure
by Francisco Gimeno 19 Oct '06

19 Oct '06

Hello! This is my first post in the list, so please excuse any eventual problem I could cause. I'm running a FreeRadius 1.1.3 server with the Debian patches and a little patch I made to correct the NAS-Port known behaviour for fixed NAS-Port. I would like to test the rlm_sqlippool module, but I can't get it work. I finally got it compiled using this settings: ----------------------- package = freeradius debiandir = $(shell pwd)/debian freeradius_dir = $(debiandir)/$(package) mandir = /usr/share/man libdir = /usr/lib/$(package) logdir = /var/log/$(package) pkgdocdir = /usr/share/doc/$(package) raddbdir = /etc/$(package) confflags += --build $(DEB_HOST_GNU_TYPE) buildssl=--with-rlm_sql_postgresql_lib_dir=`pg_config --libdir` --with-rlm_sql_postgresql_include_dir=`pg_config --includedir` ./configure \ $(confflags) \ --prefix=/usr \ --exec-prefix=/usr \ --mandir=$(mandir) \ --sysconfdir=/etc \ --libdir=$(libdir) \ --datadir=/usr/share \ --localstatedir=/var \ --with-raddbdir=$(raddbdir) \ --with-logdir=/var/log/$(package) \ --enable-ltdl-install=no --enable-strict-dependencies \ --with-large-files --with-udpfromto --with-edir \ --enable-developer \ ${buildssl} \ --with-system-libtool \ --with-experimental-modules \ --without-rlm_python ------------- In my config, I'm using the proposed sqlippool.conf provided in the examples directory. $INCLUDE ${confdir}/sqlippool.conf in the module section. I do the Auth with LDAP, and I have enabled in accounting and post-auth sections the sqlippool module. As I don't see the way to configure the sql settings, I finally added the postgresql.conf provided file with my customized settings (db, dbuser, dbpasword, dbhost, and so... ). I wouldn't like to enable it, but I don't find any other way to "configure" those settings. When executing freeradius -X I can see the following: -------------- Module: Loaded SQL IP Pool sqlippool: sql-instance-name = "sql" sqlippool: lease-duration = 3600 sqlippool: pool-name = "" sqlippool: allocate-begin = "BEGIN" sqlippool: allocate-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE pool_key = '%{Calling-Station-Id}'" sqlippool: allocate-find = "SELECT framedipaddress FROM radippool WHERE pool_name = '%{reply:Pool-Name}' AND expiry_time < 'now'::timestamp(0) ORDER BY pool_name, (username <> '%{User-Name}'), (callingstationid <> '%{Calling-Station-Id}'), expiry_time LIMIT 1 FOR UPDATE" sqlippool: allocate-update = "UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = 'now'::timestamp(0) + '3600 second'::interval WHERE framedipaddress = '%I'" sqlippool: allocate-commit = "COMMIT" sqlippool: allocate-rollback = "ROLLBACK" sqlippool: start-begin = "BEGIN" sqlippool: start-update = "UPDATE radippool SET expiry_time = 'now'::timestamp(0) + '%J second'::interval WHERE nasipaddress = '%n' AND nas_port = '%p' AND pool_name = '%P'" sqlippool: start-commit = "COMMIT" sqlippool: start-rollback = "ROLLBACK" sqlippool: alive-begin = "BEGIN" sqlippool: alive-update = "UPDATE radippool SET expiry_time = 'now'::timestamp(0) + '3600 seconds'::interval WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key = '%{Calling-Station-Id}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" sqlippool: alive-commit = "COMMIT" sqlippool: alive-rollback = "ROLLBACK" sqlippool: stop-begin = "BEGIN" sqlippool: stop-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key = '%{Calling-Station-Id}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" sqlippool: stop-commit = "COMMIT" sqlippool: stop-rollback = "ROLLBACK" sqlippool: on-begin = "BEGIN" sqlippool: on-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '%{Nas-IP-Address}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" sqlippool: on-commit = "COMMIT" sqlippool: on-rollback = "ROLLBACK" sqlippool: off-begin = "BEGIN" sqlippool: off-clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '%{Nas-IP-Address}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" sqlippool: off-commit = "COMMIT" sqlippool: off-rollback = "ROLLBACK" Module: Loaded SQL sql: driver = "rlm_sql_postgresql" sql: server = "MY_POSTGRESQL_SERVER_IP" sql: port = "" sql: login = "MY_POSTGRESQL_USER" sql: password = "MY_POSTGRESQL_PASSWORD" sql: radius_db = "MY_POSTGRESQL_DB" sql: nas_table = "nas" sql: sqltrace = yes sql: sqltracefile = "/var/log/freeradius/sqltrace.sql" sql: readclients = no sql: deletestalesessions = yes sql: num_sql_socks = 5 sql: sql_user_name = "%{User-Name}" sql: default_user_profile = "" sql: query_on_not_found = no . . . sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'" sql: connect_failure_retry_delay = 60 sql: simul_count_query = "" sql: simul_verify_query = "" sql: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked rlm_sql (sql): Attempting to connect to radiusdbuser@10.160.2.74:/radiusdb rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #4 rlm_sql (sql): Connected new DB handle, #4 Module: Instantiated sql (sql) freeradius: relocation error: /usr/lib/freeradius/rlm_sqlippool-1.1.3.so: undefined symbol: sql_get_socket ---------------- The strange thing is that the sql module seems initialized, but sqlippool doesn't load. I looked the sql_get_socket function over the code, and I found it in the sql.c file in the rlm_sql module. Furthermore, I see that function being compiled and linked in the rlm_sql.so file as it's shown here: --------- [08:11:33] fgd@myBox:/home/fgd/src/freeradius-1.1.3/src/modules/rlm_sql/.libs# nm rlm_sql.so | grep sql_get_socket 000047f0 T sql_get_socket --------- I don't know how to force it to be loaded... any hint? Thanks you! Francisco Gimeno

3 3

User collision/duplicate users and mysql backend
by Collen Blijenberg 19 Oct '06

19 Oct '06

I was wondering, any change of getting the User collision/duplicate users option in to the sql module (pref. mysql) ?? I'm still trying to get the mysql backend to work, with duplicate usernames. (still stuck here) in the tuning guide, i found a document called 'tuning guide' under the sql module section, it says something about 'multi column index' and 'sql for double login detection' ? but what is mend with this ?? the problem is that i have (a few) users with 1 username and multiple computers. we filter on username and calling-station-id (MAC). but somehow the mysql backend can't handle this (tell me if I'm wrong!!) any solution is welcome... Cheers Collen

2 2

More CVS madness: Radiusd not actually doing anything
by Jan Mulders 19 Oct '06

19 Oct '06

Hello, More CVS madness for you all. I'm trying to run radiusd on my server, replacing an existing, working configuration. When I run radiusd (specifying paths or using defaults, it doesn't matter), I get the following: root@betabitch [/etc/raddb]# radiusd -xx Starting - reading configuration files ... Ready to process requests. [ then I press ctrl-c, as the server isn't doing anything ] CHILD: exit on signal (2) MASTER: accounting process died - exit. root@betabitch [/etc/raddb]# It does this regardless of the presence of a radiusd.conf file in the /etc/raddb folder. What the hell is going on? Thanks, Jan

2 1

Combining LDAP authentication and UNIX groups
by Paul Stepowski 19 Oct '06

19 Oct '06

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hi list, Is it possible to authenticate users against LDAP and also check if the username exists in a local UNIX group. I can get both working independently i.e. in my users file - ---snip--- DEFAULT Auth-Type = LDAP Fall-Through = No DEFAULT Group == "paul", Auth-Type = System Fall-Through = No - ---snip--- I can auth users against LDAP successfully and I can auth users who are in the group "paul" successfully against the password file. I tried to combine these two in various way, e.g. - ---snip--- DEFAULT Group == "paul", Auth-Type = LDAP, Fall-Through = No - ---snip--- But I couldn't get this to work, probably because LDAP has no concept of a "Group". It might be possible to do this using two different definitions in "users" that where one falls through to another but I'm not sure how to implement this. Does anyone know if this is achievable? NOTE: Please don't ask why I'm trying to do this. I realise this is a slightly unusual concept, but I'd thought I'd ask. Thanks, Paul -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.2 (GNU/Linux) Comment: Using GnuPG with SUSE - http://enigmail.mozdev.org iD8DBQFFNd9+4qOLghPAuV0RAh6fAKCe8yPC49Ri6wXHAOXPGrbB2X+GWwCgt8hQ YWX30HRRls054OfH2LNHpv4= =p7Ww -----END PGP SIGNATURE-----

3 4

PEAP-MSCHAP failure. Please help
by Jack Daniels 19 Oct '06

19 Oct '06

Hi there, I'm trying to do authentication using the winlogon information and using PEAP. I'm not using client certificates, only windows domain logon information. Here are my config files: eap.conf eap { default_eap_type = peap timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no tls { private_key_password = password private_key_file = ${raddbdir}/certs/radiuskey.pem certificate_file = ${raddbdir}/certs/radiuscert.pem CA_file = ${raddbdir}/certs/cacert.pem dh_file = ${raddbdir}/certs/dh random_file = /dev/urandom fragment_size = 1024 include_length = yes } peap { default_eap_type = mschapv2 copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes } mschapv2 { } } radiusd.conf ... modules { $INCLUDE ${confdir}/eap.conf mschap { authtype = MS-CHAP use_mppe = yes require_encryption = yes require_strong = yes with_ntdomain_hack = yes ntlm_auth = "/opt/samba/bin/ntlm_auth --request-nt-key --domain=%{mschap:NT-Domain} --username=%{mschap:User-Name} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}" } } authorize { eap } authenticate { Auth-Type MS-CHAP { mschap } eap } This is my dump of radiusd -X -A Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /usr/local/etc/raddb/clients.conf Config: including file: /usr/local/etc/raddb/snmp.conf Config: including file: /usr/local/etc/raddb/eap.conf Config: including file: /usr/local/etc/raddb/sql.conf main: prefix = "/usr/local" main: localstatedir = "/usr/local/var" main: logdir = "/usr/local/var/log/radius" main: libdir = "/usr/local/lib" main: radacctdir = "/usr/local/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 = "/usr/local/var/log/radius/radius.log" main: log_auth = no main: log_auth_badpass = no main: log_auth_goodpass = no main: pidfile = "/usr/local/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/local/sbin/checkrad" main: proxy_requests = 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 Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Module: Library search path is /usr/local/lib Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = yes mschap: require_strong = yes mschap: with_ntdomain_hack = yes mschap: passwd = "(null)" mschap: ntlm_auth = "/opt/samba/bin/ntlm_auth --request-nt-key --domain=%{mschap:NT-Domain} --username=%{mschap:User-Name} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}" Module: Instantiated mschap (mschap) Module: Loaded eap eap: default_eap_type = "peap" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no eap: cisco_accounting_username_bug = no 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 = "/usr/local/etc/raddb/certs/radiuskey.pem" tls: certificate_file = "/usr/local/etc/raddb/certs/radiuscert.pem" tls: CA_file = "/usr/local/etc/raddb/certs/cacert.pem" tls: private_key_password = "password" tls: dh_file = "/usr/local/etc/raddb/certs/dh" tls: random_file = "/dev/urandom" tls: fragment_size = 1024 tls: include_length = yes tls: check_crl = yes tls: check_cert_cn = "(null)" tls: cipher_list = "(null)" tls: check_cert_issuer = "(null)" rlm_eap_tls: Loading the certificate file as a chain rlm_eap: Loaded and initialized type tls peap: default_eap_type = "mschapv2" peap: copy_request_to_tunnel = no peap: use_tunneled_reply = no peap: proxy_tunneled_request_as_eap = yes rlm_eap: Loaded and initialized type peap mschapv2: with_ntdomain_hack = no rlm_eap: Loaded and initialized type mschapv2 Module: Instantiated eap (eap) Listening on authentication *:1812 Listening on accounting *:1813 Ready to process requests. rad_recv: Access-Request packet from host 192.168.254.26:1812, id=22, length=165 NAS-IP-Address = 192.168.254.26 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "ASDF\\asdf" Called-Station-Id = "00-16-46-DB-93-01" Calling-Station-Id = "00-B0-D0-0C-64-B2" Service-Type = Framed-User Framed-MTU = 1500 EAP-Message = 0x0200002e01415344465c617364660000ff1c53796761746553656375726974794167656e74000000000000000000 Message-Authenticator = 0x38739029b21f29f09cf2d207b03c3a35 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 rlm_eap: EAP packet type response id 0 length 46 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 0 modcall: leaving group authorize (returns updated) for request 0 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0 rlm_eap: EAP Identity rlm_eap: processing type tls rlm_eap_tls: Initiate rlm_eap_tls: Start returned 1 modcall[authenticate]: module "eap" returns handled for request 0 modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 22 to 192.168.254.26 port 1812 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xe6aee8ce917ba33b4e9bcb87dc8aa9b0 Finished request 0 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.254.26:1812, id=23, length=217 NAS-IP-Address = 192.168.254.26 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "ASDF\\asdf" Called-Station-Id = "00-16-46-DB-93-01" Calling-Station-Id = "00-B0-D0-0C-64-B2" Service-Type = Framed-User Framed-MTU = 1500 State = 0xe6aee8ce917ba33b4e9bcb87dc8aa9b0 EAP-Message = 0x0201005019800000004616030100410100003d030145362a3286a98f942b778d74dd470fc449c041d01f0e82822ba3babcf0c7752c00001600040005000a000900640062000300060013001200630100 Message-Authenticator = 0xd0802a126d8f4c4576362704b2b1f3f1 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 rlm_eap: EAP packet type response id 1 length 80 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 1 modcall: leaving group authorize (returns updated) for request 1 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 1 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS rlm_eap_tls: Length Included eaptls_verify returned 11 (other): before/accept initialization TLS_accept: before/accept initialization rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello TLS_accept: SSLv3 read client hello A rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello TLS_accept: SSLv3 write server hello A rlm_eap_tls: >>> TLS 1.0 Handshake [length 062f], Certificate TLS_accept: SSLv3 write certificate A rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone TLS_accept: SSLv3 write server done A TLS_accept: SSLv3 flush data TLS_accept:error in SSLv3 read client certificate A rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) In SSL Handshake Phase In SSL Accept mode eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED modcall[authenticate]: module "eap" returns handled for request 1 modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 23 to 192.168.254.26 port 1812 EAP-Message = 0x0102040a19c00000068c160301004a02000046030145359d132089dfb5b31e89f6df538953346dfb57cb62b10111a9d86165b0459e20ab268afefcbeca633a9567f6bfd548d8b53e0ab1e2952afbb4af996b5ef085a8000400160301062f0b00062b00062800029d3082029930820202a003020102020101300d06092a864886f70d0101040500308188310b3009060355040613024348310d300b060355040813044265726e31163014060355040a130d536166656775617264204c6162312530230603550403131c526f6f742043657274696669636174696f6e20417574686f72697479312b302906092a864886f70d010901161c61646d696e6973 EAP-Message = 0x747261746f72407361666567756172642e74657374301e170d3036313031383032303332375a170d3037313031383032303332375a308182310b3009060355040613024348310d300b060355040813044265726e31163014060355040a130d536166656775617264204c6162311f301d0603550403131646726565526164697573205465737420536572766572312b302906092a864886f70d010901161c61646d696e6973747261746f72407361666567756172642e7465737430819f300d06092a864886f70d010101050003818d0030818902818100cecd0979f9596669055dc8ed59537dbd99cf07497d4eb982c7b68bb66c8bee8ef043f7f8364e EAP-Message = 0x45a79a16882ec31e6b7edde6e2366b9034781f9757dfe594b3eefd84bfe4bf970425a1eb33c777b429c1789c3ef12fd95ddf5fa8454be474efb29dfa25949e22529b1a196cfb8d9f4510824f6f84e351d1e97239facd5a01294f0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181004861289d07bb71f05ec9a11d716299b22f4db328b7e32d55e13e939b4961cc95429a26a793993b1f71cf0525715b9c5ce68554569deb6dad23f2e673035a5d45ce1a5037012e690b2b6c08b4dec0e6a25a7b2b00b0ed4c543bdb1b767365ea70e2b81db574604da6762608a0be9a1c757bf1 EAP-Message = 0x071a2370c3c8652c2900bc06fa9d00038530820381308202eaa003020102020900e24fc4fd6ffcf7c1300d06092a864886f70d0101040500308188310b3009060355040613024348310d300b060355040813044265726e31163014060355040a130d536166656775617264204c6162312530230603550403131c526f6f742043657274696669636174696f6e20417574686f72697479312b302906092a864886f70d010901161c61646d696e6973747261746f72407361666567756172642e74657374301e170d3036313031383032303330375a170d3037313031383032303330375a308188310b3009060355040613024348310d300b060355040813 EAP-Message = 0x044265726e31163014060355040a130d536166656775 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd9e611882c9206e57aa4934cc6c47079 Finished request 1 Going to the next request Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.254.26:1812, id=24, length=143 NAS-IP-Address = 192.168.254.26 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "ASDF\\asdf" Called-Station-Id = "00-16-46-DB-93-01" Calling-Station-Id = "00-B0-D0-0C-64-B2" Service-Type = Framed-User Framed-MTU = 1500 State = 0xd9e611882c9206e57aa4934cc6c47079 EAP-Message = 0x020200061900 Message-Authenticator = 0xb85b165671cc8a30681a688baf2a2136 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 2 rlm_eap: EAP packet type response id 2 length 6 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 2 modcall: leaving group authorize (returns updated) for request 2 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 2 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS rlm_eap_tls: Received EAP-TLS ACK message rlm_eap_tls: ack handshake fragment handler eaptls_verify returned 1 eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED modcall[authenticate]: module "eap" returns handled for request 2 modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 24 to 192.168.254.26 port 1812 EAP-Message = 0x010302921900617264204c6162312530230603550403131c526f6f742043657274696669636174696f6e20417574686f72697479312b302906092a864886f70d010901161c61646d696e6973747261746f72407361666567756172642e7465737430819f300d06092a864886f70d010101050003818d0030818902818100ce868e0ed1ea38ca7578de3aea67f43f6e259e5a3bd1e10c47c4fb588756d5eeb4e3e5a3e346488032f5724849ccdc06281b498b552eb723e84d334771be0b8c6c933a1af86ee8b1ae731eb192c5f25e916df6e22e03fc4e7b18570e894db4f429a99c43082654a5357b7fba485de171faf3567a100118b5327edff6478d0b EAP-Message = 0xd10203010001a381f03081ed301d0603551d0e0416041448296c477e81278cec7a3d90922e0f427f8968c93081bd0603551d230481b53081b2801448296c477e81278cec7a3d90922e0f427f8968c9a1818ea4818b308188310b3009060355040613024348310d300b060355040813044265726e31163014060355040a130d536166656775617264204c6162312530230603550403131c526f6f742043657274696669636174696f6e20417574686f72697479312b302906092a864886f70d010901161c61646d696e6973747261746f72407361666567756172642e74657374820900e24fc4fd6ffcf7c1300c0603551d13040530030101ff300d0609 EAP-Message = 0x2a864886f70d010104050003818100b6a2bf764bb01820c8650f0bcd7ad1797ce2711f82de2df777607aad7c9cd0f58396dfe1bf6974b9aaf368757de41b49fc4538ed0598aeec5ed8555ce7c44f658fd6ecaa1fabbc2060da8536aa136f86835b8a6731e41c78b0023b572aed7175b94cd93badab450b174067e22c58a4f434d0fd592ec1215a04e184ca612d2c9516030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2e288099d22c097d5f415cca50070a5d Finished request 2 Going to the next request Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.254.26:1812, id=25, length=329 NAS-IP-Address = 192.168.254.26 NAS-Port = 50001 NAS-Port-Type = Ethernet User-Name = "ASDF\\asdf" Called-Station-Id = "00-16-46-DB-93-01" Calling-Station-Id = "00-B0-D0-0C-64-B2" Service-Type = Framed-User Framed-MTU = 1500 State = 0x2e288099d22c097d5f415cca50070a5d EAP-Message = 0x020300c01980000000b61603010086100000820080883d13d43d2ce12fc3364a5eb33fb861636d18a200a9a0e84d10261e9c86f2350db58c1feba581442c51bee27f89d4d0255ec8509ac3910acf099b23dac128862ee02f0de774f283ae00ed5575c142dde2514d50be4004286b19f35e5c3ed602ffa270cbb94ff2780f81af5834169f9e6573dff346f45bd1c799c3b44f9240cf140301000101160301002070a4cb2e7adb74767794227e6f18c65164cc2e25355bf08505b016f9ed0a1670 Message-Authenticator = 0x65115a527c866e9357aaa8d3844a00ea Processing the authorize section of radiusd.conf modcall: entering group authorize for request 3 rlm_eap: EAP packet type response id 3 length 192 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 3 modcall: leaving group authorize (returns updated) for request 3 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 3 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS rlm_eap_tls: Length Included eaptls_verify returned 11 rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange TLS_accept: SSLv3 read client key exchange A rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001] rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished TLS_accept: SSLv3 read finished A rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001] TLS_accept: SSLv3 write change cipher spec A rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished TLS_accept: SSLv3 write finished A TLS_accept: SSLv3 flush data (other): SSL negotiation finished successfully rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) SSL Connection Established eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED modcall[authenticate]: module "eap" returns handled for request 3 modcall: leaving group authenticate (returns handled) for request 3 Sending Access-Challenge of id 25 to 192.168.254.26 port 1812 EAP-Message = 0x0104003119001403010001011603010020d0f9a0ba049067d8e4d5c36c88eeaf39cb69d081fcee756c084180b6ac53294f Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed95e59feca1d7ef0ab7eed96cec81c1 Finished request 3 Going to the next request Waking up in 6 seconds... --- Walking the entire request list --- Cleaning up request 0 ID 22 with timestamp 45359d13 Cleaning up request 1 ID 23 with timestamp 45359d13 Cleaning up request 2 ID 24 with timestamp 45359d13 Cleaning up request 3 ID 25 with timestamp 45359d13 Nothing to do. Sleeping until we see a request. The CA certificate has been imported to the connecting computer and this computer is configured with the option "Validate server certificate" with the appropiate certification authority selected. When I connect, nothing happens, it doesn't connect but it doesnt complain either, but the switch's port keeps blocked. From the dump, you can see that there is no failure in the EAP module, but it doesn't go to the mschap authentication part. Questions: Is there a way to dump more information about what is going on in the TLS conversation in freeradius? Why even if EAP doesn't fail it can't reach the mschap part? Should I consider this part (other): SSL negotiation finished successfully rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) SSL Connection Established as a failure or a success? In the client computer, if I uncheck the "Validate server certificate" option everything runs smoothly. I'm using FreeRadius v 1.1.3. Certificates when created were verified with openssl verify and everything was ok. Thanks. Please advice _________________________________________________________________ FREE pop-up blocking with the new MSN Toolbar - get it now! http://toolbar.msn.click-url.com/go/onm00200415ave/direct/01/

4 4

CVS: radtest strangeness
by Jan Mulders 19 Oct '06

19 Oct '06

Okay, I knew the CVS was weird, but this really takes the cake: root@betabitch [~]# radtest testuser1 testing localhost 5 SuperSecretPassword Unknown attribute "Password" radclient: cannot parse Password = "testing" What on earth? Usage: radtest user passwd radius-server nas-port-id secret [ppphint] [nasname] Have I really missed something obvious? Hopefully someone can clear this up real quick for me. Thanks, Jan

2 3

SSL_read failed in a system call
by King, Michael 18 Oct '06

18 Oct '06

I posted this to the list back in September, but was unable to chase it then. http://www.mail-archive.com/freeradius-users@lists.freeradius.org/msg294 52.html But it has returned with a vengeance. It only seems to affect the 1.1.3 server. I have not tried any other versions, other than the 1.0.4 I've listed below, which seems to work fine I think it's load related, since when I test with a few clients, it worked fine. When I dumped 1000 of clients, with over 50 auths/sec, things went horrible wrong. I found this on the net with the same error string: http://www.mail-archive.com/modssl-users@modssl.org/msg16180.html > There is definately something wrong in openssl 0.9.7a, or, mod_ssl 2.8.14 is trying > to call 0.9.6 functions which are different/don't exist in 0.9.7 And I found this: http://lists.alioth.debian.org/pipermail/pkg-openssl-devel/2005-November /000418.html Which has a link to: http://www.aet.tu-cottbus.de/rt2/Ticket/Display.html?id=1204 (OpenSSL's BugTracker?) >Use of SSL_OP_TLS_BLOCK_PADDING_BUG, which is included in SSL_OP_ALL, >triggers a bug in OpenSSL if both the client and server is using version 0.9.8. Unfortunately, I'm using 0.9.7 Here's my status I've built a new radius server. FreeRADIUS 1.1.3 Windbind using ntlm_auth to talk to ActiveDirectory. Mostly XP clients using the Built-in XP supplicant. (PEAP) Running on RedHat RHEL 4 Server has a trusted root Cert from Equifax. (I do NOT have a self-signed Cert) Server name is brand new, it has never been used in my network before OpenSSL is openssl-0.9.7a-43.11 via Up2date I got it all setup and operating correctly (based on my 1.0.4 config that's been in production for 1.5 years). Tested it with a few clients, everything looks fine. I put some major traffic on it, and everything goes downhill. :-( The logs read this (per user) Wed Oct 11 17:57:58 2006 : Error: TLS_accept:error in SSLv3 read client certificate A Wed Oct 11 17:57:58 2006 : Error: rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) Wed Oct 11 17:57:58 2006 : Error: TLS Alert write:fatal:bad record mac Wed Oct 11 17:57:58 2006 : Error: TLS_accept:error in SSLv3 read certificate verify A Wed Oct 11 17:57:58 2006 : Error: rlm_eap: SSL error error:1408F455:SSL routines:SSL3_GET_RECORD:decryption failed or bad record mac Wed Oct 11 17:57:58 2006 : Error: rlm_eap_tls: SSL_read failed in a system call (-1), TLS session fails. Wed Oct 11 17:57:58 2006 : Auth: Login incorrect: [BSC\\mking] (from client BUWiSM-1-2 port 29 cli 00-90-96-F4-2A-BB) For every single user. At the very beginning, a few users authenticate fine, nobody gets on after that. (All this in the first second of starting the server) So I move everyone back to my working server (version 1.0.4, OpenSSL is 0.9.7e-3 via debian) Now, it's still in this state. If I stop and start the server, it'll be normal again. Is there anykind of debugging info I can get you right now without killing the running process? I moved traffic to the server at: 17:54:03 I moved traffic off at: 17:54:36 As you can see above, I tried it with a test station at 17:57:58, and it was still busted. (Test station worked fine at 17:50) Also, I checked out the /var/log/messages file, it had this weirdness in it. I tried restarting winbindd a few seconds before these time stamps, so that's may be what threw all the error messages. Oct 11 17:02:42 radius1 kernel: audit(1160600562.652:20): avc: denied { search } for pid=2831 comm="winbindd" name="lib" dev=dm-0 ino=589826 scontext=user _u:system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:02:42 radius1 kernel: audit(1160600562.652:21): avc: denied { getattr } for pid=2831 comm="winbindd" name="samba" dev=dm-0 ino=589961 scontext=u ser_u:system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:57:44 radius1 winbind: winbindd shutdown succeeded Oct 11 17:57:46 radius1 kernel: audit(1160603866.541:22): avc: denied { setattr } for pid=4000 comm="winbindd" name="winbindd" dev=dm-0 ino=590836 scontex t=root:system_r:winbind_t tcontext=root:object_r:samba_log_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:23): avc: denied { write } for pid=4000 comm="winbindd" name="secrets.tdb" dev=dm-0 ino=937186 sconte xt=root:system_r:winbind_t tcontext=root:object_r:samba_etc_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:24): avc: denied { search } for pid=4000 comm="winbindd" name="lib" dev=dm-0 ino=589826 scontext=root :system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:25): avc: denied { read write } for pid=4000 comm="winbindd" name="gencache.tdb" dev=dm-0 ino=590838 scontext=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:26): avc: denied { lock } for pid=4000 comm="winbindd" name="gencache.tdb" dev=dm-0 ino=590838 sconte xt=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:27): avc: denied { getattr } for pid=4000 comm="winbindd" name="gencache.tdb" dev=dm-0 ino=590838 sco ntext=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.566:28): avc: denied { getattr } for pid=4000 comm="winbindd" name="samba" dev=dm-0 ino=589961 scontext=r oot:system_r:winbind_t tcontext=system_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:29): avc: denied { getattr } for pid=4001 comm="winbindd" name="winbindd_privileged" dev=dm-0 ino=590 759 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:30): avc: denied { search } for pid=4001 comm="winbindd" name="winbindd_privileged" dev=dm-0 ino=5907 59 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:31): avc: denied { write } for pid=4001 comm="winbindd" name="winbindd_privileged" dev=dm-0 ino=59075 9 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:32): avc: denied { remove_name } for pid=4001 comm="winbindd" name="pipe" dev=dm-0 ino=590760 scontex t=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:33): avc: denied { unlink } for pid=4001 comm="winbindd" name="pipe" dev=dm-0 ino=590760 scontext=roo t:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=sock_file Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:34): avc: denied { add_name } for pid=4001 comm="winbindd" name="pipe" scontext=root:system_r:winbind _t tcontext=user_u:object_r:var_lib_t tclass=dir Oct 11 17:57:46 radius1 kernel: audit(1160603866.568:35): avc: denied { create } for pid=4001 comm="winbindd" name="pipe" scontext=root:system_r:winbind_t tcontext=root:object_r:var_lib_t tclass=sock_file Oct 11 17:57:46 radius1 winbind: winbindd startup succeeded Oct 11 17:57:46 radius1 kernel: audit(1160603866.572:36): avc: denied { write } for pid=4002 comm="winbindd" name="krb5.conf" dev=dm-0 ino=934018 scontext =root:system_r:winbind_t tcontext=root:object_r:etc_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.600:37): avc: denied { read write } for pid=4002 comm="winbindd" name="winbindd_cache.tdb" dev=dm-0 ino=5 90761 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.600:38): avc: denied { lock } for pid=4002 comm="winbindd" name="winbindd_cache.tdb" dev=dm-0 ino=590761 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=file Oct 11 17:57:46 radius1 kernel: audit(1160603866.600:39): avc: denied { getattr } for pid=4002 comm="winbindd" name="winbindd_cache.tdb" dev=dm-0 ino=5907 61 scontext=root:system_r:winbind_t tcontext=user_u:object_r:var_lib_t tclass=file

2 5

Freeradius error: invalid keyword "ATTRIB_NMC"
by Jan Mulders 18 Oct '06

18 Oct '06

Hi list. I'm having some problems getting the nightly CVS snapshot to work. It compiles fine, I've set relevant log directories, and gotten rid of the old dictionary files, instead using the ones in the CVS. I now get this error when attempting to start radiusd: Wed Oct 18 15:18:43 2006 : Error: Errors reading dictionary: dict_init: /usr/local/share/freeradius/dictionary.usr[56] invalid keyword "ATTRIB_NMC" The offending file contains the following: # # USR Extensions: USR Vendor-Specific stuff. # # For now in NMC format (whatever that stands for), though the # normal vendor-specific format would work just as well. # # ATTRIB_NMC USR-Last-Number-Dialed-Out 0x0066 string ATTRIB_NMC USR-Last-Number-Dialed-In-DNIS 0x00E8 string ATTRIB_NMC USR-Last-Callers-Number-ANI 0x00E9 string ATTRIB_NMC USR-Channel 0xBF38 integer ATTRIB_NMC USR-Event-Id 0xBFBE integer ATTRIB_NMC USR-Event-Date-Time 0xBF2F date ATTRIB_NMC USR-Call-Start-Date-Time 0xBFF7 date ATTRIB_NMC USR-Call-End-Date-Time 0xBFF6 date ATTRIB_NMC USR-Default-DTE-Data-Rate 0x005E integer ...and on and on. Is there something I need to do in order to get this to work? Have I made a silly mistake? Thanks all, Jan

2 1

Stress test for EAP-PEAP
by King, Michael 18 Oct '06

18 Oct '06

Since I've been having great amounts of troubles with 1.1.2 / 1.1.3, (See SSL_read failed in a system call message) We're going to try building another server with 1.0.4 (The latest version that we have in production that works for us) Anyone know of a stress test utility that can simulate EAP-PEAP? In my test labs, everything works great. It's only when I load a few hundred to a thousand clients that things seem to break. I'd like to find out if this new server is going to have issues before I impact my clients

2 1