Alan DeKok wrote:
Is this a bug? As the detail file is correct, it does imply this isn't a
network or frontend problem.
The detail file can't be "correct", it's just a blind dump of packets.
Well yeah - but it does mean FreeRADIUS received the data and it is
consistent with what happened (that's something) - it just didn't update
radutmp correctly.
I suggest running the server in debugging mode to see what the
radutmp module does with the accounting stop record. Since you have
the "detail" files, you can set up a test server, and use the packets
from the detail files to send test "start" and "stop" packets.
Cool. Attached is a dump of a STOP that failed to remove an entry from
radutmp. I see no error that explains why.
This was run as "/usr/sbin/radiusd -f -y -z -A -p 1645 -X"
Thanks!
--
Cheers
Jason Haar
Information Security Manager, Trimble Navigation Ltd.
Phone: +64 3 9635 377 Fax: +64 3 9635 417
PGP Fingerprint: 7A2E 0407 C9A6 CAF6 2B9F 8422 C063 5EBB FE1D 66D1
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 1339 ID 77 with timestamp 4193d1e2
Nothing to do. Sleeping until we see a request.
rad_recv: Accounting-Request packet from host 192.168.1.1:3404, id=78, length=176
User-Name = "dom\\myusername"
NAS-Port = 2027
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-IP-Address = 192.168.1.2
Class = 0x656d706c6f7965652d63657274
Calling-Station-Id = "200.75.33.22"
Acct-Status-Type = Stop
Acct-Input-Octets = 100456
Acct-Output-Octets = 145336
Acct-Session-Id = "B6E00329"
Acct-Session-Time = 126
Acct-Input-Packets = 547
Acct-Output-Packets = 467
Acct-Terminate-Cause = User-Request
Tunnel-Client-Endpoint:0 = "200.75.33.22"
Acct-Authentic = RADIUS
Acct-Delay-Time = 0
NAS-IP-Address = 192.168.1.1
NAS-Port-Type = Virtual
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 1340
modcall[preacct]: module "preprocess" returns noop for request 1340
rlm_acct_unique: Hashing 'NAS-Port = 2027,Client-IP-Address = 192.168.1.2,NAS-IP-Address = 192.168.1.1,Acct-Session-Id = "B6E00329",User-Name = "dom\\myusername"'
rlm_acct_unique: Acct-Unique-Session-ID = "0bb590cf9f6db72b".
modcall[preacct]: module "acct_unique" returns ok for request 1340
rlm_realm: No '@' in User-Name = "dom\myusername", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 1340
modcall[preacct]: module "files" returns noop for request 1340
modcall: group preacct returns ok for request 1340
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 1340
radius_xlat: '/var/log/radius/radacct/192.168.1.1/detail'
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail expands to /var/log/radius/radacct/192.168.1.1/detail
modcall[accounting]: module "detail" returns ok for request 1340
modcall[accounting]: module "unix" returns ok for request 1340
radius_xlat: '/var/log/radius/radutmp'
radius_xlat: 'dom\\myusername'
modcall[accounting]: module "radutmp" returns ok for request 1339
modcall: group accounting returns ok for request 1339
Sending Accounting-Response of id 77 to 192.168.1.1:3404
Finished request 1339
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 1339 ID 77 with timestamp 4193d1e2
Nothing to do. Sleeping until we see a request.