FreeRADIUS, 3com (4500) and Windows Vista.
Hello. I have serious problem. At my company we use 802.1x authentication to access (wired) network. VLANs are dynamically assigned and users have the same privileges no matter in what location they're plugged in. Except Vista... We use 3com 4500 switches as NAS and FreeRADIUS 1.1.6 as RADIUS server. When non-vista user plugs in - one has to provide credentials and after a while - port on a switch is in authorized state. When Vista user plugs in - one also has to provide credentials. And after a while - port on a switch is in authorized state. BUT "a baloon" which prompts user for credentials pops up again. And it can pop up like three/four times in a row for a minute or two until... the connection is lost. The port on the switch is put into unauthorized state. It's impossible to work at such conditions ;-) I know that user has to reauthenticate after a period of time but i thought it should be done in a background - like other systems do. I've tried to trick the system by using "remember credentials" checkbox, but after that system doesn't want to reauthenticate at all. I'm kinda confused. I've attached two logfiles. One from the `freeradius -XX` stdout and one from the switch's console output. I've used built-in 802.1x PEAP authentication and securew2 TTLS client. Both fails to keep the connection. Thanks in advance, -- Lech Karol Pawłaszek <ike> "You will never see me fall from grace" [KoRn] Wed Jul 4 16:59:36 2007 : Info: Starting - reading configuration files ... Wed Jul 4 16:59:36 2007 : Debug: reread_config: reading radiusd.conf Wed Jul 4 16:59:36 2007 : Debug: Config: including file: /etc/freeradius/proxy.conf Wed Jul 4 16:59:36 2007 : Debug: Config: including file: /etc/freeradius/clients.conf Wed Jul 4 16:59:36 2007 : Debug: Config: including file: /etc/freeradius/snmp.conf Wed Jul 4 16:59:36 2007 : Debug: Config: including file: /etc/freeradius/eap.conf Wed Jul 4 16:59:36 2007 : Debug: Config: including file: /etc/freeradius/sql.conf Wed Jul 4 16:59:36 2007 : Debug: main: prefix = "/usr" Wed Jul 4 16:59:36 2007 : Debug: main: localstatedir = "/var" Wed Jul 4 16:59:36 2007 : Debug: main: logdir = "/var/log/freeradius" Wed Jul 4 16:59:36 2007 : Debug: main: libdir = "/usr/lib/freeradius" Wed Jul 4 16:59:36 2007 : Debug: main: radacctdir = "/var/log/freeradius/radacct" Wed Jul 4 16:59:36 2007 : Debug: main: hostname_lookups = no Wed Jul 4 16:59:36 2007 : Debug: main: max_request_time = 30 Wed Jul 4 16:59:36 2007 : Debug: main: cleanup_delay = 5 Wed Jul 4 16:59:36 2007 : Debug: main: max_requests = 1024 Wed Jul 4 16:59:36 2007 : Debug: main: delete_blocked_requests = 0 Wed Jul 4 16:59:36 2007 : Debug: main: port = 0 Wed Jul 4 16:59:36 2007 : Debug: main: allow_core_dumps = no Wed Jul 4 16:59:36 2007 : Debug: main: log_stripped_names = no Wed Jul 4 16:59:36 2007 : Debug: main: log_file = "/var/log/freeradius/radius.log" Wed Jul 4 16:59:36 2007 : Debug: main: log_auth = no Wed Jul 4 16:59:36 2007 : Debug: main: log_auth_badpass = no Wed Jul 4 16:59:36 2007 : Debug: main: log_auth_goodpass = no Wed Jul 4 16:59:36 2007 : Debug: main: pidfile = "/var/run/freeradius/freeradius.pid" Wed Jul 4 16:59:36 2007 : Debug: main: user = "freerad" Wed Jul 4 16:59:36 2007 : Debug: main: group = "freerad" Wed Jul 4 16:59:36 2007 : Debug: main: usercollide = no Wed Jul 4 16:59:36 2007 : Debug: main: lower_user = "no" Wed Jul 4 16:59:36 2007 : Debug: main: lower_pass = "no" Wed Jul 4 16:59:36 2007 : Debug: main: nospace_user = "no" Wed Jul 4 16:59:36 2007 : Debug: main: nospace_pass = "no" Wed Jul 4 16:59:36 2007 : Debug: main: checkrad = "/usr/sbin/checkrad" Wed Jul 4 16:59:36 2007 : Debug: main: proxy_requests = yes Wed Jul 4 16:59:36 2007 : Debug: proxy: retry_delay = 5 Wed Jul 4 16:59:36 2007 : Debug: proxy: retry_count = 3 Wed Jul 4 16:59:36 2007 : Debug: proxy: synchronous = no Wed Jul 4 16:59:36 2007 : Debug: proxy: default_fallback = yes Wed Jul 4 16:59:36 2007 : Debug: proxy: dead_time = 120 Wed Jul 4 16:59:36 2007 : Debug: proxy: post_proxy_authorize = no Wed Jul 4 16:59:36 2007 : Debug: proxy: wake_all_if_all_dead = no Wed Jul 4 16:59:36 2007 : Debug: security: max_attributes = 200 Wed Jul 4 16:59:36 2007 : Debug: security: reject_delay = 1 Wed Jul 4 16:59:36 2007 : Debug: security: status_server = no Wed Jul 4 16:59:36 2007 : Debug: main: debug_level = 0 Wed Jul 4 16:59:36 2007 : Debug: read_config_files: reading dictionary Wed Jul 4 16:59:36 2007 : Debug: read_config_files: reading naslist Wed Jul 4 16:59:36 2007 : Info: Using deprecated naslist file. Support for this will go away soon. Wed Jul 4 16:59:36 2007 : Debug: read_config_files: reading clients Wed Jul 4 16:59:36 2007 : Debug: read_config_files: reading realms Wed Jul 4 16:59:36 2007 : Debug: radiusd: entering modules setup Wed Jul 4 16:59:36 2007 : Debug: Module: Library search path is /usr/lib/freeradius Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded exec Wed Jul 4 16:59:36 2007 : Debug: exec: wait = yes Wed Jul 4 16:59:36 2007 : Debug: exec: program = "(null)" Wed Jul 4 16:59:36 2007 : Debug: exec: input_pairs = "request" Wed Jul 4 16:59:36 2007 : Debug: exec: output_pairs = "(null)" Wed Jul 4 16:59:36 2007 : Debug: exec: packet_type = "(null)" Wed Jul 4 16:59:36 2007 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none? Wed Jul 4 16:59:36 2007 : Debug: Module: Instantiated exec (exec) Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded expr Wed Jul 4 16:59:36 2007 : Debug: Module: Instantiated expr (expr) Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded PAP Wed Jul 4 16:59:36 2007 : Debug: pap: encryption_scheme = "crypt" Wed Jul 4 16:59:36 2007 : Debug: pap: auto_header = yes Wed Jul 4 16:59:36 2007 : Debug: Module: Instantiated pap (pap) Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded CHAP Wed Jul 4 16:59:36 2007 : Debug: Module: Instantiated chap (chap) Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded MS-CHAP Wed Jul 4 16:59:36 2007 : Debug: mschap: use_mppe = yes Wed Jul 4 16:59:36 2007 : Debug: mschap: require_encryption = no Wed Jul 4 16:59:36 2007 : Debug: mschap: require_strong = no Wed Jul 4 16:59:36 2007 : Debug: mschap: with_ntdomain_hack = no Wed Jul 4 16:59:36 2007 : Debug: mschap: passwd = "(null)" Wed Jul 4 16:59:36 2007 : Debug: mschap: ntlm_auth = "(null)" Wed Jul 4 16:59:36 2007 : Debug: Module: Instantiated mschap (mschap) Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded System Wed Jul 4 16:59:36 2007 : Debug: unix: cache = no Wed Jul 4 16:59:36 2007 : Debug: unix: passwd = "(null)" Wed Jul 4 16:59:36 2007 : Debug: unix: shadow = "/etc/shadow" Wed Jul 4 16:59:36 2007 : Debug: unix: group = "(null)" Wed Jul 4 16:59:36 2007 : Debug: unix: radwtmp = "/var/log/freeradius/radwtmp" Wed Jul 4 16:59:36 2007 : Debug: unix: usegroup = no Wed Jul 4 16:59:36 2007 : Debug: unix: cache_reload = 600 Wed Jul 4 16:59:36 2007 : Debug: Module: Instantiated unix (unix) Wed Jul 4 16:59:36 2007 : Debug: Module: Loaded eap Wed Jul 4 16:59:36 2007 : Debug: eap: default_eap_type = "md5" Wed Jul 4 16:59:36 2007 : Debug: eap: timer_expire = 60 Wed Jul 4 16:59:36 2007 : Debug: eap: ignore_unknown_eap_types = no Wed Jul 4 16:59:36 2007 : Debug: eap: cisco_accounting_username_bug = no Wed Jul 4 16:59:36 2007 : Debug: rlm_eap: Loaded and initialized type md5 Wed Jul 4 16:59:36 2007 : Debug: rlm_eap: Loaded and initialized type leap Wed Jul 4 16:59:36 2007 : Debug: gtc: challenge = "Password: " Wed Jul 4 16:59:36 2007 : Debug: gtc: auth_type = "PAP" Wed Jul 4 16:59:36 2007 : Debug: rlm_eap: Loaded and initialized type gtc Wed Jul 4 16:59:36 2007 : Debug: tls: rsa_key_exchange = no Wed Jul 4 16:59:36 2007 : Debug: tls: dh_key_exchange = yes Wed Jul 4 16:59:36 2007 : Debug: tls: rsa_key_length = 512 Wed Jul 4 16:59:36 2007 : Debug: tls: dh_key_length = 512 Wed Jul 4 16:59:36 2007 : Debug: tls: verify_depth = 0 Wed Jul 4 16:59:36 2007 : Debug: tls: CA_path = "(null)" Wed Jul 4 16:59:36 2007 : Debug: tls: pem_file_type = yes Wed Jul 4 16:59:36 2007 : Debug: tls: private_key_file = "/etc/freeradius/certs/CERT/cert-srv.pem" Wed Jul 4 16:59:36 2007 : Debug: tls: certificate_file = "/etc/freeradius/certs/CERT/cert-srv.pem" Wed Jul 4 16:59:36 2007 : Debug: tls: CA_file = "/etc/freeradius/certs/CERT/root.pem" Wed Jul 4 16:59:36 2007 : Debug: tls: private_key_password = "BLStream" Wed Jul 4 16:59:36 2007 : Debug: tls: dh_file = "/etc/freeradius/certs/CERT/dh" Wed Jul 4 16:59:36 2007 : Debug: tls: random_file = "/dev/urandom" Wed Jul 4 16:59:36 2007 : Debug: tls: fragment_size = 1024 Wed Jul 4 16:59:36 2007 : Debug: tls: include_length = yes Wed Jul 4 16:59:36 2007 : Debug: tls: check_crl = no Wed Jul 4 16:59:36 2007 : Debug: tls: check_cert_cn = "(null)" Wed Jul 4 16:59:36 2007 : Debug: tls: cipher_list = "(null)" Wed Jul 4 16:59:36 2007 : Debug: tls: check_cert_issuer = "(null)" Wed Jul 4 16:59:36 2007 : Info: rlm_eap_tls: Loading the certificate file as a chain Wed Jul 4 16:59:37 2007 : Debug: rlm_eap: Loaded and initialized type tls Wed Jul 4 16:59:37 2007 : Debug: ttls: default_eap_type = "md5" Wed Jul 4 16:59:37 2007 : Debug: ttls: copy_request_to_tunnel = no Wed Jul 4 16:59:37 2007 : Debug: ttls: use_tunneled_reply = no Wed Jul 4 16:59:37 2007 : Debug: rlm_eap: Loaded and initialized type ttls Wed Jul 4 16:59:37 2007 : Debug: peap: default_eap_type = "mschapv2" Wed Jul 4 16:59:37 2007 : Debug: peap: copy_request_to_tunnel = no Wed Jul 4 16:59:37 2007 : Debug: peap: use_tunneled_reply = no Wed Jul 4 16:59:37 2007 : Debug: peap: proxy_tunneled_request_as_eap = yes Wed Jul 4 16:59:37 2007 : Debug: rlm_eap: Loaded and initialized type peap Wed Jul 4 16:59:37 2007 : Debug: mschapv2: with_ntdomain_hack = no Wed Jul 4 16:59:37 2007 : Debug: rlm_eap: Loaded and initialized type mschapv2 Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated eap (eap) Wed Jul 4 16:59:37 2007 : Debug: Module: Loaded preprocess Wed Jul 4 16:59:37 2007 : Debug: preprocess: huntgroups = "/etc/freeradius/huntgroups" Wed Jul 4 16:59:37 2007 : Debug: preprocess: hints = "/etc/freeradius/hints" Wed Jul 4 16:59:37 2007 : Debug: preprocess: with_ascend_hack = no Wed Jul 4 16:59:37 2007 : Debug: preprocess: ascend_channels_per_line = 23 Wed Jul 4 16:59:37 2007 : Debug: preprocess: with_ntdomain_hack = no Wed Jul 4 16:59:37 2007 : Debug: preprocess: with_specialix_jetstream_hack = no Wed Jul 4 16:59:37 2007 : Debug: preprocess: with_cisco_vsa_hack = no Wed Jul 4 16:59:37 2007 : Debug: preprocess: with_alvarion_vsa_hack = no Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated preprocess (preprocess) Wed Jul 4 16:59:37 2007 : Debug: Module: Loaded realm Wed Jul 4 16:59:37 2007 : Debug: realm: format = "suffix" Wed Jul 4 16:59:37 2007 : Debug: realm: delimiter = "@" Wed Jul 4 16:59:37 2007 : Debug: realm: ignore_default = no Wed Jul 4 16:59:37 2007 : Debug: realm: ignore_null = no Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated realm (suffix) Wed Jul 4 16:59:37 2007 : Debug: Module: Loaded files Wed Jul 4 16:59:37 2007 : Debug: files: usersfile = "/etc/freeradius/users" Wed Jul 4 16:59:37 2007 : Debug: files: acctusersfile = "/etc/freeradius/acct_users" Wed Jul 4 16:59:37 2007 : Debug: files: preproxy_usersfile = "/etc/freeradius/preproxy_users" Wed Jul 4 16:59:37 2007 : Debug: files: compat = "no" Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated files (files) Wed Jul 4 16:59:37 2007 : Debug: Module: Loaded Acct-Unique-Session-Id Wed Jul 4 16:59:37 2007 : Debug: acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated acct_unique (acct_unique) Wed Jul 4 16:59:37 2007 : Debug: Module: Loaded detail Wed Jul 4 16:59:37 2007 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Wed Jul 4 16:59:37 2007 : Debug: detail: detailperm = 384 Wed Jul 4 16:59:37 2007 : Debug: detail: dirperm = 493 Wed Jul 4 16:59:37 2007 : Debug: detail: locking = no Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated detail (detail) Wed Jul 4 16:59:37 2007 : Debug: Module: Loaded radutmp Wed Jul 4 16:59:37 2007 : Debug: radutmp: filename = "/var/log/freeradius/radutmp" Wed Jul 4 16:59:37 2007 : Debug: radutmp: username = "%{User-Name}" Wed Jul 4 16:59:37 2007 : Debug: radutmp: case_sensitive = yes Wed Jul 4 16:59:37 2007 : Debug: radutmp: check_with_nas = yes Wed Jul 4 16:59:37 2007 : Debug: radutmp: perm = 384 Wed Jul 4 16:59:37 2007 : Debug: radutmp: callerid = yes Wed Jul 4 16:59:37 2007 : Debug: Module: Instantiated radutmp (radutmp) Wed Jul 4 16:59:37 2007 : Debug: Listening on authentication *:1812 Wed Jul 4 16:59:37 2007 : Debug: Listening on accounting *:1813 Wed Jul 4 16:59:37 2007 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.0.101:5001, id=48, length=113 User-Name = "windows" EAP-Message = 0x0201000c0177696e646f7773 Message-Authenticator = 0x444d8e6faba64d1e2bb7a312881af4de NAS-IP-Address = 192.168.0.101 NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Service-Type = Framed-User Framed-Protocol = PPP Calling-Station-Id = "0017-a4e1-2c86" Wed Jul 4 16:59:45 2007 : Debug: Processing the authorize section of radiusd.conf Wed Jul 4 16:59:45 2007 : Debug: modcall: entering group authorize for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0 Wed Jul 4 16:59:45 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:45 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: EAP packet type response id 1 length 12 Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0 Wed Jul 4 16:59:45 2007 : Debug: users: Matched entry DEFAULT at line 153 Wed Jul 4 16:59:45 2007 : Debug: users: Matched entry DEFAULT at line 172 Wed Jul 4 16:59:45 2007 : Debug: users: Matched entry DEFAULT at line 184 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "files" returns ok for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "pap" returns noop for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall: leaving group authorize (returns updated) for request 0 Wed Jul 4 16:59:45 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed Jul 4 16:59:45 2007 : Debug: auth: type "EAP" Wed Jul 4 16:59:45 2007 : Debug: Processing the authenticate section of radiusd.conf Wed Jul 4 16:59:45 2007 : Debug: modcall: entering group authenticate for request 0 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: EAP Identity Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: processing type md5 Wed Jul 4 16:59:45 2007 : Info: rlm_eap_md5: Issuing Challenge Wed Jul 4 16:59:45 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 0 Wed Jul 4 16:59:45 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 48 to 192.168.0.101 port 5001 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP EAP-Message = 0x0102001604107e221326be214a5fe9d6289619b535d9 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x83e9e226d093fd3a34a1b8aa9cf3cc66 Wed Jul 4 16:59:45 2007 : Debug: Finished request 0 Wed Jul 4 16:59:45 2007 : Debug: Going to the next request Wed Jul 4 16:59:45 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:45 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.0.101:5001, id=49, length=125 User-Name = "windows" EAP-Message = 0x020200060315 Message-Authenticator = 0x21527f75b96370cc339d961533f147bc NAS-IP-Address = 192.168.0.101 NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Service-Type = Framed-User Framed-Protocol = PPP Calling-Station-Id = "0017-a4e1-2c86" State = 0x83e9e226d093fd3a34a1b8aa9cf3cc66 Wed Jul 4 16:59:45 2007 : Debug: Processing the authorize section of radiusd.conf Wed Jul 4 16:59:45 2007 : Debug: modcall: entering group authorize for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 1 Wed Jul 4 16:59:45 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:45 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: EAP packet type response id 2 length 6 Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 1 Wed Jul 4 16:59:45 2007 : Debug: users: Matched entry DEFAULT at line 153 Wed Jul 4 16:59:45 2007 : Debug: users: Matched entry DEFAULT at line 172 Wed Jul 4 16:59:45 2007 : Debug: users: Matched entry DEFAULT at line 184 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "files" returns ok for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jul 4 16:59:45 2007 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authorize]: module "pap" returns noop for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall: leaving group authorize (returns updated) for request 1 Wed Jul 4 16:59:45 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed Jul 4 16:59:45 2007 : Debug: auth: type "EAP" Wed Jul 4 16:59:45 2007 : Debug: Processing the authenticate section of radiusd.conf Wed Jul 4 16:59:45 2007 : Debug: modcall: entering group authenticate for request 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: Request found, released from the list Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: EAP NAK Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: EAP-NAK asked for EAP-Type/ttls Wed Jul 4 16:59:45 2007 : Debug: rlm_eap: processing type tls Wed Jul 4 16:59:45 2007 : Debug: rlm_eap_tls: Initiate Wed Jul 4 16:59:45 2007 : Debug: rlm_eap_tls: Start returned 1 Wed Jul 4 16:59:45 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 1 Wed Jul 4 16:59:45 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 49 to 192.168.0.101 port 5001 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP EAP-Message = 0x010300061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd94d2390e46b7e7424967ddc53d6e624 Wed Jul 4 16:59:45 2007 : Debug: Finished request 1 Wed Jul 4 16:59:45 2007 : Debug: Going to the next request Wed Jul 4 16:59:45 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.0.101:5001, id=50, length=179 User-Name = "windows" EAP-Message = 0x0203003c158000000032160301002d01000029030194cf2d38f93c284f79a1da60ce7d2c4b6371b9710ab09c9b0139575ac062630a000002000a0100 Message-Authenticator = 0x1ab6f00ffd25073472cc1f9c29402dd9 NAS-IP-Address = 192.168.0.101 NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Service-Type = Framed-User Framed-Protocol = PPP Calling-Station-Id = "0017-a4e1-2c86" State = 0xd94d2390e46b7e7424967ddc53d6e624 Wed Jul 4 16:59:46 2007 : Debug: Processing the authorize section of radiusd.conf Wed Jul 4 16:59:46 2007 : Debug: modcall: entering group authorize for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 2 Wed Jul 4 16:59:46 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:46 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: rlm_eap: EAP packet type response id 3 length 60 Wed Jul 4 16:59:46 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 2 Wed Jul 4 16:59:46 2007 : Debug: users: Matched entry DEFAULT at line 153 Wed Jul 4 16:59:46 2007 : Debug: users: Matched entry DEFAULT at line 172 Wed Jul 4 16:59:46 2007 : Debug: users: Matched entry DEFAULT at line 184 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "files" returns ok for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jul 4 16:59:46 2007 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authorize]: module "pap" returns noop for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall: leaving group authorize (returns updated) for request 2 Wed Jul 4 16:59:46 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed Jul 4 16:59:46 2007 : Debug: auth: type "EAP" Wed Jul 4 16:59:46 2007 : Debug: Processing the authenticate section of radiusd.conf Wed Jul 4 16:59:46 2007 : Debug: modcall: entering group authenticate for request 2 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: rlm_eap: Request found, released from the list Wed Jul 4 16:59:46 2007 : Debug: rlm_eap: EAP/ttls Wed Jul 4 16:59:46 2007 : Debug: rlm_eap: processing type ttls Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_ttls: Authenticate Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_tls: processing TLS Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_tls: Length Included Wed Jul 4 16:59:46 2007 : Debug: eaptls_verify returned 11 Wed Jul 4 16:59:46 2007 : Debug: (other): before/accept initialization Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: before/accept initialization Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 002d], ClientHello Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: SSLv3 read client hello A Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: SSLv3 write server hello A Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0277], Certificate Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: SSLv3 write certificate A Wed Jul 4 16:59:46 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: SSLv3 write server done A Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: SSLv3 flush data Wed Jul 4 16:59:46 2007 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A Wed Jul 4 16:59:46 2007 : Debug: In SSL Handshake Phase Wed Jul 4 16:59:46 2007 : Debug: In SSL Accept mode Wed Jul 4 16:59:46 2007 : Debug: eaptls_process returned 13 Wed Jul 4 16:59:46 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 2 Wed Jul 4 16:59:46 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 50 to 192.168.0.101 port 5001 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP EAP-Message = 0x010402de1580000002d4160301004a020000460301468bb5e2a4975a93c8164e0156bac69a62b4682ea4f498a7f41671a7b73159db20515e1c2b5bd73cfd20dc38cba49aa7179b1bbeeb7cea04288e3f0c6d3387070b000a0016030102770b00027300027000026d30820269308201d2a003020102020101300d06092a864886f70d0101050500306e310b300906035504061302504c311330110603550408130a536f6d652d53746174653111300f06035504071308537a637a6563696e3111300f060355040a1308424c53747265616d3111300f060355040b1308424c53747265616d3111300f06035504031308424c53747265616d301e170d3037 EAP-Message = 0x303431303133303334305a170d3038303430393133303334305a306e310b300906035504061302504c311330110603550408130a536f6d652d53746174653111300f06035504071308537a637a6563696e3111300f060355040a1308424c53747265616d3111300f060355040b1308424c53747265616d3111300f06035504031308424c53747265616d30819f300d06092a864886f70d010101050003818d0030818902818100afb54d4842d2c71a18300bdbab4072c1eb95316fe2123ab0b61c53041f6283653e2f40bbacadf8c8024d08daf5eafe2f91ca633dcfb86981c53c4c765d85bbc1f35019be2534b2f43b149b918c3851f55f5899d2a656 EAP-Message = 0x8c20374f39ff26baa68214ba723042dac8116294c72e4d63928d2772389cc6e9d0801b83064ca26354530203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000381810072d3d8ed4865c9885b9ecd447b5b9aa0e61b817829d52a7711a050a257682d2699a54b2a8b87111f8c79e698f443b569d818116b9fe390626a756560713a095a3ae8df41afd7d428b8ba734efd1d08a6a72b47f56f0b109d1f6a982235f62f2f82cc558bd9edc999e015671f6e7673856895c5718981a184d5023e6818a2a3f416030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xe4fb85c1d069ea7c3edc9d62c438dbd3 Wed Jul 4 16:59:46 2007 : Debug: Finished request 2 Wed Jul 4 16:59:46 2007 : Debug: Going to the next request Wed Jul 4 16:59:46 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:46 2007 : Debug: Waking up in 5 seconds... rad_recv: Access-Request packet from host 192.168.0.101:5001, id=51, length=319 User-Name = "windows" EAP-Message = 0x020400c81580000000be160301008610000082008014d2c8e23608ab3d1bfb4de79f06fa4f447c97b7f7a401c5851ec350df61d665b2aed41e3a49382877630e0861cd157db5358e6ee0fa9137ff8d8d39951a3ebd5f31ca7d7b69713248f589ced97c3498b7e6c3da61e6c0ec1a0d5e9bef96df2f5f2e512194ed3efd3c48890c0b7b70256f197bd3de3863a652d715b3837bf9ad1403010001011603010028b9dd07638168c95c3105ec091da9cea7a1a3530433ca5ac02c72622c1f0612adf8eb001f75b7ae80 Message-Authenticator = 0x92397db0cbc22142c0ae0e125ed28b25 NAS-IP-Address = 192.168.0.101 NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Service-Type = Framed-User Framed-Protocol = PPP Calling-Station-Id = "0017-a4e1-2c86" State = 0xe4fb85c1d069ea7c3edc9d62c438dbd3 Wed Jul 4 16:59:47 2007 : Debug: Processing the authorize section of radiusd.conf Wed Jul 4 16:59:47 2007 : Debug: modcall: entering group authorize for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 3 Wed Jul 4 16:59:47 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:47 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: rlm_eap: EAP packet type response id 4 length 200 Wed Jul 4 16:59:47 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 3 Wed Jul 4 16:59:47 2007 : Debug: users: Matched entry DEFAULT at line 153 Wed Jul 4 16:59:47 2007 : Debug: users: Matched entry DEFAULT at line 172 Wed Jul 4 16:59:47 2007 : Debug: users: Matched entry DEFAULT at line 184 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "files" returns ok for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jul 4 16:59:47 2007 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authorize]: module "pap" returns noop for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall: leaving group authorize (returns updated) for request 3 Wed Jul 4 16:59:47 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed Jul 4 16:59:47 2007 : Debug: auth: type "EAP" Wed Jul 4 16:59:47 2007 : Debug: Processing the authenticate section of radiusd.conf Wed Jul 4 16:59:47 2007 : Debug: modcall: entering group authenticate for request 3 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: rlm_eap: Request found, released from the list Wed Jul 4 16:59:47 2007 : Debug: rlm_eap: EAP/ttls Wed Jul 4 16:59:47 2007 : Debug: rlm_eap: processing type ttls Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_ttls: Authenticate Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: processing TLS Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: Length Included Wed Jul 4 16:59:47 2007 : Debug: eaptls_verify returned 11 Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Wed Jul 4 16:59:47 2007 : Debug: TLS_accept: SSLv3 read client key exchange A Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001] Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished Wed Jul 4 16:59:47 2007 : Debug: TLS_accept: SSLv3 read finished A Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001] Wed Jul 4 16:59:47 2007 : Debug: TLS_accept: SSLv3 write change cipher spec A Wed Jul 4 16:59:47 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished Wed Jul 4 16:59:47 2007 : Debug: TLS_accept: SSLv3 write finished A Wed Jul 4 16:59:47 2007 : Debug: TLS_accept: SSLv3 flush data Wed Jul 4 16:59:47 2007 : Debug: (other): SSL negotiation finished successfully Wed Jul 4 16:59:47 2007 : Debug: SSL Connection Established Wed Jul 4 16:59:47 2007 : Debug: eaptls_process returned 13 Wed Jul 4 16:59:47 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 3 Wed Jul 4 16:59:47 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 3 Sending Access-Challenge of id 51 to 192.168.0.101 port 5001 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP EAP-Message = 0x0105003d15800000003314030100010116030100280817e0c979a1581256954dbd92eb185703224f29328669f70d77f4b1f115c60a36a6572ed53c7e4d Message-Authenticator = 0x00000000000000000000000000000000 State = 0xaf9772dd39f5fef5662a750d599a7173 Wed Jul 4 16:59:47 2007 : Debug: Finished request 3 Wed Jul 4 16:59:47 2007 : Debug: Going to the next request Wed Jul 4 16:59:47 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:47 2007 : Debug: Waking up in 4 seconds... rad_recv: Access-Request packet from host 192.168.0.101:5001, id=52, length=190 User-Name = "windows" EAP-Message = 0x0205004715800000003d1703010038315e06986314921dfa4a6b6392bf76aece1d9b11dd11e7458b0af9a6cd1dfc3831088821584fc5c8022538952d178b18434d58ec558391cc Message-Authenticator = 0xe9f0eca8fad3c1fe3f3c01546c6858d4 NAS-IP-Address = 192.168.0.101 NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Service-Type = Framed-User Framed-Protocol = PPP Calling-Station-Id = "0017-a4e1-2c86" State = 0xaf9772dd39f5fef5662a750d599a7173 Wed Jul 4 16:59:48 2007 : Debug: Processing the authorize section of radiusd.conf Wed Jul 4 16:59:48 2007 : Debug: modcall: entering group authorize for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:48 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: EAP packet type response id 5 length 71 Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 4 Wed Jul 4 16:59:48 2007 : Debug: users: Matched entry DEFAULT at line 153 Wed Jul 4 16:59:48 2007 : Debug: users: Matched entry DEFAULT at line 172 Wed Jul 4 16:59:48 2007 : Debug: users: Matched entry DEFAULT at line 184 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "files" returns ok for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "pap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall: leaving group authorize (returns updated) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed Jul 4 16:59:48 2007 : Debug: auth: type "EAP" Wed Jul 4 16:59:48 2007 : Debug: Processing the authenticate section of radiusd.conf Wed Jul 4 16:59:48 2007 : Debug: modcall: entering group authenticate for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: Request found, released from the list Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: EAP/ttls Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: processing type ttls Wed Jul 4 16:59:48 2007 : Debug: rlm_eap_ttls: Authenticate Wed Jul 4 16:59:48 2007 : Debug: rlm_eap_tls: processing TLS Wed Jul 4 16:59:48 2007 : Debug: rlm_eap_tls: Length Included Wed Jul 4 16:59:48 2007 : Debug: eaptls_verify returned 11 Wed Jul 4 16:59:48 2007 : Debug: eaptls_process returned 7 Wed Jul 4 16:59:48 2007 : Debug: rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes. TTLS tunnel data in 0000: 00 00 00 01 40 00 00 0f 77 69 6e 64 6f 77 73 00 TTLS tunnel data in 0010: 00 00 00 02 40 00 00 0f 77 69 6e 64 6f 77 73 00 TTLS: Got tunneled request User-Name = "windows" User-Password = "windows" FreeRADIUS-Proxied-To = 127.0.0.1 TTLS: Sending tunneled request User-Name = "windows" User-Password = "windows" FreeRADIUS-Proxied-To = 127.0.0.1 Wed Jul 4 16:59:48 2007 : Debug: Processing the authorize section of radiusd.conf Wed Jul 4 16:59:48 2007 : Debug: modcall: entering group authorize for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:48 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: No EAP-Message, not doing EAP Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "eap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 4 Wed Jul 4 16:59:48 2007 : Debug: users: Matched entry DEFAULT at line 153 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "files" returns ok for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jul 4 16:59:48 2007 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authorize]: module "pap" returns noop for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall: leaving group authorize (returns ok) for request 4 Wed Jul 4 16:59:48 2007 : Debug: rad_check_password: Found Auth-Type System Wed Jul 4 16:59:48 2007 : Debug: auth: type "System" Wed Jul 4 16:59:48 2007 : Debug: Processing the authenticate section of radiusd.conf Wed Jul 4 16:59:48 2007 : Debug: modcall: entering group authenticate for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authenticate]: calling unix (rlm_unix) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modsingle[authenticate]: returned from unix (rlm_unix) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authenticate]: module "unix" returns ok for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall: leaving group authenticate (returns ok) for request 4 TTLS: Got tunneled reply RADIUS code 2 Wed Jul 4 16:59:48 2007 : Debug: TTLS: Got tunneled Access-Accept Wed Jul 4 16:59:48 2007 : Debug: rlm_eap: Freeing handler Wed Jul 4 16:59:48 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall[authenticate]: module "eap" returns ok for request 4 Wed Jul 4 16:59:48 2007 : Debug: modcall: leaving group authenticate (returns ok) for request 4 Sending Access-Accept of id 52 to 192.168.0.101 port 5001 Framed-IP-Address = 255.255.255.254 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP MS-MPPE-Recv-Key = 0xfef30370af9456481e25da06b05e8791016870004a747ebffe1511441c1ef7ec MS-MPPE-Send-Key = 0x8719de99a610ee10bbb374c2e12a712cb9371dc8aceb2e2b10b3b60268d0bd52 EAP-Message = 0x03050004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "windows" Wed Jul 4 16:59:48 2007 : Debug: Finished request 4 Wed Jul 4 16:59:48 2007 : Debug: Going to the next request Wed Jul 4 16:59:48 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:48 2007 : Debug: Waking up in 3 seconds... rad_recv: Accounting-Request packet from host 192.168.0.101:5001, id=81, length=102 User-Name = "windows" NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Calling-Station-Id = "0017-a4e1-2c86" Acct-Status-Type = Start Acct-Authentic = RADIUS Acct-Session-Id = "110706041659a" NAS-IP-Address = 192.168.0.101 Event-Timestamp = "Jul 4 2007 18:59:28 CEST" Wed Jul 4 16:59:48 2007 : Debug: Processing the preacct section of radiusd.conf Wed Jul 4 16:59:48 2007 : Debug: modcall: entering group preacct for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: calling preprocess (rlm_preprocess) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: returned from preprocess (rlm_preprocess) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[preacct]: module "preprocess" returns noop for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: calling acct_unique (rlm_acct_unique) for request 5 Wed Jul 4 16:59:48 2007 : Debug: rlm_acct_unique: Hashing 'NAS-Port = 268533761,Client-IP-Address = 192.168.0.101,NAS-IP-Address = 192.168.0.101,Acct-Session-Id = "110706041659a",User-Name = "windows"' Wed Jul 4 16:59:48 2007 : Debug: rlm_acct_unique: Acct-Unique-Session-ID = "444a790794f6652e". Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: returned from acct_unique (rlm_acct_unique) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[preacct]: module "acct_unique" returns ok for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: calling suffix (rlm_realm) for request 5 Wed Jul 4 16:59:48 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 16:59:48 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: returned from suffix (rlm_realm) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[preacct]: module "suffix" returns noop for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: calling files (rlm_files) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[preacct]: returned from files (rlm_files) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[preacct]: module "files" returns noop for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall: leaving group preacct (returns ok) for request 5 Wed Jul 4 16:59:48 2007 : Debug: Processing the accounting section of radiusd.conf Wed Jul 4 16:59:48 2007 : Debug: modcall: entering group accounting for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[accounting]: calling detail (rlm_detail) for request 5 Wed Jul 4 16:59:48 2007 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.0.101/detail-20070704' Wed Jul 4 16:59:48 2007 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.0.101/detail-20070704 Wed Jul 4 16:59:48 2007 : Debug: modsingle[accounting]: returned from detail (rlm_detail) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[accounting]: module "detail" returns ok for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[accounting]: calling unix (rlm_unix) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[accounting]: returned from unix (rlm_unix) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[accounting]: module "unix" returns ok for request 5 Wed Jul 4 16:59:48 2007 : Debug: modsingle[accounting]: calling radutmp (rlm_radutmp) for request 5 Wed Jul 4 16:59:48 2007 : Debug: radius_xlat: '/var/log/freeradius/radutmp' Wed Jul 4 16:59:48 2007 : Debug: radius_xlat: 'windows' Wed Jul 4 16:59:48 2007 : Debug: modsingle[accounting]: returned from radutmp (rlm_radutmp) for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall[accounting]: module "radutmp" returns ok for request 5 Wed Jul 4 16:59:48 2007 : Debug: modcall: leaving group accounting (returns ok) for request 5 Sending Accounting-Response of id 81 to 192.168.0.101 port 5001 Wed Jul 4 16:59:48 2007 : Debug: Finished request 5 Wed Jul 4 16:59:48 2007 : Debug: Going to the next request Wed Jul 4 16:59:48 2007 : Debug: Waking up in 3 seconds... Wed Jul 4 16:59:51 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:51 2007 : Debug: Cleaning up request 0 ID 48 with timestamp 468bb5e1 Wed Jul 4 16:59:51 2007 : Debug: Cleaning up request 1 ID 49 with timestamp 468bb5e1 Wed Jul 4 16:59:51 2007 : Debug: Cleaning up request 5 ID 81 with timestamp 468bb5e4 Wed Jul 4 16:59:51 2007 : Debug: Waking up in 1 seconds... Wed Jul 4 16:59:52 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:52 2007 : Debug: Cleaning up request 2 ID 50 with timestamp 468bb5e2 Wed Jul 4 16:59:52 2007 : Debug: Waking up in 1 seconds... Wed Jul 4 16:59:53 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:53 2007 : Debug: Cleaning up request 3 ID 51 with timestamp 468bb5e3 Wed Jul 4 16:59:53 2007 : Debug: Waking up in 1 seconds... Wed Jul 4 16:59:54 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 16:59:54 2007 : Debug: Cleaning up request 4 ID 52 with timestamp 468bb5e4 Wed Jul 4 16:59:54 2007 : Debug: Nothing to do. Sleeping until we see a request. rad_recv: Accounting-Request packet from host 192.168.0.101:5001, id=82, length=156 User-Name = "windows" NAS-Identifier = "4500" NAS-Port = 268533761 NAS-Port-Type = Ethernet Calling-Station-Id = "0017-a4e1-2c86" Acct-Status-Type = Stop Acct-Authentic = RADIUS Acct-Session-Id = "110706041659a" NAS-IP-Address = 192.168.0.101 Event-Timestamp = "Jul 4 2007 19:00:28 CEST" Acct-Session-Time = 60 Acct-Delay-Time = 0 Acct-Input-Octets = 8915 Acct-Input-Packets = 95 Acct-Output-Octets = 8539 Acct-Output-Packets = 117 Acct-Input-Gigawords = 0 Acct-Output-Gigawords = 0 Acct-Terminate-Cause = Lost-Carrier Wed Jul 4 17:00:48 2007 : Debug: Processing the preacct section of radiusd.conf Wed Jul 4 17:00:48 2007 : Debug: modcall: entering group preacct for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: calling preprocess (rlm_preprocess) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: returned from preprocess (rlm_preprocess) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[preacct]: module "preprocess" returns noop for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: calling acct_unique (rlm_acct_unique) for request 6 Wed Jul 4 17:00:48 2007 : Debug: rlm_acct_unique: Hashing 'NAS-Port = 268533761,Client-IP-Address = 192.168.0.101,NAS-IP-Address = 192.168.0.101,Acct-Session-Id = "110706041659a",User-Name = "windows"' Wed Jul 4 17:00:48 2007 : Debug: rlm_acct_unique: Acct-Unique-Session-ID = "444a790794f6652e". Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: returned from acct_unique (rlm_acct_unique) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[preacct]: module "acct_unique" returns ok for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: calling suffix (rlm_realm) for request 6 Wed Jul 4 17:00:48 2007 : Debug: rlm_realm: No '@' in User-Name = "windows", looking up realm NULL Wed Jul 4 17:00:48 2007 : Debug: rlm_realm: No such realm "NULL" Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: returned from suffix (rlm_realm) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[preacct]: module "suffix" returns noop for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: calling files (rlm_files) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[preacct]: returned from files (rlm_files) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[preacct]: module "files" returns noop for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall: leaving group preacct (returns ok) for request 6 Wed Jul 4 17:00:48 2007 : Debug: Processing the accounting section of radiusd.conf Wed Jul 4 17:00:48 2007 : Debug: modcall: entering group accounting for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[accounting]: calling detail (rlm_detail) for request 6 Wed Jul 4 17:00:48 2007 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.0.101/detail-20070704' Wed Jul 4 17:00:48 2007 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.0.101/detail-20070704 Wed Jul 4 17:00:48 2007 : Debug: modsingle[accounting]: returned from detail (rlm_detail) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[accounting]: module "detail" returns ok for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[accounting]: calling unix (rlm_unix) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[accounting]: returned from unix (rlm_unix) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[accounting]: module "unix" returns ok for request 6 Wed Jul 4 17:00:48 2007 : Debug: modsingle[accounting]: calling radutmp (rlm_radutmp) for request 6 Wed Jul 4 17:00:48 2007 : Debug: radius_xlat: '/var/log/freeradius/radutmp' Wed Jul 4 17:00:48 2007 : Debug: radius_xlat: 'windows' Wed Jul 4 17:00:48 2007 : Debug: modsingle[accounting]: returned from radutmp (rlm_radutmp) for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall[accounting]: module "radutmp" returns ok for request 6 Wed Jul 4 17:00:48 2007 : Debug: modcall: leaving group accounting (returns ok) for request 6 Sending Accounting-Response of id 82 to 192.168.0.101 port 5001 Wed Jul 4 17:00:48 2007 : Debug: Finished request 6 Wed Jul 4 17:00:48 2007 : Debug: Going to the next request Wed Jul 4 17:00:48 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 17:00:48 2007 : Debug: Waking up in 6 seconds... Wed Jul 4 17:00:54 2007 : Debug: --- Walking the entire request list --- Wed Jul 4 17:00:54 2007 : Debug: Cleaning up request 6 ID 82 with timestamp 468bb620 Wed Jul 4 17:00:54 2007 : Debug: Nothing to do. Sleeping until we see a request. Jul 4 16:59:24 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Received a EAPOL packet. Jul 4 16:59:24 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,NOT a Eapol-start. Jul 4 16:59:24 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,PacketType: EAPOL-PACKET. Jul 4 16:59:24 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,EAP Type: Response. Jul 4 16:59:24 192.168.0.101 4500 8021X/8/Error::- 1 -Port:23,No resource exist. Jul 4 16:59:25 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Alloc or search resource successfully. Jul 4 16:59:25 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Band the resource to port successfully. Jul 4 16:59:25 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:12,Code Type: Identity. Jul 4 16:59:25 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Sent EAP Msg to 1X-Queue. Jul 4 16:59:25 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,End processing the packet received. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0017-a4e1-2c86 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 12. -----Packet Body----- Code: 2. Identifier: 1. Length: 12. Jul 4 16:59:25 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: EAP MD5-Challenge. Jul 4 16:59:25 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=EAP auth request Index = 12, ulParam3=2181960324] Jul 4 16:59:25 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 16:59:26 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 16:59:26 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [79 EAP-Message ] [14] [0201000C0177696E646F7773] [80 Message-Autheticator ] [18] [00000000000000000000000000000000] [4 NAS-IP-Address ] [6 ] [192.168.0.101] [32 NAS-Identifier ] [6 ] [4500] [5 NAS-Port ] [6 ] [268533761] [61 NAS-Port-Type ] [6 ] [15] Jul 4 16:59:26 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [31 Caller-ID ] [16] [303031372D613465312D32633836] Jul 4 16:59:26 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[48], RetryTimes=[0], Code=[1], Length=[113] Jul 4 16:59:26 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 16:59:27 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 01 30 00 71 07 30 00 00 fff28 00 00 fff0d 00 00 39 4a 00 00 01 09 77 69 6e 64 6f 77 73 4f 0e 02 01 00 0c 01 77 69 6e 64 6f 77 73 50 12 44 4d fff 6f ffffff4d 1e 2b ffffff12 fff1a ffffff04 06 fff fff00 65 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 06 06 00 00 00 02 07 06 00 00 00 01 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 Jul 4 16:59:27 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 110, ulParam3=3372263616] Jul 4 16:59:27 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 16:59:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 0b 30 00 6e 03 11 52 fffffffff74 70 5c 33 07 76 ffffffffffff08 06 ffffffffffff0c 06 00 00 02 40 06 06 00 00 00 02 07 06 00 00 00 01 0d 06 00 00 00 01 4f 18 01 02 00 16 04 10 7e 22 13 26 fff21 4a 5f ffffff28 fff19 fff35 fff50 12 39 fff6a fff 71 4e 44 fff00 40 22 fff37 12 32 1b 18 12 ffffff fff26 fffffffff3a 34 ffffffffffffffffff66 Jul 4 16:59:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[11],Length=[110] Jul 4 16:59:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [8 Framed-Address ] [6 ] [255.255.255.254] [12 Framed-MTU ] [6 ] [576] [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [13 Framed-Compression ] [6 ] [1] [79 EAP-Message ] [24] [0102001604107E221326FF214A5FFFFF28FF19FF35FFFFFFD9] Jul 4 16:59:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [80 Message-Autheticator ] [18] [39FF6AFF714E44FF004022FF3712321B] [24 State ] [18] [FFFFFF26FFFFFF3A34FFFFFFFFFFFF66] Jul 4 16:59:28 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 16:59:29 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 22. -----Packet Body----- Code: 1. Identifier: 2. Length: 22. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Received a EAPOL packet. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,NOT a Eapol-start. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,PacketType: EAPOL-PACKET. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,EAP Type: Response. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Resource exists. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:12,Code Type: Nak. Jul 4 16:59:29 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Sent EAP Msg to 1X-Queue. Jul 4 16:59:30 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,End processing the packet received. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0017-a4e1-2c86 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 6. -----Packet Body----- Code: 2. Identifier: 2. Length: 6. Jul 4 16:59:30 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: EAP MD5-Challenge. Jul 4 16:59:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=EAP auth request Index = 12, ulParam3=2181961364] Jul 4 16:59:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 16:59:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 16:59:31 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [79 EAP-Message ] [8 ] [020200060315] [80 Message-Autheticator ] [18] [00000000000000000000000000000000] [4 NAS-IP-Address ] [6 ] [192.168.0.101] [32 NAS-Identifier ] [6 ] [4500] [5 NAS-Port ] [6 ] [268533761] [61 NAS-Port-Type ] [6 ] [15] Jul 4 16:59:31 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [31 Caller-ID ] [16] [303031372D613465312D32633836] [24 State ] [18] [FFFFFF26FFFFFF3A34FFFFFFFFFFFF66] Jul 4 16:59:31 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[49], RetryTimes=[0], Code=[1], Length=[125] Jul 4 16:59:31 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 16:59:32 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 01 31 00 7d fff36 00 00 70 21 00 00 34 1a 00 00 60 2f 00 00 01 09 77 69 6e 64 6f 77 73 4f 08 02 02 00 06 03 15 50 12 21 52 7f 75 fff63 70 fff33 ffffff15 33 fff47 fff04 06 ffffff00 65 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 06 06 00 00 00 02 07 06 00 00 00 01 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 18 12 fffffffff 26 fffffffff3a 34 ffffffffffffffffff66 Jul 4 16:59:32 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 94, ulParam3=3372263616] Jul 4 16:59:32 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 16:59:32 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 0b 31 00 5e 1b fffffffff41 ffffff10 00 fff16 10 38 fffffffff08 06 ffffffffffff0c 06 00 00 02 40 06 06 00 00 00 02 07 06 00 00 00 01 0d 06 00 00 00 01 4f 08 01 03 00 06 15 20 50 12 29 ffffff31 1f 4c fff30 fff6d 1e 56 fffffffff49 18 12 fff4d 23 ffffff6b 7e 74 24 fff7d fff53 ffffff24 Jul 4 16:59:32 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[11],Length=[94] Jul 4 16:59:33 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [8 Framed-Address ] [6 ] [255.255.255.254] [12 Framed-MTU ] [6 ] [576] [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [13 Framed-Compression ] [6 ] [1] [79 EAP-Message ] [8 ] [010300061520] Jul 4 16:59:33 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [80 Message-Autheticator ] [18] [29FFFF311F4CFF30FF6D1E56FFFFFF49] [24 State ] [18] [FF4D23FFFF6B7E7424FF7DFF53FFFF24] Jul 4 16:59:33 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 16:59:33 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 6. -----Packet Body----- Code: 1. Identifier: 3. Length: 6. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Received a EAPOL packet. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,NOT a Eapol-start. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,PacketType: EAPOL-PACKET. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,EAP Type: Response. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Resource exists. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:12,Code Type: eap_ttls. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Sent EAP Msg to 1X-Queue. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,End processing the packet received. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0017-a4e1-2c86 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 60. -----Packet Body----- Code: 2. Identifier: 3. Length: 60. Jul 4 16:59:34 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: EAP MD5-Challenge. Jul 4 16:59:35 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=EAP auth request Index = 12, ulParam3=2181963444] Jul 4 16:59:35 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 16:59:35 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 16:59:35 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [79 EAP-Message ] [62] [0203003C15FF00000032160301002D010000290301FFFF2D38FF3C284F79FFFF60FF7D2C4B6371FF710AFFFFFF0139575AFF62630A000002000A0100] [80 Message-Autheticator ] [18] [00000000000000000000000000000000] [4 NAS-IP-Address ] [6 ] [192.168.0.101] [32 NAS-Identifier ] [6 ] [4500] [5 NAS-Port ] [6 ] [268533761] [61 NAS-Port-Type ] [6 ] [15] Jul 4 16:59:36 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [31 Caller-ID ] [16] [303031372D613465312D32633836] [24 State ] [18] [FF4D23FFFF6B7E7424FF7DFF53FFFF24] Jul 4 16:59:36 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[50], RetryTimes=[0], Code=[1], Length=[179] Jul 4 16:59:36 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 16:59:37 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 01 32 00 fff4d 2e 00 00 27 34 00 00 fff37 00 00 fff12 00 00 01 09 77 69 6e 64 6f 77 73 4f 3e 02 03 00 3c 15 fff00 00 00 32 16 03 01 00 2d 01 00 00 29 03 01 ffffff2d 38 fff3c 28 4f 79 ffffff60 fff7d 2c 4b 63 71 fff71 0a fffffffff01 39 57 5a fff62 63 0a 00 00 02 00 0a 01 00 50 12 1a ffffff 0f fff25 07 34 72 fff1f fff29 40 2d fff04 06 fff fff00 65 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 06 06 00 00 00 02 07 06 00 00 00 01 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 18 12 fff4d 23 ffffff6b 7e 74 24 fff7d fff53 ffffff24 Jul 4 16:59:37 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 826, ulParam3=3372263616] Jul 4 16:59:37 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 16:59:38 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 0b 32 03 3a 30 fffffffff7d fff29 fff7e 01 ffffff ffffff3b 04 08 06 ffffffffffff0c 06 00 00 02 40 06 06 00 00 00 02 07 06 00 00 00 01 0d 06 00 00 00 01 4f fff01 04 02 fff15 fff00 00 02 fff16 03 01 00 4a 02 00 00 46 03 01 46 fffffffffffffff5a ffffff16 4e 01 56 fffffffff62 fff68 2e fffffffff ffffff16 71 ffffff31 59 fff20 51 5e 1c 2b 5b fff 3c fff20 fff38 ffffffffffff17 fff1b ffffff7c fff 04 28 fff3f 0c 6d 33 fff07 0b 00 0a 00 16 03 01 02 77 0b 00 02 73 00 02 70 00 02 6d 30 fff02 69 30 fff01 ffffff03 02 01 02 02 01 01 30 0d 06 09 2a fff48 ffffff0d 01 01 05 05 00 30 6e 31 0b 30 09 06 03 55 04 06 13 02 50 4c 31 13 30 11 06 03 55 04 08 13 0a 53 6f 6d 65 2d 53 74 61 74 65 31 11 30 0f 06 03 55 04 07 13 08 53 7a 63 7a 65 63 69 6e 31 11 30 0f 06 03 55 04 0a 13 08 42 4c 53 74 72 65 61 6d 31 11 30 0f 06 03 55 04 0b 13 08 42 4c 53 74 72 65 61 6d 31 11 30 0f 06 03 55 04 03 13 08 42 4c 53 74 72 65 61 6d 30 1e 17 0d 30 37 4f fff30 34 31 30 31 33 30 33 34 30 5a 17 0d 3 Jul 4 16:59:39 192.168.0.101 4500 RDS/8/DEBUG:- 1 -0 38 30 34 30 39 31 33 30 33 34 30 5a 30 6e 31 0b 30 09 06 03 55 04 06 13 02 50 4c 31 13 30 11 06 03 55 04 08 13 0a 53 6f 6d 65 2d 53 74 61 74 65 31 11 30 0f 06 03 55 04 07 13 08 53 7a 63 7a 65 63 69 6e 31 11 30 0f 06 03 55 04 0a 13 08 42 4c 53 74 72 65 61 6d 31 11 30 0f 06 03 55 04 0b 13 08 42 4c 53 74 72 65 61 6d 31 11 30 0f 06 03 55 04 03 13 08 42 4c 53 74 72 65 61 6d 30 ffffff 30 0d 06 09 2a fff48 ffffff0d 01 01 01 05 00 03 ffffff00 30 ffffff02 ffffff00 ffffff4d 48 42 fff fff1a 18 30 0b ffffff40 72 fffffffff31 6f fff12 3a ffffff1c 53 04 1f 62 fff65 3e 2f 40 fffffffff ffffff02 4d 08 ffffffffffff2f ffffff63 3d ffffff 69 ffffff3c 4c 76 5d ffffffffffff50 19 fff25 34 ffffff3b 14 fffffffff38 51 fff5f 58 fffffffff56 4f ffffff20 37 4f 39 fff26 fffffffff14 fff72 30 42 ffffff11 62 ffffff2e 4d 63 ffffff27 72 38 fff ffffffffffff1b fff06 4c fff63 54 53 02 03 01 00 01 fff17 30 15 30 13 06 03 55 1d 25 04 0c 30 0a Jul 4 16:59:40 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 06 08 2b 06 01 05 05 07 03 01 30 0d 06 09 2a fff 48 ffffff0d 01 01 05 05 00 03 ffffff00 72 ffffff fff48 65 ffffff5b ffffff44 7b 5b fffffffff1b fff 78 29 fff2a 77 11 fff50 fff57 68 2d 26 ffffff4b 2a ffffff11 1f fff79 fffffffff43 fff69 fff18 11 6b fffffffff62 6a 75 65 60 71 3a 09 5a 3a ffffff 41 fffffffff28 ffffff73 4e fff1d 08 ffffff2b 47 fff6f 0b 10 fff1f 6a fff22 35 fff2f 2f ffffff55 ffffffffffffffffff15 67 1f 6e 76 73 fff68 ffffff 71 fffffffffffffff02 3e 68 18 fffffffff16 03 01 00 04 0e 00 00 00 50 12 2e fffffffff5f 7c 4c fff fff30 ffffff35 fff4a fff18 12 fffffffffffffff69 fff7c 3e ffffff62 fff38 ffffff Jul 4 16:59:40 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[11],Length=[826] Jul 4 16:59:41 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [8 Framed-Address ] [6 ] [255.255.255.254] [12 Framed-MTU ] [6 ] [576] [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [13 Framed-Compression ] [6 ] [1] Jul 4 16:59:41 192.168.0.101 4500 RDS/8/DEBUG:- 1 -NULL Jul 4 16:59:41 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 16:59:41 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 734. -----Packet Body----- Code: 1. Identifier: 4. Length: 734. Jul 4 16:59:41 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Received a EAPOL packet. Jul 4 16:59:41 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,NOT a Eapol-start. Jul 4 16:59:41 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,PacketType: EAPOL-PACKET. Jul 4 16:59:41 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,EAP Type: Response. Jul 4 16:59:41 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Resource exists. Jul 4 16:59:42 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:12,Code Type: eap_ttls. Jul 4 16:59:42 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Sent EAP Msg to 1X-Queue. Jul 4 16:59:42 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,End processing the packet received. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0017-a4e1-2c86 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 200. -----Packet Body----- Code: 2. Identifier: 4. Length: 200. Jul 4 16:59:42 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: EAP MD5-Challenge. Jul 4 16:59:42 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=EAP auth request Index = 12, ulParam3=2181960324] Jul 4 16:59:42 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 16:59:42 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 16:59:42 192.168.0.101 4500 RDS/8/DEBUG:- 1 - Jul 4 16:59:42 192.168.0.101 4500 RDS/8/DEBUG:- 1 -NULL Jul 4 16:59:43 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[51], RetryTimes=[0], Code=[1], Length=[319] Jul 4 16:59:43 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 16:59:44 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 01 33 01 3f fff47 00 00 fff4e 00 00 fff6e 00 00 fff39 00 00 01 09 77 69 6e 64 6f 77 73 4f fff02 04 00 fff15 fff00 00 00 fff16 03 01 00 fff10 00 00 fff00 fff14 fffffffff36 08 fff3d 1b fff4d fff fff06 fff4f 44 7c ffffffffffff01 ffffff1e fff50 fff61 fff65 fffffffff1e 3a 49 38 28 77 63 0e 08 61 fff15 7d fff35 fff6e fffffffff37 fffffffff39 fff1a 3e fff5f 31 fff7d 7b 69 71 32 48 fffffffff fff7c 34 fffffffffffffff61 fffffffff1a 0d 5e fff fffffffff2f 5f 2e 51 21 ffffff3e fff3c 48 fff0c 0b 7b 70 25 6f 19 7b ffffff38 63 fff52 fff15 fff fff7b ffffff14 03 01 00 01 01 16 03 01 00 28 fff fff07 63 fff68 fff5c 31 05 fff09 1d ffffffffffff fff53 04 33 fff5a fff2c 72 62 2c 1f 06 12 ffffff fff00 1f 75 fffffffff50 12 fff39 7d fffffffff21 42 ffffff0e 12 5e ffffff25 04 06 ffffff00 65 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 06 06 00 00 00 02 07 06 00 00 00 01 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 18 12 fff ffffffffffff69 fff7c 3e ffffff62 fff38 ffffff Jul 4 16:59:44 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 149, ulParam3=3372263616] Jul 4 16:59:44 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 16:59:45 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 0b 33 00 ffffff06 06 fff23 7f fffffffff6b 3e 47 22 7c fff60 08 06 ffffffffffff0c 06 00 00 02 40 06 06 00 00 00 02 07 06 00 00 00 01 0d 06 00 00 00 01 4f 3f 01 05 00 3d 15 fff00 00 00 33 14 03 01 00 01 01 16 03 01 00 28 08 17 ffffff79 fff58 12 56 fff4d fffffffff18 57 03 22 4f 29 32 fff69 fff0d 77 fffffffff15 fff0a 36 fff57 2e fff3c 7e 4d 50 12 27 1e 70 fffffffff7a ffffff41 fffffffff fff64 36 18 12 ffffff72 fff39 fffffffff66 2a 75 0d 59 fff71 73 Jul 4 16:59:45 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[11],Length=[149] Jul 4 16:59:45 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [8 Framed-Address ] [6 ] [255.255.255.254] [12 Framed-MTU ] [6 ] [576] [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [13 Framed-Compression ] [6 ] [1] [79 EAP-Message ] [63] [0105003D15FF0000003314030100010116030100280817FFFF79FF581256FF4DFFFFFF185703224F2932FF69FF0D77FFFFFF15FF0A36FF572EFF3C7E4D] Jul 4 16:59:46 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [80 Message-Autheticator ] [18] [271E70FFFFFF7AFFFF41FFFFFFFF6436] [24 State ] [18] [FFFF72FF39FFFFFF662A750D59FF7173] Jul 4 16:59:46 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 16:59:46 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 61. -----Packet Body----- Code: 1. Identifier: 5. Length: 61. Jul 4 16:59:46 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Received a EAPOL packet. Jul 4 16:59:46 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,NOT a Eapol-start. Jul 4 16:59:46 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,PacketType: EAPOL-PACKET. Jul 4 16:59:46 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:0,EAP Type: Response. Jul 4 16:59:46 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Resource exists. Jul 4 16:59:47 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Auth:12,Code Type: eap_ttls. Jul 4 16:59:47 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12,Sent EAP Msg to 1X-Queue. Jul 4 16:59:47 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,End processing the packet received. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0017-a4e1-2c86 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 71. -----Packet Body----- Code: 2. Identifier: 5. Length: 71. Jul 4 16:59:47 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: EAP MD5-Challenge. Jul 4 16:59:47 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=EAP auth request Index = 12, ulParam3=2181963444] Jul 4 16:59:47 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 16:59:47 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 16:59:48 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [79 EAP-Message ] [73] [0205004715FF0000003D1703010038315E06FF6314FF1DFF4A6B63FFFF76FFFF1DFF11FF11FF45FF0AFFFFFF1DFF383108FF21584FFFFF022538FF2D17FF18434D58FF55FFFFFFFFFFCC] [80 Message-Autheticator ] [18] [00000000000000000000000000000000] [4 NAS-IP-Address ] [6 ] [192.168.0.101] [32 NAS-Identifier ] [6 ] [4500] [5 NAS-Port ] [6 ] [268533761] [61 NAS-Port-Type ] [6 ] [15] Jul 4 16:59:48 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [31 Caller-ID ] [16] [303031372D613465312D32633836] [24 State ] [18] [FFFF72FF39FFFFFF662A750D59FF7173] Jul 4 16:59:49 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[52], RetryTimes=[0], Code=[1], Length=[190] Jul 4 16:59:49 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 16:59:49 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 01 34 00 fff66 5f 00 00 fff5b 00 00 0b 3e 00 00 1b 31 00 00 01 09 77 69 6e 64 6f 77 73 4f 49 02 05 00 47 15 fff00 00 00 3d 17 03 01 00 38 31 5e 06 fff63 14 fff1d fff4a 6b 63 ffffff76 ffffff1d fff11 fff11 fff45 fff0a fffffffff1d fff38 31 08 fff21 58 4f ffffff02 25 38 fff2d 17 fff18 43 4d 58 fff55 fffffffff50 12 ffffffffffffffffffffffff 3f 3c 01 54 6c 68 58 fff04 06 ffffff00 65 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 06 06 00 00 00 02 07 06 00 00 00 01 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 18 12 ffffff 72 fff39 fffffffff66 2a 75 0d 59 fff71 73 Jul 4 16:59:49 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 199, ulParam3=3372263616] Jul 4 16:59:50 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 16:59:50 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 02 34 00 fff48 ffffff39 51 5a 5f fff02 5e ffffff 4d 42 fff46 08 06 ffffffffffff0c 06 00 00 02 40 06 06 00 00 00 02 07 06 00 00 00 01 0d 06 00 00 00 01 1a 3a 00 00 01 37 11 34 fff02 fff63 32 73 fff1e 4b 03 fff74 fff35 4d 0b fff4f 32 57 7b fff fff53 fff3b 6e 57 58 ffffff10 5c fff10 fffffffff fff47 17 fff42 4f ffffff6d 6e 4b 1a 1a 3a 00 00 01 37 10 34 fff6f 02 fff77 fff3f 26 fff20 fff1c fff2f fff5c 38 63 6a 7b 4e 02 2e 79 ffffff45 fff 3c 4c 75 fff27 ffffff1b 5d fff26 2f ffffffffffff fff15 45 fffffffff4f 06 03 05 00 04 50 12 0b fff fffffffffffffff5f fff40 58 2e 33 6a 20 fff01 09 77 69 6e 64 6f 77 73 Jul 4 16:59:50 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[2],Length=[199] Jul 4 16:59:51 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [8 Framed-Address ] [6 ] [255.255.255.254] [12 Framed-MTU ] [6 ] [576] [6 Service-Type ] [6 ] [2] [7 Framed-Protocol ] [6 ] [1] [13 Framed-Compression ] [6 ] [1] [79 EAP-Message ] [6 ] [03050004] Jul 4 16:59:51 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [80 Message-Autheticator ] [18] [0BFFFFFFFFFFFF5FFF40582E336A20FFFFFFC3] [1 User-name ] [9 ] [windows] Jul 4 16:59:51 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=Account request Index = 12, ulParam3=0] Jul 4 16:59:51 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 16:59:51 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 16:59:52 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [32 NAS-Identifier ] [6 ] [4500] [5 NAS-Port ] [6 ] [268533761] [61 NAS-Port-Type ] [6 ] [15] [31 Caller-ID ] [16] [303031372D613465312D32633836] [40 Acct-Status-Type ] [6 ] [1] [45 Acct-Authentic ] [6 ] [1] Jul 4 16:59:52 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [44 Acct-Session-Id ] [15] [110706041659a] [4 NAS-IP-Address ] [6 ] [192.168.0.101] [55 Event-Timestamp ] [6 ] [1183568368] Jul 4 16:59:52 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[81], RetryTimes=[0], Code=[4], Length=[102] Jul 4 16:59:52 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 16:59:53 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 04 51 00 66 fff70 0f 2d 55 fff49 4c 7a 17 fff63 31 fff5a 37 01 09 77 69 6e 64 6f 77 73 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 28 06 00 00 00 01 2d 06 00 00 00 01 2c 0f 31 31 30 37 30 36 30 34 31 36 35 39 61 04 06 ffffff00 65 37 06 46 fffffffff Jul 4 16:59:53 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 20, ulParam3=3372263616] Jul 4 16:59:53 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 16:59:53 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 05 51 00 14 11 fff1e 43 7e ffffffffffffffffff00 fff65 2e 6d Jul 4 16:59:53 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[5],Length=[20] Jul 4 16:59:53 192.168.0.101 4500 RDS/8/DEBUG:- 1 -NULL Jul 4 16:59:53 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: Auth request ack for succeed, ACM->1X. Jul 4 16:59:53 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Processing node SUCCESS... Jul 4 16:59:53 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Sending EAPoL-Success... Jul 4 16:59:54 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 4. -----Packet Body----- Code: 3. Identifier: 5. Length: 4. Jul 4 16:59:54 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Failed to send EAPoL-Notification... Jul 4 16:59:54 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Processing node WORKING... Jul 4 16:59:54 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 5. -----Packet Body----- Code: 1. Identifier: 1. Length: 5. Jul 4 16:59:54 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 16:59:54 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12, Send shakehanding-pkt without proxy-chk tag Jul 4 16:59:55 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 5. -----Packet Body----- Code: 1. Identifier: 6. Length: 5. Jul 4 16:59:58 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 16:59:58 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12, Send shakehanding-pkt without proxy-chk tag Jul 4 16:59:58 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 5. -----Packet Body----- Code: 1. Identifier: 6. Length: 5. Jul 4 17:00:13 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 5. -----Packet Body----- Code: 1. Identifier: 1. Length: 5. Jul 4 17:00:13 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 17:00:13 192.168.0.101 4500 8021X/8/EVENT:- 1 -Port:23,Auth:12, Send shakehanding-pkt without proxy-chk tag Jul 4 17:00:13 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 5. -----Packet Body----- Code: 1. Identifier: 6. Length: 5. Jul 4 17:00:28 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12, Jul 4 17:00:28 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Processing node LOGOFF... Jul 4 17:00:28 192.168.0.101 4500 8021X/8/Error::- 1 -Port:23,Auth:12, Fail to snd Dhcp release msg when logoff. Jul 4 17:00:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=Account off request Index = 12, ulParam3=0] Jul 4 17:00:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send attribute list: Jul 4 17:00:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [1 User-name ] [9 ] [windows] Jul 4 17:00:28 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [32 NAS-Identifier ] [6 ] [4500] [5 NAS-Port ] [6 ] [268533761] [61 NAS-Port-Type ] [6 ] [15] [31 Caller-ID ] [16] [303031372D613465312D32633836] [40 Acct-Status-Type ] [6 ] [2] [45 Acct-Authentic ] [6 ] [1] Jul 4 17:00:29 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [44 Acct-Session-Id ] [15] [110706041659a] [4 NAS-IP-Address ] [6 ] [192.168.0.101] [55 Event-Timestamp ] [6 ] [1183568428] [46 Acct-Session-Time ] [6 ] [60] [41 Acct-Delay-Time ] [6 ] [0] [42 Acct-Input-Octets ] [6 ] [8915] Jul 4 17:00:29 192.168.0.101 4500 RDS/8/DEBUG:- 1 - [47 Acct-Input-Packets ] [6 ] [95] [43 Acct-Output-Octets ] [6 ] [8539] [48 Acct-Output-Packets ] [6 ] [117] [52 Acct_Input_Gigawords ] [6 ] [0] [53 Acct_Output_Gigawords ] [6 ] [0] [49 Terminate-Cause ] [6 ] [2] Jul 4 17:00:29 192.168.0.101 4500 RDS/8/DEBUG:- 1 -NULL Jul 4 17:00:29 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send: IP=[192.168.0.201], UserIndex=[12], ID=[82], RetryTimes=[0], Code=[4], Length=[156] Jul 4 17:00:29 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Send Raw Pakcet is: Jul 4 17:00:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 04 52 00 fff3a fff04 71 fff3f fff41 fff4f fff15 4f 34 fff3b 01 09 77 69 6e 64 6f 77 73 20 06 34 35 30 30 05 06 10 01 fff01 3d 06 00 00 00 0f 1f 10 30 30 31 37 2d 61 34 65 31 2d 32 63 38 36 28 06 00 00 00 02 2d 06 00 00 00 01 2c 0f 31 31 30 37 30 36 30 34 31 36 35 39 61 04 06 ffffff00 65 37 06 46 ffffff2c 2e 06 00 00 00 3c 29 06 00 00 00 00 2a 06 00 00 22 fff2f 06 00 00 00 5f 2b 06 00 00 21 5b 30 06 00 00 00 75 34 06 00 00 00 00 35 06 00 00 00 00 31 06 00 00 00 02 Jul 4 17:00:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Recv MSG,[MsgType=PKT response Index = 20, ulParam3=3372263616] Jul 4 17:00:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive Raw Packet is: Jul 4 17:00:30 192.168.0.101 4500 RDS/8/DEBUG:- 1 - 05 52 00 14 78 ffffff2d 56 fff27 ffffff0b fff12 fffffffff56 Jul 4 17:00:31 192.168.0.101 4500 RDS/8/DEBUG:- 1 -Receive:IP=[192.168.0.201],Code=[5],Length=[20] Jul 4 17:00:31 192.168.0.101 4500 RDS/8/DEBUG:- 1 -NULL Jul 4 17:00:31 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Msg: Release request ack, ACM->1X. Jul 4 17:00:31 192.168.0.101 4500 8021X/8/EVENT:- 1 -Auth:12,Sending EAPoL-Failure... Jul 4 17:00:31 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0017-a4e1-2c86 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 7. -----Packet Body----- Code: 4. Identifier: 7. Length: 7. Jul 4 17:00:43 192.168.0.101 4500 8021X/8/PACKET:- 1 -Port:23,Transmitted a packet. ---Verbose information of the packet--- Destination Mac Address: 0180-c200-0003 Source Mac Address: 0018-6e46-6040 Mac Frame Type: 888e. Protocol Version ID: 1. Packet Type: 0. Packet Length: 5. -----Packet Body----- Code: 1. Identifier: 1. Length: 5.
participants (1)
-
Lech Karol Pawłaszek