Alan, Here's the output from FR2.1.7. Thanks for you help in advance, Chris ++[exec] returns noop Sending Access-Accept of id 128 to 10.12.80.109 port 32769 User-Name = "isschug" MS-MPPE-Recv-Key = 0x3019b4c8f9f76bb2fc4d69edbc20e98377351a661c0b412c760cd773e3b4c5f5 MS-MPPE-Send-Key = 0x5c7923cd941d8d7bd673b823632371b01435f0590105a5c38211b89b04fdea1b EAP-Message = 0x030b0004 Message-Authenticator = 0x00000000000000000000000000000000 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3021," Reply-Message = "Welcome isschug - student" Finished request 20. Going to the next request Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.7 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.2 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Cleaning up request 11 ID 119 with timestamp +601 Cleaning up request 12 ID 120 with timestamp +601 Cleaning up request 13 ID 121 with timestamp +601 Cleaning up request 14 ID 122 with timestamp +601 Cleaning up request 15 ID 123 with timestamp +601 Cleaning up request 16 ID 124 with timestamp +601 Cleaning up request 17 ID 125 with timestamp +601 Cleaning up request 18 ID 126 with timestamp +601 Cleaning up request 19 ID 127 with timestamp +601 Cleaning up request 20 ID 128 with timestamp +601 Waking up in 0.5 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=144, length=156 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 29,Client-IP-Address = 10.12.80.109,NAS-IP-Address = 10.12.80.109,Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52",User-Name = "isschug"' [acct_unique] Acct-Unique-Session-ID = "5b58953f85bf5074". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "isschug", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop ++[files] returns noop +- entering group accounting {...} [detail] expand: /usr/local/var/log/radius/radacct/%Y-%m-%d/accounting-detail-%H:00 -> /usr/local/var/log/radius/radacct/2009-06-12/accounting-detail-17:00 [detail] /usr/local/var/log/radius/radacct/%Y-%m-%d/accounting-detail-%H:00 expands to /usr/local/var/log/radius/radacct/2009-06-12/accounting-detail-17:00 [detail] expand: %{Packet-Src-IP-Address} - %t -> 10.12.80.109 - Fri Jun 12 17:10:06 2009 ++[detail] returns ok ++? if ("%{Client-IP-Address}" != "129.11.162.17") expand: %{Client-IP-Address} -> 10.12.80.109 ? Evaluating ("%{Client-IP-Address}" != "129.11.162.17") -> TRUE ++? if ("%{Client-IP-Address}" != "129.11.162.17") -> TRUE ++- entering if ("%{Client-IP-Address}" != "129.11.162.17") {...} +++[control] returns ok ++- if ("%{Client-IP-Address}" != "129.11.162.17") returns ok ++[unix] returns ok [radutmp] expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp [radutmp] expand: %{User-Name} -> isschug ++[radutmp] returns ok [attr_filter.accounting_response] expand: %{User-Name} -> isschug attr_filter: Matched entry DEFAULT at line 1 ++[attr_filter.accounting_response] returns updated server home.example.com { } Sending Accounting-Request of id 253 to 129.11.162.17 port 1813 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" Proxy-State = 0x313434 Proxying request 21 to home server 129.11.162.17 port 1813 Sending Accounting-Request of id 253 to 129.11.162.17 port 1813 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" Proxy-State = 0x313434 Going to the next request Waking up in 0.3 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.6 seconds. Waking up in 0.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=144, length=156 Discarding duplicate request from client wism07-1 port 32769 - ID: 144 due to unfinished request 21 Waking up in 0.3 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=144, length=156 Discarding duplicate request from client wism07-1 port 32769 - ID: 144 due to unfinished request 21 Waking up in 0.4 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.4 seconds. Rejecting request 21 due to lack of any response from home server 129.11.162.17 port 1813 Found Post-Proxy-Type server home.example.com { +- entering group Fail {...} [detail.example.com] expand: /usr/local/var/log/radius/radacct/detail.example.com/detail-%Y%m%d:%H -> /usr/local/var/log/radius/radacct/detail.example.com/detail-20090612:17 [detail.example.com] /usr/local/var/log/radius/radacct/detail.example.com/detail-%Y%m%d:%H expands to /usr/local/var/log/radius/radacct/detail.example.com/detail-20090612:17 [detail.example.com] expand: %t -> Fri Jun 12 17:10:06 2009 [detail.example.com] Freeradius-Proxied-To = 129.11.162.17 ++[detail.example.com] returns ok } Sending Accounting-Response of id 144 to 10.12.80.109 port 32769 Finished request 21. Cleaning up request 21 ID 144 with timestamp +611 Going to the next request PROXY: Marking home server 129.11.162.17 port 1813 as zombie (it looks like it is dead). Sending Status-Server of id 225 to 129.11.162.17 port 1813 Message-Authenticator := 0x00000000000000000000000000000000 NAS-Identifier := "Status Check. Are you alive?" Waking up in 0.5 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* detail_recv: Renaming /usr/local/var/log/radius/radacct/detail.example.com/detail-20090612:17 -> /usr/local/var/log/radius/radacct/detail.example.com/detail.work detail_recv: Read packet from /usr/local/var/log/radius/radacct/detail.example.com/detail.work User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" Acct-Unique-Session-Id = "5b58953f85bf5074" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 129.11.162.17 Packet-Original-Timestamp = "Jun 12 2009 17:10:06 BST" Acct-Delay-Time = 7 server home.example.com { +- entering group accounting {...} ++[control] returns noop } # server home.example.com server home.example.com { } Sending Accounting-Request of id 42 to 129.11.162.17 port 1813 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" FreeRADIUS-Proxied-To = 129.11.162.17 Acct-Delay-Time = 7 Proxy-State = 0x3133363235 Proxying request 23 to home server 129.11.162.17 port 1813 Sending Accounting-Request of id 42 to 129.11.162.17 port 1813 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" FreeRADIUS-Proxied-To = 129.11.162.17 Acct-Delay-Time = 7 Proxy-State = 0x3133363235 Going to the next request Waking up in 0.9 seconds. Waking up in 0.1 seconds. Waking up in 0.9 seconds. Waking up in 0.7 seconds. Waking up in 0.5 seconds. Waking up in 0.4 seconds. Waking up in 1.0 seconds. Waking up in 1.0 seconds. Rejecting request 23 due to lack of any response from home server 129.11.162.17 port 1813 Found Post-Proxy-Type server home.example.com { +- entering group Fail {...} [detail.example.com] Suppressing writes to detail file as the request was just read from a detail file. ++[detail.example.com] returns noop } server home.example.com { } # server home.example.com No response configured for request 23. Will retry in 30 seconds Finished request 23. Cleaning up request 23 ID 13625 with timestamp +618 Going to the next request Waking up in 24.4 seconds. Sending Status-Server of id 66 to 129.11.162.17 port 1813 Message-Authenticator := 0x00000000000000000000000000000000 NAS-Identifier := "Status Check. Are you alive?" Waking up in 3.9 seconds. Waking up in 1.5 seconds. detail_recv: Read packet from /usr/local/var/log/radius/radacct/detail.example.com/detail.work User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" Acct-Unique-Session-Id = "5b58953f85bf5074" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 129.11.162.17 Packet-Original-Timestamp = "Jun 12 2009 17:10:06 BST" Acct-Delay-Time = 43 server home.example.com { +- entering group accounting {...} ++[control] returns noop } # server home.example.com server home.example.com { } Sending Accounting-Request of id 13 to 129.11.162.17 port 1813 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" FreeRADIUS-Proxied-To = 129.11.162.17 Acct-Delay-Time = 43 Proxy-State = 0x3534373934 Proxying request 25 to home server 129.11.162.17 port 1813 Sending Accounting-Request of id 13 to 129.11.162.17 port 1813 User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" FreeRADIUS-Proxied-To = 129.11.162.17 Acct-Delay-Time = 43 Proxy-State = 0x3534373934 Going to the next request Waking up in 0.9 seconds. Waking up in 0.1 seconds. Waking up in 0.9 seconds. Waking up in 1.1 seconds. Waking up in 1.0 seconds. Waking up in 1.1 seconds. Waking up in 0.4 seconds. Rejecting request 25 due to lack of any response from home server 129.11.162.17 port 1813 PROXY: Marking home server 129.11.162.17 port 1813 as dead. Found Post-Proxy-Type server home.example.com { +- entering group Fail {...} [detail.example.com] Suppressing writes to detail file as the request was just read from a detail file. ++[detail.example.com] returns noop } server home.example.com { } # server home.example.com No response configured for request 25. Will retry in 30 seconds Finished request 25. Cleaning up request 25 ID 54794 with timestamp +654 Going to the next request Waking up in 0.7 seconds. Waking up in 20.7 seconds. Sending Status-Server of id 81 to 129.11.162.17 port 1813 Message-Authenticator := 0x00000000000000000000000000000000 NAS-Identifier := "Status Check. Are you alive?" Waking up in 3.9 seconds. Waking up in 5.2 seconds. detail_recv: Read packet from /usr/local/var/log/radius/radacct/detail.example.com/detail.work User-Name = "isschug" NAS-Port = 29 NAS-IP-Address = 10.12.80.109 Framed-IP-Address = 129.11.1.138 NAS-Identifier = "WM07-1" Airespace-Wlan-Id = 1 Acct-Session-Id = "4a327dde/00:13:02:8d:f3:1f/52" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3022" Acct-Status-Type = Start Calling-Station-Id = "129.11.1.138" Called-Station-Id = "10.12.80.109" Acct-Unique-Session-Id = "5b58953f85bf5074" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 129.11.162.17 Packet-Original-Timestamp = "Jun 12 2009 17:10:06 BST" Acct-Delay-Time = 79 server home.example.com { +- entering group accounting {...} ++[control] returns noop } # server home.example.com server home.example.com { }
Sending proxied request internally to virtual server. server acct_detail.example.com { +- entering group accounting {...} [detail.example.com] Suppressing writes to detail file as the request was just read from a detail file. ++[detail.example.com] returns noop } # server acct_detail.example.com Going to the next request <<< Received proxied response code 0 from internal virtual server. server home.example.com { } server home.example.com { } # server home.example.com Finished request 27. Cleaning up request 27 ID 8957 with timestamp +690 Going to the next request Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.2 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.7 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.7 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.7 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.1 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. Sending Status-Server of id 3 to 129.11.162.17 port 1813 Message-Authenticator := 0x00000000000000000000000000000000 NAS-Identifier := "Status Check. Are you alive?" Waking up in 0.3 seconds.