Ivan, I doubled the value of cleanup delay in radiusd.conf. This change didn't fix the problem (see below). Thanks for your help, Chris ++[exec] returns noop Sending Access-Accept of id 88 to 10.12.80.109 port 32769 User-Name = "isschug" MS-MPPE-Recv-Key = 0x529e91a0004dce6a6ba2d81c79eeeb98aa3bc7c08880c37d95236064ef786280 MS-MPPE-Send-Key = 0x59005da107574a481d3a7d580821be64872d65153f9767789e79a51f84880994 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 9. 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.0 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.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 1.0 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.8 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=137, 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = "4a323344/00:13:02:8d:f3:1f/49",User-Name = "isschug"' [acct_unique] Acct-Unique-Session-ID = "829905a4bf02a129". ++[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-11: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-11:00 [detail] expand: %{Packet-Src-IP-Address} - %t -> 10.12.80.109 - Fri Jun 12 11:51:48 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 167 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = 0x313337 Proxying request 10 to home server 129.11.162.17 port 1813 Sending Accounting-Request of id 167 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = 0x313337 Going to the next request Waking up in 0.2 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.7 seconds. Waking up in 0.2 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.9 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=137, length=156 Discarding duplicate request from client wism07-1 port 32769 - ID: 137 due to unfinished request 10 Waking up in 0.2 seconds. Polling for detail file /usr/local/var/log/radius/radacct/detail.example.com/detail-*:* Waking up in 0.3 seconds. Cleaning up request 0 ID 79 with timestamp +1750 Cleaning up request 1 ID 80 with timestamp +1750 Cleaning up request 2 ID 81 with timestamp +1750 Cleaning up request 3 ID 82 with timestamp +1750 Cleaning up request 4 ID 83 with timestamp +1750 Cleaning up request 5 ID 84 with timestamp +1750 Cleaning up request 6 ID 85 with timestamp +1750 Waking up in 0.2 seconds. Cleaning up request 7 ID 86 with timestamp +1750 Cleaning up request 8 ID 87 with timestamp +1751 Cleaning up request 9 ID 88 with timestamp +1751 Waking up in 0.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.8 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=137, length=156 Discarding duplicate request from client wism07-1 port 32769 - ID: 137 due to unfinished request 10 Waking up in 0.7 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.4 seconds. rad_recv: Accounting-Request packet from host 10.12.80.109 port 32769, id=137, length=156 Discarding duplicate request from client wism07-1 port 32769 - ID: 137 due to unfinished request 10 Rejecting request 10 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:11 [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:11 [detail.example.com] expand: %t -> Fri Jun 12 11:51:48 2009 [detail.example.com] Freeradius-Proxied-To = 129.11.162.17 ++[detail.example.com] returns ok } Sending Accounting-Response of id 137 to 10.12.80.109 port 32769 Finished request 10. Cleaning up request 10 ID 137 with timestamp +1758 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 86 to 129.11.162.17 port 1813 Message-Authenticator := 0x00000000000000000000000000000000 NAS-Identifier := "Status Check. Are you alive?" Waking up in 0.7 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:11 -> /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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = "829905a4bf02a129" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 129.11.162.17 Packet-Original-Timestamp = "Jun 12 2009 11:51:48 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 179 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = 0x3339353133 Proxying request 12 to home server 129.11.162.17 port 1813 Sending Accounting-Request of id 179 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = 0x3339353133 Going to the next request Waking up in 0.8 seconds. Waking up in 0.1 seconds. Waking up in 0.6 seconds. Waking up in 1.0 seconds. Waking up in 0.5 seconds. Waking up in 0.6 seconds. Waking up in 0.8 seconds. Waking up in 0.9 seconds. Waking up in 0.3 seconds. Rejecting request 12 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 Finished request 12. Cleaning up request 12 ID 39513 with timestamp +1765 Going to the next request Waking up in 0.7 seconds. Waking up in 26.6 seconds. Sending Status-Server of id 141 to 129.11.162.17 port 1813 Message-Authenticator := 0x00000000000000000000000000000000 NAS-Identifier := "Status Check. Are you alive?" Waking up in 3.3 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = "829905a4bf02a129" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 129.11.162.17 Packet-Original-Timestamp = "Jun 12 2009 11:51:48 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 210 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = 0x3232383630 Proxying request 14 to home server 129.11.162.17 port 1813 Sending Accounting-Request of id 210 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = 0x3232383630 Going to the next request Waking up in 0.6 seconds. Waking up in 0.3 seconds. Waking up in 1.1 seconds. Waking up in 1.0 seconds. Waking up in 0.8 seconds. Waking up in 0.7 seconds. Waking up in 1.1 seconds. Rejecting request 14 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 Finished request 14. Cleaning up request 14 ID 22860 with timestamp +1801 Going to the next request Waking up in 25.5 seconds. Sending Status-Server of id 186 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 0.4 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 = "4a323344/00:13:02:8d:f3:1f/49" 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 = "829905a4bf02a129" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 129.11.162.17 Packet-Original-Timestamp = "Jun 12 2009 11:51:48 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 from internal virtual server. server home.example.com { } server home.example.com { } # server home.example.com Finished request 16. Cleaning up request 16 ID 56874 with timestamp +1837 Going to the next request 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-*:*