2 * detail.c Process the detail file
6 * This program is free software; you can redistribute it and/or modify
7 * it under the terms of the GNU General Public License as published by
8 * the Free Software Foundation; either version 2 of the License, or
9 * (at your option) any later version.
11 * This program is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14 * GNU General Public License for more details.
16 * You should have received a copy of the GNU General Public License
17 * along with this program; if not, write to the Free Software
18 * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA
20 * Copyright 2007 The FreeRADIUS server project
21 * Copyright 2007 Alan DeKok <aland@deployingradius.com>
26 #include <freeradius-devel/radiusd.h>
27 #include <freeradius-devel/modules.h>
28 #include <freeradius-devel/detail.h>
29 #include <freeradius-devel/process.h>
30 #include <freeradius-devel/rad_assert.h>
32 #ifdef HAVE_SYS_STAT_H
44 extern bool check_config;
46 #define USEC (1000000)
48 static FR_NAME_NUMBER state_names[] = {
49 { "unopened", STATE_UNOPENED },
50 { "unlocked", STATE_UNLOCKED },
51 { "header", STATE_HEADER },
52 { "reading", STATE_READING },
53 { "queued", STATE_QUEUED },
54 { "running", STATE_RUNNING },
55 { "no-reply", STATE_NO_REPLY },
56 { "replied", STATE_REPLIED },
63 * If we're limiting outstanding packets, then mark the response
66 int detail_send(rad_listen_t *listener, REQUEST *request)
68 #ifdef WITH_DETAIL_THREAD
71 listen_detail_t *data = listener->data;
73 rad_assert(request->listener == listener);
74 rad_assert(listener->send == detail_send);
77 * This request timed out. Remember that, and tell the
78 * caller it's OK to read more "detail" file stuff.
80 if (request->reply->code == 0) {
81 data->delay_time = data->retry_interval * USEC;
83 data->state = STATE_NO_REPLY;
85 RDEBUG("Detail - No response configured for request %d. Will retry in %d seconds",
86 request->number, data->retry_interval);
91 * We call gettimeofday a lot. But it should be OK,
92 * because there's nothing else to do.
94 gettimeofday(&now, NULL);
97 * If we haven't sent a packet in the last second, reset
101 if (timercmp(&data->last_packet, &now, <)) {
102 data->has_rtt = false;
107 * Only one detail packet may be outstanding at a time,
108 * so it's safe to update some entries in the detail
111 * We keep smoothed round trip time (SRTT), but not round
112 * trip timeout (RTO). We use SRTT to calculate a rough
115 rtt = now.tv_sec - request->packet->timestamp.tv_sec;
118 rtt -= request->packet->timestamp.tv_usec;
121 * If we're proxying, the RTT is our processing time,
122 * plus the network delay there and back, plus the time
123 * on the other end to process the packet. Ideally, we
124 * should remove the network delays from the RTT, but we
125 * don't know what they are.
127 * So, to be safe, we over-estimate the total cost of
128 * processing the packet.
130 if (!data->has_rtt) {
131 data->has_rtt = true;
133 data->rttvar = rtt / 2;
136 data->rttvar -= data->rttvar >> 2;
137 data->rttvar += (data->srtt - rtt);
138 data->srtt -= data->srtt >> 3;
139 data->srtt += rtt >> 3;
143 * Calculate the time we wait before sending the next
146 * rtt / (rtt + delay) = load_factor / 100
148 data->delay_time = (data->srtt * (100 - data->load_factor)) / (data->load_factor);
151 * Cap delay at no less than 4 packets/s. If the
152 * end system can't handle this, then it's very
155 if (data->delay_time > (USEC / 4)) data->delay_time= USEC / 4;
157 RDEBUG3("Received response for request %d. Will read the next packet in %d seconds",
158 request->number, data->delay_time / USEC);
160 data->last_packet = now;
162 data->state = STATE_REPLIED;
166 #ifdef WITH_DETAIL_THREAD
167 (void) write(data->child_pipe[1], &c, 1);
169 radius_signal_self(RADIUS_SIGNAL_SELF_DETAIL);
177 * Open the detail file, if we can.
179 * FIXME: create it, if it's not already there, so that the main
180 * server select() will wake us up if there's anything to read.
182 static int detail_open(rad_listen_t *this)
185 listen_detail_t *data = this->data;
187 rad_assert(data->state == STATE_UNOPENED);
188 data->delay_time = USEC;
191 * Open detail.work first, so we don't lose
192 * accounting packets. It's probably better to
193 * duplicate them than to lose them.
195 * Note that we're not writing to the file, but
196 * we've got to open it for writing in order to
197 * establish the lock, to prevent rlm_detail from
200 * This also means that if we're doing globbing,
201 * this file will be read && processed before the
202 * file globbing is done.
204 data->work_fd = open(data->filename_work, O_RDWR);
205 if (data->work_fd < 0) {
212 char const *filename;
215 DEBUG2("Polling for detail file %s", data->filename);
217 memset(&files, 0, sizeof(files));
218 if (glob(data->filename, 0, NULL, &files) != 0) {
225 * Loop over the glob'd files, looking for the
230 for (i = 0; i < files.gl_pathc; i++) {
231 if (stat(files.gl_pathv[i], &st) < 0) continue;
233 if ((i == 0) || (st.st_ctime < chtime)) {
234 chtime = st.st_ctime;
239 if (found < 0) goto noop;
242 * Rename detail to detail.work
244 filename = files.gl_pathv[found];
246 DEBUG("Detail - Renaming %s -> %s", filename, data->filename_work);
247 if (rename(filename, data->filename_work) < 0) {
248 ERROR("Detail - Failed renaming %s to %s: %s",
249 filename, data->filename_work, fr_syserror(errno));
253 globfree(&files); /* Shouldn't be using anything in files now */
256 * And try to open the filename.
258 data->work_fd = open(data->filename_work, O_RDWR);
259 if (data->work_fd < 0) return 0;
261 } /* else detail.work existed, and we opened it */
263 rad_assert(data->vps == NULL);
264 rad_assert(data->fp == NULL);
266 data->state = STATE_UNLOCKED;
268 data->client_ip.af = AF_UNSPEC;
279 * FIXME: add a configuration "exit when done" so that the detail
280 * file reader can be used as a one-off tool to update stuff.
282 * The time sequence for reading from the detail file is:
284 * t_0 signalled that the server is idle, and we
285 * can read from the detail file.
287 * t_rtt the packet has been processed successfully,
288 * wait for t_delay to enforce load factor.
290 * t_rtt + t_delay wait for signal that the server is idle.
293 #ifndef WITH_DETAIL_THREAD
294 static RADIUS_PACKET *detail_poll(rad_listen_t *listener);
296 int detail_recv(rad_listen_t *listener)
298 RADIUS_PACKET *packet;
299 listen_detail_t *data = listener->data;
302 * We may be in the main thread. It needs to update the
303 * timers before we try to read from the file again.
305 if (data->signal) return 0;
307 packet = detail_poll(listener);
308 if (!packet) return -1;
311 * Don't bother doing limit checks, etc.
313 if (!request_receive(listener, packet, &data->detail_client,
316 data->state = STATE_NO_REPLY; /* try again later */
323 int detail_recv(rad_listen_t *listener)
326 RADIUS_PACKET *packet;
327 listen_detail_t *data = listener->data;
330 * Block until there's a packet ready.
332 rcode = read(data->master_pipe[0], &packet, sizeof(packet));
333 if (rcode <= 0) return rcode;
335 rad_assert(packet != NULL);
337 if (!request_receive(listener, packet, &data->detail_client,
341 data->state = STATE_NO_REPLY; /* try again later */
342 (void) write(data->child_pipe[1], &c, 1);
346 * Wait for the child thread to write an answer to the pipe
352 static RADIUS_PACKET *detail_poll(rad_listen_t *listener)
354 char key[256], op[8], value[1024];
357 RADIUS_PACKET *packet;
359 listen_detail_t *data = listener->data;
361 switch (data->state) {
364 rad_assert(data->work_fd < 0);
366 if (!detail_open(listener)) return NULL;
368 rad_assert(data->state == STATE_UNLOCKED);
369 rad_assert(data->work_fd >= 0);
374 * Try to lock fd. If we can't, return.
375 * If we can, continue. This means that
376 * the server doesn't block while waiting
377 * for the lock to open...
381 * Note that we do NOT block waiting for
382 * the lock. We've re-named the file
383 * above, so we've already guaranteed
384 * that any *new* detail writer will not
385 * be opening this file. The only
386 * purpose of the lock is to catch a race
387 * condition where the execution
388 * "ping-pongs" between radiusd &
391 if (rad_lockfd_nonblock(data->work_fd, 0) < 0) {
393 * Close the FD. The main loop
394 * will wake up in a second and
397 close(data->work_fd);
399 data->state = STATE_UNOPENED;
403 data->fp = fdopen(data->work_fd, "r");
405 ERROR("FATAL: Failed to re-open detail file %s: %s",
406 data->filename, fr_syserror(errno));
411 * Look for the header
413 data->state = STATE_HEADER;
414 data->delay_time = USEC;
423 data->state = STATE_UNOPENED;
430 if (fstat(data->work_fd, &buf) < 0) {
431 ERROR("Failed to stat "
432 "detail file %s: %s",
438 if (((off_t) ftell(data->fp)) == buf.st_size) {
444 * End of file. Delete it, and re-set
447 if (feof(data->fp)) {
449 DEBUG("Detail - unlinking %s",
450 data->filename_work);
451 unlink(data->filename_work);
452 if (data->fp) fclose(data->fp);
455 data->state = STATE_UNOPENED;
456 rad_assert(data->vps == NULL);
458 if (data->one_shot) {
459 INFO("Finished reading \"one shot\" detail file - Exiting");
460 radius_signal_self(RADIUS_SIGNAL_SELF_EXIT);
467 * Else go read something.
472 * Read more value-pair's, unless we're
473 * at EOF. In that case, queue whatever
477 if (data->fp && !feof(data->fp)) break;
478 data->state = STATE_QUEUED;
486 * Periodically check what's going on.
487 * If the request is taking too long,
491 if (time(NULL) < (data->running + data->retry_interval)) {
495 DEBUG("No response to detail request. Retrying");
499 * If there's no reply, keep
500 * retransmitting the current packet
504 data->state = STATE_QUEUED;
508 * We have a reply. Clean up the old
509 * request, and go read another one.
512 pairfree(&data->vps);
513 data->state = STATE_HEADER;
517 fr_cursor_init(&cursor, &data->vps);
520 * Read a header, OR a value-pair.
522 while (fgets(buffer, sizeof(buffer), data->fp)) {
523 data->offset = ftell(data->fp); /* for statistics */
526 * Badly formatted file: delete it.
528 * FIXME: Maybe flag an error?
530 if (!strchr(buffer, '\n')) {
531 pairfree(&data->vps);
536 * We're reading VP's, and got a blank line.
539 if ((data->state == STATE_READING) &&
540 (buffer[0] == '\n')) {
541 data->state = STATE_QUEUED;
546 * Look for date/time header, and read VP's if
547 * found. If not, keep reading lines until we
550 if (data->state == STATE_HEADER) {
553 if (sscanf(buffer, "%*s %*s %*d %*d:%*d:%*d %d", &y)) {
554 data->state = STATE_READING;
560 * We have a full "attribute = value" line.
561 * If it doesn't look reasonable, skip it.
563 * FIXME: print an error for badly formatted attributes?
565 if (sscanf(buffer, "%255s %7s %1023s", key, op, value) != 3) {
566 WARN("Skipping badly formatted line %s",
572 * Should be =, :=, +=, ...
574 if (!strchr(op, '=')) continue;
577 * Skip non-protocol attributes.
579 if (!strcasecmp(key, "Request-Authenticator")) continue;
582 * Set the original client IP address, based on
583 * what's in the detail file.
585 * Hmm... we don't set the server IP address.
588 if (!strcasecmp(key, "Client-IP-Address")) {
589 data->client_ip.af = AF_INET;
590 if (ip_hton(value, AF_INET, &data->client_ip) < 0) {
591 ERROR("Failed parsing Client-IP-Address");
593 pairfree(&data->vps);
600 * The original time at which we received the
601 * packet. We need this to properly calculate
604 if (!strcasecmp(key, "Timestamp")) {
605 data->timestamp = atoi(value);
607 vp = paircreate(data, PW_PACKET_ORIGINAL_TIMESTAMP, 0);
609 vp->vp_date = (uint32_t) data->timestamp;
611 fr_cursor_insert(&cursor, vp);
619 * FIXME: do we want to check for non-protocol
620 * attributes like radsqlrelay does?
623 if ((userparse(data, buffer, &vp) > 0) &&
625 fr_cursor_insert(&cursor, vp);
630 * Some kind of error.
632 * FIXME: Leave the file in-place, and warn the
635 if (ferror(data->fp)) goto cleanup;
641 * Process the packet.
647 * The writer doesn't check that the record was
648 * completely written. If the disk is full, this can
649 * result in a truncated record. When that happens,
652 if (data->state != STATE_QUEUED) {
653 ERROR("Truncated record: treating it as EOF for detail file %s", data->filename_work);
658 * We're done reading the file, but we didn't read
659 * anything. Clean up, and don't return anything.
662 data->state = STATE_HEADER;
663 if (!data->fp || feof(data->fp)) goto cleanup;
668 * Allocate the packet. If we fail, it's a serious
671 packet = rad_alloc(NULL, 1);
673 ERROR("FATAL: Failed allocating memory for detail");
678 memset(packet, 0, sizeof(*packet));
680 packet->src_ipaddr.af = AF_INET;
681 packet->src_ipaddr.ipaddr.ip4addr.s_addr = htonl(INADDR_NONE);
682 packet->code = PW_CODE_ACCOUNTING_REQUEST;
683 gettimeofday(&packet->timestamp, NULL);
686 * Remember where it came from, so that we don't
687 * proxy it to the place it came from...
689 if (data->client_ip.af != AF_UNSPEC) {
690 packet->src_ipaddr = data->client_ip;
693 vp = pairfind(packet->vps, PW_PACKET_SRC_IP_ADDRESS, 0, TAG_ANY);
695 packet->src_ipaddr.af = AF_INET;
696 packet->src_ipaddr.ipaddr.ip4addr.s_addr = vp->vp_ipaddr;
698 vp = pairfind(packet->vps, PW_PACKET_SRC_IPV6_ADDRESS, 0, TAG_ANY);
700 packet->src_ipaddr.af = AF_INET6;
701 memcpy(&packet->src_ipaddr.ipaddr.ip6addr,
702 &vp->vp_ipv6addr, sizeof(vp->vp_ipv6addr));
706 vp = pairfind(packet->vps, PW_PACKET_DST_IP_ADDRESS, 0, TAG_ANY);
708 packet->dst_ipaddr.af = AF_INET;
709 packet->dst_ipaddr.ipaddr.ip4addr.s_addr = vp->vp_ipaddr;
711 vp = pairfind(packet->vps, PW_PACKET_DST_IPV6_ADDRESS, 0, TAG_ANY);
713 packet->dst_ipaddr.af = AF_INET6;
714 memcpy(&packet->dst_ipaddr.ipaddr.ip6addr,
715 &vp->vp_ipv6addr, sizeof(vp->vp_ipv6addr));
720 * Generate packet ID, ports, IP via a counter.
722 packet->id = data->counter & 0xff;
723 packet->src_port = 1024 + ((data->counter >> 8) & 0xff);
724 packet->dst_port = 1024 + ((data->counter >> 16) & 0xff);
726 packet->dst_ipaddr.af = AF_INET;
727 packet->dst_ipaddr.ipaddr.ip4addr.s_addr = htonl((INADDR_LOOPBACK & ~0xffffff) | ((data->counter >> 24) & 0xff));
730 * If everything's OK, this is a waste of memory.
731 * Otherwise, it lets us re-send the original packet
732 * contents, unmolested.
734 packet->vps = paircopy(packet, data->vps);
737 * Prefer the Event-Timestamp in the packet, if it
738 * exists. That is when the event occurred, whereas the
739 * "Timestamp" field is when we wrote the packet to the
740 * detail file, which could have been much later.
742 vp = pairfind(packet->vps, PW_EVENT_TIMESTAMP, 0, TAG_ANY);
744 data->timestamp = vp->vp_integer;
748 * Look for Acct-Delay-Time, and update
749 * based on Acct-Delay-Time += (time(NULL) - timestamp)
751 vp = pairfind(packet->vps, PW_ACCT_DELAY_TIME, 0, TAG_ANY);
753 vp = paircreate(packet, PW_ACCT_DELAY_TIME, 0);
754 rad_assert(vp != NULL);
755 pairadd(&packet->vps, vp);
757 if (data->timestamp != 0) {
758 vp->vp_integer += time(NULL) - data->timestamp;
762 * Set the transmission count.
764 vp = pairfind(packet->vps, PW_PACKET_TRANSMIT_COUNTER, 0, TAG_ANY);
766 vp = paircreate(packet, PW_PACKET_TRANSMIT_COUNTER, 0);
767 rad_assert(vp != NULL);
768 pairadd(&packet->vps, vp);
770 vp->vp_integer = data->tries;
773 fr_printf_log("detail_recv: Read packet from %s\n", data->filename_work);
774 for (vp = fr_cursor_init(&cursor, &packet->vps);
776 vp = fr_cursor_next(&cursor)) {
781 data->state = STATE_RUNNING;
782 data->running = packet->timestamp.tv_sec;
788 * Free detail-specific stuff.
790 void detail_free(rad_listen_t *this)
792 listen_detail_t *data = this->data;
794 #ifdef WITH_DETAIL_THREAD
799 * Mark the child pipes as unusable
801 close(data->child_pipe[0]);
802 close(data->child_pipe[1]);
803 data->child_pipe[0] = -1;
806 * Tell it to stop (interrupting it's sleep)
808 pthread_kill(data->pthread_id, SIGTERM);
811 * Wait for it to acknowledge that it's stopped.
813 (void) read(data->master_pipe[0], &arg, sizeof(arg));
815 close(data->master_pipe[0]);
816 close(data->master_pipe[1]);
818 pthread_join(data->pthread_id, &arg);
822 talloc_free(data->filename);
823 data->filename = NULL;
824 pairfree(&data->vps);
826 if (data->fp != NULL) {
833 int detail_print(rad_listen_t const *this, char *buffer, size_t bufsize)
836 return snprintf(buffer, bufsize, "%s",
837 ((listen_detail_t *)(this->data))->filename);
840 return snprintf(buffer, bufsize, "detail file %s as server %s",
841 ((listen_detail_t *)(this->data))->filename,
847 * Delay while waiting for a file to be ready
849 static int detail_delay(listen_detail_t *data)
851 int delay = (data->poll_interval - 1) * USEC;
854 * Add +/- 0.25s of jitter
856 delay += (USEC * 3) / 4;
857 delay += fr_rand() % (USEC / 2);
859 DEBUG2("Detail listener %s state %s waiting %d.%06d sec",
861 fr_int2str(state_names, data->state, "?"),
862 (delay / USEC), delay % USEC);
868 * Overloaded to return delay times.
870 int detail_encode(UNUSED rad_listen_t *this, UNUSED REQUEST *request)
872 #ifdef WITH_DETAIL_THREAD
875 listen_detail_t *data = this->data;
878 * We haven't sent a packet... delay things a bit.
880 if (!data->signal) return detail_delay(data);
884 DEBUG2("Detail listener %s state %s signalled %d waiting %d.%06d sec",
885 data->filename, fr_int2str(state_names, data->state, "?"),
887 data->delay_time / USEC,
888 data->delay_time % USEC);
890 return data->delay_time;
895 * Overloaded to return "should we fix delay times"
897 int detail_decode(UNUSED rad_listen_t *this, UNUSED REQUEST *request)
899 #ifdef WITH_DETAIL_THREAD
902 listen_detail_t *data = this->data;
909 #ifdef WITH_DETAIL_THREAD
910 static void *detail_handler_thread(void *arg)
914 rad_listen_t *this = arg;
915 listen_detail_t *data = this->data;
918 RADIUS_PACKET *packet;
920 while ((packet = detail_poll(this)) == NULL) {
921 usleep(detail_delay(data));
924 * If we're supposed to exit then tell
925 * the master thread we've exited.
927 if (data->child_pipe[0] < 0) {
929 (void) write(data->master_pipe[1], &packet, sizeof(packet));
935 * Keep retrying forever.
937 * FIXME: cap the retries.
940 (void) write(data->master_pipe[1], &packet, sizeof(packet));
942 rcode = read(data->child_pipe[0], &c, 1);
943 if (rcode < 0) break; /* fatal? */
945 if (data->delay_time > 0) usleep(data->delay_time);
946 } while (data->state != STATE_REPLIED);
954 static const CONF_PARSER detail_config[] = {
955 { "detail", PW_TYPE_FILE_OUTPUT | PW_TYPE_DEPRECATED,
956 offsetof(listen_detail_t, filename), NULL, NULL },
957 { "filename", PW_TYPE_FILE_OUTPUT | PW_TYPE_REQUIRED,
958 offsetof(listen_detail_t, filename), NULL, NULL },
959 { "load_factor", PW_TYPE_INTEGER,
960 offsetof(listen_detail_t, load_factor), NULL, STRINGIFY(10)},
961 { "poll_interval", PW_TYPE_INTEGER,
962 offsetof(listen_detail_t, poll_interval), NULL, STRINGIFY(1)},
963 { "retry_interval", PW_TYPE_INTEGER,
964 offsetof(listen_detail_t, retry_interval), NULL, STRINGIFY(30)},
965 { "one_shot", PW_TYPE_BOOLEAN,
966 offsetof(listen_detail_t, one_shot), NULL, NULL},
967 { "max_outstanding", PW_TYPE_INTEGER,
968 offsetof(listen_detail_t, load_factor), NULL, NULL},
970 { NULL, -1, 0, NULL, NULL } /* end the list */
974 * Parse a detail section.
976 int detail_parse(CONF_SECTION *cs, rad_listen_t *this)
979 listen_detail_t *data;
985 rcode = cf_section_parse(cs, data, detail_config);
987 cf_log_err_cs(cs, "Failed parsing listen section");
992 * We don't do duplicate detection for "detail" sockets.
995 this->synchronous = false;
997 if (!data->filename) {
998 cf_log_err_cs(cs, "No detail file specified in listen section");
1002 if ((data->load_factor < 1) || (data->load_factor > 100)) {
1003 cf_log_err_cs(cs, "Load factor must be between 1 and 100");
1007 if ((data->poll_interval < 1) || (data->poll_interval > 20)) {
1008 cf_log_err_cs(cs, "poll_interval must be between 1 and 20");
1012 if (check_config) return 0;
1014 if (data->max_outstanding == 0) data->max_outstanding = 1;
1017 * If the filename is a glob, use "detail.work" as the
1020 if ((strchr(data->filename, '*') != NULL) ||
1021 (strchr(data->filename, '[') != NULL)) {
1025 WARN("Detail file \"%s\" appears to use file globbing, but it is not supported on this system.",
1028 strlcpy(buffer, data->filename, sizeof(buffer));
1029 p = strrchr(buffer, FR_DIR_SEP);
1035 strlcat(buffer, "detail.work",
1036 sizeof(buffer) - strlen(buffer));
1039 snprintf(buffer, sizeof(buffer), "%s.work", data->filename);
1042 talloc_free(data->filename_work);
1043 data->filename_work = talloc_strdup(this, buffer);
1048 data->state = STATE_UNOPENED;
1049 data->delay_time = data->poll_interval * USEC;
1053 * Initialize the fake client.
1055 client = &data->detail_client;
1056 memset(client, 0, sizeof(*client));
1057 client->ipaddr.af = AF_INET;
1058 client->ipaddr.ipaddr.ip4addr.s_addr = INADDR_NONE;
1060 client->longname = client->shortname = data->filename;
1061 client->secret = client->shortname;
1062 client->nas_type = talloc_strdup(this, "none"); /* Part of 'data' not dynamically allocated */
1064 #ifdef WITH_DETAIL_THREAD
1066 * Create the communication pipes.
1068 if (pipe(data->master_pipe) < 0) {
1069 ERROR("radiusd: Error opening internal pipe: %s",
1070 fr_syserror(errno));
1074 if (pipe(data->child_pipe) < 0) {
1075 ERROR("radiusd: Error opening internal pipe: %s",
1076 fr_syserror(errno));
1080 pthread_create(&data->pthread_id, NULL, detail_handler_thread, this);
1082 this->fd = data->master_pipe[0];