In testing the new 2.1.8 for accounting packets I have discovered the following strange situation,

There are 2 radius servers (radius-a and radius-b).

Each server will relay packets it receives to the other server. (Currently only accounting packets are being received)

The packets are collected in detail-relay file.

The packets are then relayed via the sites/enabled/copy-acct-to-home-server config.

What I observe is a single packet being read from the detail-relay.work file on radius-b and being sent radius-a.

I do not see any response from radius-a being returned to radius-b.

After what seems to be about 30 seconds the packet is resent from radius-b to radius-a. Again and again...

On radius-b the following messages are logged (status_check = status-server)....

Mon Jan 4 10:10:15 2010 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Mon Jan 4 10:10:15 2010 : Info: rlm_sql (sql): Attempting to connect to radiusd@localhost:/radius
Mon Jan 4 10:10:15 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0
Mon Jan 4 10:10:15 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1
Mon Jan 4 10:10:15 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2
Mon Jan 4 10:10:15 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3
Mon Jan 4 10:10:15 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4
Mon Jan 4 10:10:15 2010 : Info: Loaded virtual server inner-tunnel
Mon Jan 4 10:10:15 2010 : Info: Loaded virtual server copy-acct-to-home-server
Mon Jan 4 10:10:15 2010 : Info: Loaded virtual server <default>
Mon Jan 4 10:10:15 2010 : Info: Ready to process requests.
Mon Jan 4 10:10:42 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 10:10:42 2010 : Proxy: Received response to status check 5938 (1 in current sequence)
Mon Jan 4 10:11:11 2010 : Proxy: Received response to status check 6013 (2 in current sequence)
Mon Jan 4 10:11:40 2010 : Proxy: Received response to status check 6048 (3 in current sequence)
Mon Jan 4 10:11:40 2010 : Proxy: Marking home server 192.168.1.225 port 1813 alive
Mon Jan 4 10:11:43 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 10:11:43 2010 : Proxy: Received response to status check 6051 (4 in current sequence)
Mon Jan 4 10:11:43 2010 : Proxy: Marking home server 192.168.1.225 port 1813 alive
Mon Jan 4 10:12:13 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 10:12:13 2010 : Proxy: Received response to status check 6086 (5 in current sequence)
Mon Jan 4 10:12:13 2010 : Proxy: Marking home server 192.168.1.225 port 1813 alive
Mon Jan 4 10:12:44 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 10:12:44 2010 : Proxy: Received response to status check 6118 (6 in current sequence)
Mon Jan 4 10:12:44 2010 : Proxy: Marking home server 192.168.1.225 port 1813 alive
Mon Jan 4 10:13:14 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 10:13:14 2010 : Proxy: Received response to status check 6153 (7 in current sequence)
Mon Jan 4 10:13:14 2010 : Proxy: Marking home server 192.168.1.225 port 1813 alive

On radius-a for the same time frame...

Mon Jan 4 10:11:55 2010 : Proxy: Marking home server 192.168.1.226 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 10:11:55 2010 : Proxy: Received response to status check 669399 (6 in current sequence)
Mon Jan 4 10:11:55 2010 : Proxy: Marking home server 192.168.1.226 port 1813 alive

I then tried using the alternate "status_check = request " method, but I think I have it configured incorrectly since it is also not receiving a reply...

Mon Jan 4 11:52:16 2010 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Mon Jan 4 11:52:16 2010 : Info: rlm_sql (sql): Attempting to connect to radiusd@localhost:/radius
Mon Jan 4 11:52:16 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0
Mon Jan 4 11:52:16 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1
Mon Jan 4 11:52:16 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2
Mon Jan 4 11:52:16 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3
Mon Jan 4 11:52:16 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4
Mon Jan 4 11:52:16 2010 : Info: Loaded virtual server inner-tunnel
Mon Jan 4 11:52:16 2010 : Info: Loaded virtual server copy-acct-to-home-server
Mon Jan 4 11:52:16 2010 : Info: Loaded virtual server <default>
Mon Jan 4 11:52:16 2010 : Info: Ready to process requests.
Mon Jan 4 11:52:43 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as zombie (it looks like it is dead).
Mon Jan 4 11:52:44 2010 : Info: [sql] stop packet with zero session length. [user 'test_user_please_reject_me', nas '192.168.1.226']
Mon Jan 4 11:52:47 2010 : Error: No response to status check 5969 for home server 192.168.1.225 port 1813
Mon Jan 4 11:53:13 2010 : Info: [sql] stop packet with zero session length. [user 'test_user_please_reject_me', nas '192.168.1.226']
Mon Jan 4 11:53:16 2010 : Error: No response to status check 6007 for home server 192.168.1.225 port 1813
Mon Jan 4 11:53:43 2010 : Proxy: Marking home server 192.168.1.225 port 1813 as dead.
Mon Jan 4 11:53:46 2010 : Info: [sql] stop packet with zero session length. [user 'test_user_please_reject_me', nas '192.168.1.226']

on radius-a, for status_check=request I added to acct_user,

    test_user_please_reject_me      Auth-Type := Reject
        Reply-Message = "Status check only",
        Fall-Through = No

I suspect I SHOULD be using status_check=status-server.

Which then leads to why my server keeps getting marked as zombie/dead/alive....

It seems like the accounting stop packet being sent is not generating a reply...?

Below is the only packet being sent... again and again....

Mon Jan 4 11:53:45 2010
        Acct-Status-Type = Stop
        User-Name = "not_real_id@somerealm"
        Event-Timestamp = "Dec 31 2009 15:41:36 DST"
        Acct-Delay-Time = 331887
        NAS-Identifier = "ERX-2"
        Acct-Session-Id = "0378168264"
        NAS-IP-Address = 192.168.1.101
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Framed-Compression = None
        ERX-Pppoe-Description = "pppoe 00:1d:68:ec:ee:64"
        Framed-IP-Address = 66.247.201.49
        Framed-IP-Netmask = 255.255.255.255
        ERX-Ingress-Policy-Name = "SOMEREALM_UP"
        ERX-Egress-Policy-Name = "SOMEREALM_DOWN"
        Calling-Station-Id = "ERX-08000000283"
        Acct-Input-Gigawords = 0
        Acct-Input-Octets = 96
        Acct-Output-Gigawords = 0
        Acct-Output-Octets = 60
        ERX-Input-Gigapkts = 0
        Acct-Input-Packets = 0
        ERX-Output-Gigapkts = 0
        Acct-Output-Packets = 0
        NAS-Port-Type = Ethernet
        NAS-Port = 2147483931
        NAS-Port-Id = "GigabitEthernet 8/0.283:283"
        Acct-Authentic = RADIUS
        Acct-Session-Time = 0
        Acct-Terminate-Cause = User-Request
        Proxy-State = 0x3534313734
        Acct-Unique-Session-Id = "038113f04620fe75"
        Timestamp = 1262620425
        Request-Authenticator = Verified

I'm not certain what additional info would be helpful at this point.

Craig Campbell
craig.campbell@ccraft.ca
CampbellCraft Consulting Inc
2 Kenny Court
Whitby, Ontario
Canada
L1R 2L8
905 922-2789