FreeRADIUS, 3com (4500) and Windows Vista.

4 Jul 2007

      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.