I've just installed latest fr2.1.10 stable, and testing the stock robust-proxy-accounting. It looks as if when all home servers are down, the detail file is continuously replayed over itself, causing new attributes to be appended on each poll and rapidly increasing the size of the detail log, and other obscurities like Packet-Transmit-Counter being re-set as it thinks each re-play is a new proxied packet. In rlm_detail.c:479 if (request->listener->type == RAD_LISTEN_DETAIL && strcmp(((struct detail_instance *)instance)->detailfile, ((listen_detail_t *)request->listener->data)->filename) == 0) { RDEBUG("Suppressing writes to detail file as the request was just read from a detail file."); return RLM_MODULE_NOOP; } It looks like in the example config, detail-%Y%m%d:%H is used on the detail writer, and detail-*:* is used on the detail listener, which wont match above? So short-term workaround is to just use a single detail file. Rgds Paul --8<---------------- Going to the next request Detail listener /var/log/freeradius/radacct/detail.example.com/detail-*:* state replied signalled 0 waiting 0.005643 sec Detail - unlinking /var/log/freeradius/radacct/detail.example.com/detail.work Detail listener /var/log/freeradius/radacct/detail.example.com/detail-*:* state unopened signalled 0 waiting 1.035186 sec Waking up in 1.0 seconds. Polling for detail file /var/log/freeradius/radacct/detail.example.com/detail-*:* Detail - Renaming /var/log/freeradius/radacct/detail.example.com/detail-20101203:15 -> /var/log/freeradius/radacct/detail.example.com/detail.work detail_recv: Read packet from /var/log/freeradius/radacct/detail.example.com/detail.work Acct-Status-Type = Interim-Update NAS-IP-Address = 192.0.2.1 Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 192.0.2.20 Packet-Original-Timestamp = "Dec 3 2010 15:14:32 GMT" Acct-Delay-Time = 21 Packet-Transmit-Counter = 1 Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 192.0.2.10 Packet-Original-Timestamp = "Dec 3 2010 15:14:39 GMT" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 192.0.2.10 Packet-Original-Timestamp = "Dec 3 2010 15:14:46 GMT" server home.example.com { WARNING: Empty preacct section. Using default return values. # Executing section accounting from file /etc/freeradius/sites-enabled/test +- entering group accounting {...} ++[control] returns noop } # server home.example.com server home.example.com { WARNING: Empty pre-proxy section. Using default return values. }
Sending proxied request internally to virtual server.
server acct_detail.example.com { WARNING: Empty preacct section. Using default return values. # Executing section accounting from file /etc/freeradius/sites-enabled/test +- entering group accounting {...} [detail.example.com] expand: /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H -> /var/log/freeradius/radacct/detail.example.com/detail-20101203:15 [detail.example.com] /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H expands to /var/log/freeradius/radacct/detail.example.com/detail-20101203:15 [detail.example.com] expand: %t -> Fri Dec 3 15:14:56 2010 ++[detail.example.com] returns ok } # server acct_detail.example.com Going to the next request <<< Received proxied response code 5 from internal virtual server. server home.example.com { WARNING: Empty post-proxy section. Using default return values. # Executing section post-proxy from file /etc/freeradius/sites-enabled/test } server home.example.com { } # server home.example.com Finished request 5. ... Cleaning up request 7 ID 25567 with timestamp +37 Going to the next request Detail listener /var/log/freeradius/radacct/detail.example.com/detail-*:* state replied signalled 0 waiting 0.002655 sec Detail - unlinking /var/log/freeradius/radacct/detail.example.com/detail.work Detail listener /var/log/freeradius/radacct/detail.example.com/detail-*:* state unopened signalled 0 waiting 1.146660 sec Waking up in 1.1 seconds. Polling for detail file /var/log/freeradius/radacct/detail.example.com/detail-*:* Detail - Renaming /var/log/freeradius/radacct/detail.example.com/detail-20101203:15 -> /var/log/freeradius/radacct/detail.example.com/detail.work detail_recv: Read packet from /var/log/freeradius/radacct/detail.example.com/detail.work Acct-Status-Type = Interim-Update NAS-IP-Address = 192.0.2.1 Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 192.0.2.20 Packet-Original-Timestamp = "Dec 3 2010 15:14:32 GMT" Acct-Delay-Time = 25 Packet-Transmit-Counter = 1 Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 192.0.2.10 Packet-Original-Timestamp = "Dec 3 2010 15:14:39 GMT" Realm = "acct_realm.example.com" FreeRADIUS-Proxied-To = 192.0.2.10 Packet-Original-Timestamp = "Dec 3 2010 15:14:46 GMT" Proxy-State = 0x3239373330 Packet-Original-Timestamp = "Dec 3 2010 15:14:53 GMT" Proxy-State = 0x3237313737 Packet-Original-Timestamp = "Dec 3 2010 15:14:55 GMT" Proxy-State = 0x3235353637 Packet-Original-Timestamp = "Dec 3 2010 15:14:56 GMT"
It looks like in the example config, detail-%Y%m%d:%H is used on the detail writer, and detail-*:* is used on the detail listener, which wont match above? So short-term workaround is to just use a single detail file.
Following patch submitted to https://bugs.freeradius.org/bugzilla/show_bug.cgi?id=128 --- a/src/modules/rlm_detail/rlm_detail.c +++ b/src/modules/rlm_detail/rlm_detail.c @@ -31,6 +31,7 @@ RCSID("$Id$") #include <sys/stat.h> #include <ctype.h> #include <fcntl.h> +#include <fnmatch.h> #define DIRLEN 8192 @@ -477,8 +478,9 @@ static int do_detail(void *instance, REQUEST *request, RADIUS_PACKET *packet, static int detail_accounting(void *instance, REQUEST *request) { if (request->listener->type == RAD_LISTEN_DETAIL && - strcmp(((struct detail_instance *)instance)->detailfile, - ((listen_detail_t *)request->listener->data)->filename) == 0) { + fnmatch( ((listen_detail_t *)request->listener->data)->filename, + ((struct detail_instance *)instance)->detailfile, + FNM_FILE_NAME | FNM_PERIOD ) == 0) { RDEBUG("Suppressing writes to detail file as the request was just read from a detail file."); return RLM_MODULE_NOOP; }
Paul Sherratt wrote:
I've just installed latest fr2.1.10 stable, and testing the stock robust-proxy-accounting. ...
It looks like in the example config, detail-%Y%m%d:%H is used on the detail writer, and detail-*:* is used on the detail listener, which wont match above? So short-term workaround is to just use a single detail file.
Sounds right. The patch should be in 2.1.11. Alan DeKok.
participants (2)
-
Alan DeKok -
Paul Sherratt