Sun Feb 27 09:29:36 2011 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 172.23.35.62 port 55033, id=0, length=118
        User-Name = "data1"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x0200000a016461746131
        Message-Authenticator = 0x777a37976300dc5696d8712356041a91
Sun Feb 27 09:30:16 2011 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group authorize {...}
Sun Feb 27 09:30:16 2011 : Info: ++[preprocess] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[chap] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[mschap] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[digest] returns noop
Sun Feb 27 09:30:16 2011 : Info: [suffix] No '@' in User-Name = "data1", looking up realm NULL
Sun Feb 27 09:30:16 2011 : Info: [suffix] No such realm "NULL"
Sun Feb 27 09:30:16 2011 : Info: ++[suffix] returns noop
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP packet type response id 0 length 10
Sun Feb 27 09:30:16 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Feb 27 09:30:16 2011 : Info: ++[eap] returns updated
Sun Feb 27 09:30:16 2011 : Info: [files] users: Matched entry data1 at line 79
Sun Feb 27 09:30:16 2011 : Info: ++[files] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[expiration] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[logintime] returns noop
Sun Feb 27 09:30:16 2011 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Sun Feb 27 09:30:16 2011 : Info: ++[pap] returns noop
Sun Feb 27 09:30:16 2011 : Info: Found Auth-Type = EAP
Sun Feb 27 09:30:16 2011 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group authenticate {...}
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP Identity
Sun Feb 27 09:30:16 2011 : Info: [eap] processing type tls
Sun Feb 27 09:30:16 2011 : Info: [tls] Initiate
Sun Feb 27 09:30:16 2011 : Info: [tls] Start returned 1
Sun Feb 27 09:30:16 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 172.23.35.62 port 55033
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "4"
        EAP-Message = 0x010100061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x172e7727172f625187c234eeb4d1267d
Sun Feb 27 09:30:16 2011 : Info: Finished request 0.
Sun Feb 27 09:30:16 2011 : Debug: Going to the next request
Sun Feb 27 09:30:16 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.23.35.62 port 55033, id=1, length=132
        User-Name = "data1"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x020100060304
        State = 0x172e7727172f625187c234eeb4d1267d
        Message-Authenticator = 0xb2ec1201bad493bfbc1ac774e078eb2a
Sun Feb 27 09:30:16 2011 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group authorize {...}
Sun Feb 27 09:30:16 2011 : Info: ++[preprocess] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[chap] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[mschap] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[digest] returns noop
Sun Feb 27 09:30:16 2011 : Info: [suffix] No '@' in User-Name = "data1", looking up realm NULL
Sun Feb 27 09:30:16 2011 : Info: [suffix] No such realm "NULL"
Sun Feb 27 09:30:16 2011 : Info: ++[suffix] returns noop
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP packet type response id 1 length 6
Sun Feb 27 09:30:16 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Feb 27 09:30:16 2011 : Info: ++[eap] returns updated
Sun Feb 27 09:30:16 2011 : Info: [files] users: Matched entry data1 at line 79
Sun Feb 27 09:30:16 2011 : Info: ++[files] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[expiration] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[logintime] returns noop
Sun Feb 27 09:30:16 2011 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Sun Feb 27 09:30:16 2011 : Info: ++[pap] returns noop
Sun Feb 27 09:30:16 2011 : Info: Found Auth-Type = EAP
Sun Feb 27 09:30:16 2011 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group authenticate {...}
Sun Feb 27 09:30:16 2011 : Info: [eap] Request found, released from the list
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP NAK
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Sun Feb 27 09:30:16 2011 : Info: [eap] processing type md5
Sun Feb 27 09:30:16 2011 : Debug: rlm_eap_md5: Issuing Challenge
Sun Feb 27 09:30:16 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 1 to 172.23.35.62 port 55033
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "4"
        EAP-Message = 0x010200160410db56d04fe2358d44f6681e15e9fc8e53
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x172e7727162c735187c234eeb4d1267d
Sun Feb 27 09:30:16 2011 : Info: Finished request 1.
Sun Feb 27 09:30:16 2011 : Debug: Going to the next request
Sun Feb 27 09:30:16 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.23.35.62 port 55033, id=2, length=148
        User-Name = "data1"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x020200160410fe0e9b7e61422c8c4c703135762fd803
        State = 0x172e7727162c735187c234eeb4d1267d
        Message-Authenticator = 0x66bc0b9a2986020c01c35fa01bdba7c5
Sun Feb 27 09:30:16 2011 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group authorize {...}
Sun Feb 27 09:30:16 2011 : Info: ++[preprocess] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[chap] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[mschap] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[digest] returns noop
Sun Feb 27 09:30:16 2011 : Info: [suffix] No '@' in User-Name = "data1", looking up realm NULL
Sun Feb 27 09:30:16 2011 : Info: [suffix] No such realm "NULL"
Sun Feb 27 09:30:16 2011 : Info: ++[suffix] returns noop
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP packet type response id 2 length 22
Sun Feb 27 09:30:16 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Feb 27 09:30:16 2011 : Info: ++[eap] returns updated
Sun Feb 27 09:30:16 2011 : Info: [files] users: Matched entry data1 at line 79
Sun Feb 27 09:30:16 2011 : Info: ++[files] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[expiration] returns noop
Sun Feb 27 09:30:16 2011 : Info: ++[logintime] returns noop
Sun Feb 27 09:30:16 2011 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Sun Feb 27 09:30:16 2011 : Info: ++[pap] returns noop
Sun Feb 27 09:30:16 2011 : Info: Found Auth-Type = EAP
Sun Feb 27 09:30:16 2011 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group authenticate {...}
Sun Feb 27 09:30:16 2011 : Info: [eap] Request found, released from the list
Sun Feb 27 09:30:16 2011 : Info: [eap] EAP/md5
Sun Feb 27 09:30:16 2011 : Info: [eap] processing type md5
Sun Feb 27 09:30:16 2011 : Info: [eap] Freeing handler
Sun Feb 27 09:30:16 2011 : Info: ++[eap] returns ok
Sun Feb 27 09:30:16 2011 : Info: # Executing section post-auth from file /etc/raddb/sites-enabled/default
Sun Feb 27 09:30:16 2011 : Info: +- entering group post-auth {...}
Sun Feb 27 09:30:16 2011 : Info: [reply_log]    expand: /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/radius/radacct/172.23.35.62/reply-detail-20110227
Sun Feb 27 09:30:16 2011 : Info: [reply_log] /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/radius/radacct/172.23.35.62/reply-detail-20110227
Sun Feb 27 09:30:16 2011 : Info: [reply_log]    expand: %t -> Sun Feb 27 09:30:16 2011
Sun Feb 27 09:30:16 2011 : Info: ++[reply_log] returns ok
Sun Feb 27 09:30:16 2011 : Info: ++[exec] returns noop
Sending Access-Accept of id 2 to 172.23.35.62 port 55033
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "4"
        EAP-Message = 0x03020004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "data1"
Sun Feb 27 09:30:16 2011 : Info: Finished request 2.
Sun Feb 27 09:30:16 2011 : Debug: Going to the next request
Sun Feb 27 09:30:16 2011 : Debug: Waking up in 4.9 seconds.
Sun Feb 27 09:30:21 2011 : Info: Cleaning up request 0 ID 0 with timestamp +40
Sun Feb 27 09:30:21 2011 : Info: Cleaning up request 1 ID 1 with timestamp +40
Sun Feb 27 09:30:21 2011 : Info: Cleaning up request 2 ID 2 with timestamp +40
Sun Feb 27 09:30:21 2011 : Info: Ready to process requests.