Call fr_printf_log instead of printf
[freeradius.git] / src / main / detail.c
1 /*
2  * detail.c     Process the detail file
3  *
4  * Version:     $Id$
5  *
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.
10  *
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.
15  *
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
19  *
20  * Copyright 2007  The FreeRADIUS server project
21  * Copyright 2007  Alan DeKok <aland@deployingradius.com>
22  */
23
24 #include <freeradius-devel/ident.h>
25 RCSID("$Id$")
26
27 #include <freeradius-devel/radiusd.h>
28 #include <freeradius-devel/modules.h>
29 #include <freeradius-devel/detail.h>
30 #include <freeradius-devel/rad_assert.h>
31
32 #ifdef HAVE_SYS_STAT_H
33 #include <sys/stat.h>
34 #endif
35
36 #include <fcntl.h>
37
38 #define USEC (1000000)
39
40 typedef struct listen_detail_t {
41         int             delay_time; /* should be first entry */
42         char            *filename;
43         char            *filename_work;
44         VALUE_PAIR      *vps;
45         FILE            *fp;
46         int             state;
47         time_t          timestamp;
48         fr_ipaddr_t     client_ip;
49         int             load_factor; /* 1..100 */
50         int             signal;
51
52         int             has_rtt;
53         int             srtt;
54         int             rttvar;
55         struct timeval  last_packet;
56         RADCLIENT       detail_client;
57 } listen_detail_t;
58
59
60 #define STATE_UNOPENED  (0)
61 #define STATE_UNLOCKED  (1)
62 #define STATE_HEADER    (2)
63 #define STATE_READING   (3)
64 #define STATE_QUEUED    (4)
65 #define STATE_RUNNING   (5)
66 #define STATE_NO_REPLY  (6)
67 #define STATE_REPLIED   (7)
68
69 /*
70  *      If we're limiting outstanding packets, then mark the response
71  *      as being sent.
72  */
73 int detail_send(rad_listen_t *listener, REQUEST *request)
74 {
75         int rtt;
76         struct timeval now;
77         listen_detail_t *data = listener->data;
78
79         rad_assert(request->listener == listener);
80         rad_assert(listener->send == detail_send);
81
82         /*
83          *      This request timed out.  Remember that, and tell the
84          *      caller it's OK to read more "detail" file stuff.
85          */
86         if (request->reply->code == 0) {
87                 data->delay_time = 1;
88                 data->signal = 1;
89                 data->state = STATE_NO_REPLY;
90                 radius_signal_self(RADIUS_SIGNAL_SELF_DETAIL);
91                 return 0;
92         }
93
94         /*
95          *      We call gettimeofday a lot.  But here it should be OK,
96          *      because there's nothing else to do.
97          */
98         gettimeofday(&now, NULL);
99
100         /*
101          *      If we haven't sent a packet in the last second, reset
102          *      the RTT.
103          */
104         now.tv_sec -= 1;
105         if (timercmp(&data->last_packet, &now, <)) {
106                 data->has_rtt = FALSE;
107         }
108         now.tv_sec += 1;
109
110         /*
111          *      Only one detail packet may be outstanding at a time,
112          *      so it's safe to update some entries in the detail
113          *      structure.
114          *
115          *      We keep smoothed round trip time (SRTT), but not round
116          *      trip timeout (RTO).  We use SRTT to calculate a rough
117          *      load factor.
118          */
119         rtt = now.tv_sec - request->received.tv_sec;
120         rtt *= USEC;
121         rtt += now.tv_usec;
122         rtt -= request->received.tv_usec;
123
124         /*
125          *      If we're proxying, the RTT is our processing time,
126          *      plus the network delay there and back, plus the time
127          *      on the other end to process the packet.  Ideally, we
128          *      should remove the network delays from the RTT, but we
129          *      don't know what they are.
130          *
131          *      So, to be safe, we over-estimate the total cost of
132          *      processing the packet.
133          */
134         if (!data->has_rtt) {
135                 data->has_rtt = TRUE;
136                 data->srtt = rtt;
137                 data->rttvar = rtt / 2;
138
139         } else {
140                 data->rttvar -= data->rttvar >> 2;
141                 data->rttvar += (data->srtt - rtt);
142                 data->srtt -= data->srtt >> 3;
143                 data->srtt += rtt >> 3;
144         }
145
146         /*
147          *      Calculate the time we wait before sending the next
148          *      packet.
149          *
150          *      rtt / (rtt + delay) = load_factor / 100
151          */
152         data->delay_time = (data->srtt * (100 - data->load_factor)) / (data->load_factor);
153         if (data->delay_time == 0) data->delay_time = USEC / 10;
154
155         /*
156          *      Cap delay at 4 packets/s.  If the end system can't
157          *      handle this, then it's very broken.
158          */
159         if (data->delay_time > (USEC / 4)) data->delay_time= USEC / 4;
160
161 #if 0
162         DEBUG2("RTT %d\tdelay %d", data->srtt, data->delay_time);
163 #endif
164
165         data->last_packet = now;
166         data->signal = 1;
167         data->state = STATE_REPLIED;
168         radius_signal_self(RADIUS_SIGNAL_SELF_DETAIL);
169
170         return 0;
171 }
172
173 int detail_delay(rad_listen_t *listener)
174 {
175         listen_detail_t *data = listener->data;
176
177         if (!data->signal) return 0;
178
179         data->signal = 0;
180
181         return data->delay_time;
182 }
183
184
185 /*
186  *      Open the detail file, if we can.
187  *
188  *      FIXME: create it, if it's not already there, so that the main
189  *      server select() will wake us up if there's anything to read.
190  */
191 static int detail_open(rad_listen_t *this)
192 {
193         struct stat st;
194         listen_detail_t *data = this->data;
195
196         rad_assert(data->state == STATE_UNOPENED);
197         data->delay_time = USEC;
198
199         /*
200          *      Open detail.work first, so we don't lose
201          *      accounting packets.  It's probably better to
202          *      duplicate them than to lose them.
203          *
204          *      Note that we're not writing to the file, but
205          *      we've got to open it for writing in order to
206          *      establish the lock, to prevent rlm_detail from
207          *      writing to it.
208          */
209         this->fd = open(data->filename_work, O_RDWR);
210         if (this->fd < 0) {
211                 DEBUG2("Polling for detail file %s", data->filename);
212
213                 /*
214                  *      Try reading the detail file.  If it
215                  *      doesn't exist, we can't do anything.
216                  *
217                  *      Doing the stat will tell us if the file
218                  *      exists, even if we don't have permissions
219                  *      to read it.
220                  */
221                 if (stat(data->filename, &st) < 0) {
222                         return 0;
223                 }
224
225                 /*
226                  *      Open it BEFORE we rename it, just to
227                  *      be safe...
228                  */
229                 this->fd = open(data->filename, O_RDWR);
230                 if (this->fd < 0) {
231                         radlog(L_ERR, "Failed to open %s: %s",
232                                data->filename, strerror(errno));
233                         return 0;
234                 }
235
236                 /*
237                  *      Rename detail to detail.work
238                  */
239                 if (rename(data->filename, data->filename_work) < 0) {
240                         close(this->fd);
241                         this->fd = -1;
242                         return 0;
243                 }
244         } /* else detail.work existed, and we opened it */
245
246         rad_assert(data->vps == NULL);
247         rad_assert(data->fp == NULL);
248
249         data->state = STATE_UNLOCKED;
250
251         data->client_ip.af = AF_UNSPEC;
252         data->timestamp = 0;
253
254         return 1;
255 }
256
257
258 /*
259  *      FIXME: add a configuration "exit when done" so that the detail
260  *      file reader can be used as a one-off tool to update stuff.
261  *
262  *      The time sequence for reading from the detail file is:
263  *
264  *      t_0             signalled that the server is idle, and we
265  *                      can read from the detail file.
266  *
267  *      t_rtt           the packet has been processed successfully,
268  *                      wait for t_delay to enforce load factor.
269  *                      
270  *      t_rtt + t_delay wait for signal that the server is idle.
271  *      
272  */
273 int detail_recv(rad_listen_t *listener,
274                 RAD_REQUEST_FUNP *pfun, REQUEST **prequest)
275 {
276         char            key[256], value[1024];
277         VALUE_PAIR      *vp, **tail;
278         RADIUS_PACKET   *packet;
279         char            buffer[2048];
280         listen_detail_t *data = listener->data;
281
282         switch (data->state) {
283                 case STATE_UNOPENED:
284         open_file:
285                         rad_assert(listener->fd < 0);
286                         
287                         if (!detail_open(listener)) return 0;
288
289                         rad_assert(data->state == STATE_UNLOCKED);
290                         rad_assert(listener->fd >= 0);
291
292                         /* FALL-THROUGH */
293
294                         /*
295                          *      Try to lock fd.  If we can't, return.
296                          *      If we can, continue.  This means that
297                          *      the server doesn't block while waiting
298                          *      for the lock to open...
299                          */
300                 case STATE_UNLOCKED:
301                         /*
302                          *      Note that we do NOT block waiting for
303                          *      the lock.  We've re-named the file
304                          *      above, so we've already guaranteed
305                          *      that any *new* detail writer will not
306                          *      be opening this file.  The only
307                          *      purpose of the lock is to catch a race
308                          *      condition where the execution
309                          *      "ping-pongs" between radiusd &
310                          *      radrelay.
311                          */
312                         if (rad_lockfd_nonblock(listener->fd, 0) < 0) {
313                                 /*
314                                  *      Close the FD.  The main loop
315                                  *      will wake up in a second and
316                                  *      try again.
317                                  */
318                                 close(listener->fd);
319                                 listener->fd = -1;
320                                 data->state = STATE_UNOPENED;
321                                 return 0;
322                         }
323
324                         data->fp = fdopen(listener->fd, "r");
325                         if (!data->fp) {
326                                 radlog(L_ERR, "FATAL: Failed to re-open detail file %s: %s",
327                                        data->filename, strerror(errno));
328                                 exit(1);
329                         }
330
331                         /*
332                          *      Look for the header
333                          */
334                         data->state = STATE_HEADER;
335                         data->vps = NULL;
336
337                         /* FALL-THROUGH */
338
339                 case STATE_HEADER:
340                 do_header:
341                         if (!data->fp) {
342                                 data->state = STATE_UNOPENED;
343                                 goto open_file;
344                         }
345
346                         {
347                                 struct stat buf;
348                                 
349                                 fstat(listener->fd, &buf);
350                                 if (((off_t) ftell(data->fp)) == buf.st_size) {
351                                         goto cleanup;
352                                 }
353                         }
354
355                         /*
356                          *      End of file.  Delete it, and re-set
357                          *      everything.
358                          */
359                         if (feof(data->fp)) {
360                         cleanup:
361                                 unlink(data->filename_work);
362                                 if (data->fp) fclose(data->fp);
363                                 data->fp = NULL;
364                                 listener->fd = -1;
365                                 data->state = STATE_UNOPENED;
366                                 rad_assert(data->vps == NULL);
367                                 return 0;
368                         }
369
370                         /*
371                          *      Else go read something.
372                          */
373                         break;
374
375                         /*
376                          *      Read more value-pair's, unless we're
377                          *      at EOF.  In that case, queue whatever
378                          *      we have.
379                          */
380                 case STATE_READING:
381                         if (!feof(data->fp)) break;
382                         data->state = STATE_QUEUED;
383
384                         /* FALL-THROUGH */
385
386                 case STATE_QUEUED:
387                         goto alloc_packet;
388
389                         /*
390                          *      We still have an outstanding packet.
391                          *      Don't read any more.
392                          */
393                 case STATE_RUNNING:
394                         return 0;
395
396                         /*
397                          *      If there's no reply, keep
398                          *      retransmitting the current packet
399                          *      forever.
400                          */
401                 case STATE_NO_REPLY:
402                         data->state = STATE_QUEUED;
403                         goto alloc_packet;
404                                 
405                         /*
406                          *      We have a reply.  Clean up the old
407                          *      request, and go read another one.
408                          */
409                 case STATE_REPLIED:
410                         pairfree(&data->vps);
411                         data->state = STATE_HEADER;
412                         goto do_header;
413         }
414         
415         tail = &data->vps;
416         while (*tail) tail = &(*tail)->next;
417
418         /*
419          *      Read a header, OR a value-pair.
420          */
421         while (fgets(buffer, sizeof(buffer), data->fp)) {
422                 /*
423                  *      Badly formatted file: delete it.
424                  *
425                  *      FIXME: Maybe flag an error?
426                  */
427                 if (!strchr(buffer, '\n')) {
428                         pairfree(&data->vps);
429                         goto cleanup;
430                 }
431
432                 /*
433                  *      We're reading VP's, and got a blank line.
434                  *      Queue the packet.
435                  */
436                 if ((data->state == STATE_READING) &&
437                     (buffer[0] == '\n')) {
438                         data->state = STATE_QUEUED;
439                         break;
440                 }
441
442                 /*
443                  *      Look for date/time header, and read VP's if
444                  *      found.  If not, keep reading lines until we
445                  *      find one.
446                  */
447                 if (data->state == STATE_HEADER) {
448                         int y;
449
450                         if (sscanf(buffer, "%*s %*s %*d %*d:%*d:%*d %d", &y)) {
451                                 data->state = STATE_READING;
452                         }
453                         continue;
454                 }
455
456                 /*
457                  *      We have a full "attribute = value" line.
458                  *      If it doesn't look reasonable, skip it.
459                  *
460                  *      FIXME: print an error for badly formatted attributes?
461                  */
462                 if (sscanf(buffer, "%255s = %1023s", key, value) != 2) {
463                         continue;
464                 }
465
466                 /*
467                  *      Skip non-protocol attributes.
468                  */
469                 if (!strcasecmp(key, "Request-Authenticator")) continue;
470
471                 /*
472                  *      Set the original client IP address, based on
473                  *      what's in the detail file.
474                  *
475                  *      Hmm... we don't set the server IP address.
476                  *      or port.  Oh well.
477                  */
478                 if (!strcasecmp(key, "Client-IP-Address")) {
479                         data->client_ip.af = AF_INET;
480                         ip_hton(value, AF_INET, &data->client_ip);
481                         continue;
482                 }
483
484                 /*
485                  *      The original time at which we received the
486                  *      packet.  We need this to properly calculate
487                  *      Acct-Delay-Time.
488                  */
489                 if (!strcasecmp(key, "Timestamp")) {
490                         data->timestamp = atoi(value);
491                         continue;
492                 }
493
494                 /*
495                  *      Read one VP.
496                  *
497                  *      FIXME: do we want to check for non-protocol
498                  *      attributes like radsqlrelay does?
499                  */
500                 vp = NULL;
501                 if ((userparse(buffer, &vp) > 0) &&
502                     (vp != NULL)) {
503                         *tail = vp;
504                         tail = &(vp->next);
505                 }
506         }
507
508         /*
509          *      Some kind of error.
510          *
511          *      FIXME: Leave the file in-place, and warn the
512          *      administrator?
513          */
514         if (ferror(data->fp)) goto cleanup;
515
516         /*
517          *      Process the packet.
518          */
519  alloc_packet:
520         rad_assert(data->state == STATE_QUEUED);
521
522         /*
523          *      We're done reading the file, but we didn't read
524          *      anything.  Clean up, and don't return anything.
525          */
526         if (!data->vps) {
527                 data->state = STATE_HEADER;
528                 return 0;
529         }
530
531         /*
532          *      Allocate the packet.  If we fail, it's a serious
533          *      problem.
534          */
535         packet = rad_alloc(1);
536         if (!packet) {
537                 radlog(L_ERR, "FATAL: Failed allocating memory for detail");
538                 exit(1);
539         }
540
541         memset(packet, 0, sizeof(*packet));
542         packet->sockfd = -1;
543         packet->src_ipaddr.af = AF_INET;
544         packet->src_ipaddr.ipaddr.ip4addr.s_addr = htonl(INADDR_NONE);
545         packet->code = PW_ACCOUNTING_REQUEST;
546         packet->timestamp = time(NULL);
547
548         /*
549          *      Remember where it came from, so that we don't
550          *      proxy it to the place it came from...
551          */
552         if (data->client_ip.af != AF_UNSPEC) {
553                 packet->src_ipaddr = data->client_ip;
554         }
555
556         vp = pairfind(packet->vps, PW_PACKET_SRC_IP_ADDRESS);
557         if (vp) {
558                 packet->src_ipaddr.af = AF_INET;
559                 packet->src_ipaddr.ipaddr.ip4addr.s_addr = vp->vp_ipaddr;
560         } else {
561                 vp = pairfind(packet->vps, PW_PACKET_SRC_IPV6_ADDRESS);
562                 if (vp) {
563                         packet->src_ipaddr.af = AF_INET6;
564                         memcpy(&packet->src_ipaddr.ipaddr.ip6addr,
565                                &vp->vp_ipv6addr, sizeof(vp->vp_ipv6addr));
566                 }
567         }
568
569         vp = pairfind(packet->vps, PW_PACKET_DST_IP_ADDRESS);
570         if (vp) {
571                 packet->dst_ipaddr.af = AF_INET;
572                 packet->dst_ipaddr.ipaddr.ip4addr.s_addr = vp->vp_ipaddr;
573         } else {
574                 vp = pairfind(packet->vps, PW_PACKET_DST_IPV6_ADDRESS);
575                 if (vp) {
576                         packet->dst_ipaddr.af = AF_INET6;
577                         memcpy(&packet->dst_ipaddr.ipaddr.ip6addr,
578                                &vp->vp_ipv6addr, sizeof(vp->vp_ipv6addr));
579                 }
580         }
581
582         /*
583          *      We've got to give SOME value for Id & ports, so that
584          *      the packets can be added to the request queue.
585          *      However, we don't want to keep track of used/unused
586          *      id's and ports, as that's a lot of work.  This hack
587          *      ensures that (if we have real random numbers), that
588          *      there will be a collision on every 2^(16+15+15+24 - 1)
589          *      packets, on average.  That means we can read 2^37
590          *      packets before having a collision, which means it's
591          *      effectively impossible.
592          */
593         packet->id = fr_rand() & 0xffff;
594         packet->src_port = 1024 + (fr_rand() & 0x7fff);
595         packet->dst_port = 1024 + (fr_rand() & 0x7fff);
596
597         packet->dst_ipaddr.af = AF_INET;
598         packet->dst_ipaddr.ipaddr.ip4addr.s_addr = htonl((INADDR_LOOPBACK & ~0xffffff) | (fr_rand() & 0xffffff));
599
600         /*
601          *      If everything's OK, this is a waste of memory.
602          *      Otherwise, it lets us re-send the original packet
603          *      contents, unmolested.
604          */
605         packet->vps = paircopy(data->vps);
606
607         /*
608          *      Look for Acct-Delay-Time, and update
609          *      based on Acct-Delay-Time += (time(NULL) - timestamp)
610          */
611         vp = pairfind(packet->vps, PW_ACCT_DELAY_TIME);
612         if (!vp) {
613                 vp = paircreate(PW_ACCT_DELAY_TIME, PW_TYPE_INTEGER);
614                 rad_assert(vp != NULL);
615                 pairadd(&packet->vps, vp);
616         }
617         if (data->timestamp != 0) {
618                 vp->vp_integer += time(NULL) - data->timestamp;
619         }
620
621         *pfun = rad_accounting;
622
623         if (debug_flag) {
624                 fr_printf_log("detail_recv: Read packet from %s\n", data->filename);
625                 for (vp = packet->vps; vp; vp = vp->next) {
626                         debug_pair(vp);
627                 }
628         }
629
630         /*
631          *      FIXME: many of these checks may not be necessary when
632          *      reading from the detail file.
633          *
634          *      Try again later...
635          */
636         if (!received_request(listener, packet, prequest,
637                               &data->detail_client)) {
638                 rad_free(&packet);
639                 data->state = STATE_NO_REPLY;   /* try again later */
640                 return 0;
641         }
642
643         data->state = STATE_RUNNING;
644
645         return 1;
646 }
647
648
649 /*
650  *      Free detail-specific stuff.
651  */
652 void detail_free(rad_listen_t *this)
653 {
654         listen_detail_t *data = this->data;
655
656         free(data->filename);
657         pairfree(&data->vps);
658
659         if (data->fp != NULL) fclose(data->fp);
660 }
661
662
663 int detail_print(rad_listen_t *this, char *buffer, size_t bufsize)
664 {
665         if (!this->server) {
666                 return snprintf(buffer, bufsize, "%s",
667                                 ((listen_detail_t *)(this->data))->filename);
668         }
669
670         return snprintf(buffer, bufsize, "detail file %s as server %s",
671                         ((listen_detail_t *)(this->data))->filename,
672                         this->server);
673 }
674
675 int detail_encode(UNUSED rad_listen_t *this, UNUSED REQUEST *request)
676 {
677         /*
678          *      We never encode responses "sent to" the detail file.
679          */
680         return 0;
681 }
682
683 int detail_decode(UNUSED rad_listen_t *this, UNUSED REQUEST *request)
684 {
685         /*
686          *      We never decode responses read from the detail file.
687          */
688         return 0;
689 }
690
691
692 static const CONF_PARSER detail_config[] = {
693         { "filename",   PW_TYPE_STRING_PTR,
694           offsetof(listen_detail_t, filename), NULL,  NULL },
695         { "load_factor",   PW_TYPE_INTEGER,
696           offsetof(listen_detail_t, load_factor), NULL, Stringify(10)},
697
698         { NULL, -1, 0, NULL, NULL }             /* end the list */
699 };
700
701
702 /*
703  *      Parse a detail section.
704  */
705 int detail_parse(CONF_SECTION *cs, rad_listen_t *this)
706 {
707         int             rcode;
708         listen_detail_t *data;
709         RADCLIENT       *client;
710         char buffer[2048];
711
712         if (!this->data) {
713                 this->data = rad_malloc(sizeof(*data));
714                 memset(this->data, 0, sizeof(*data));
715         }
716
717         data = this->data;
718         data->delay_time = USEC;
719
720         rcode = cf_section_parse(cs, data, detail_config);
721         if (rcode < 0) {
722                 cf_log_err(cf_sectiontoitem(cs), "Failed parsing listen section");
723                 return -1;
724         }
725
726         if (!data->filename) {
727                 cf_log_err(cf_sectiontoitem(cs), "No detail file specified in listen section");
728                 return -1;
729         }
730
731         if ((data->load_factor < 1) || (data->load_factor > 100)) {
732                 cf_log_err(cf_sectiontoitem(cs), "Load factor must be between 1 and 100");
733                 return -1;
734         }
735
736         snprintf(buffer, sizeof(buffer), "%s.work", data->filename);
737         free(data->filename_work);
738         data->filename_work = strdup(buffer); /* FIXME: leaked */
739
740         data->vps = NULL;
741         data->fp = NULL;
742         data->state = STATE_UNOPENED;
743
744         /*
745          *      Initialize the fake client.
746          */
747         client = &data->detail_client;
748         memset(client, 0, sizeof(*client));
749         client->ipaddr.af = AF_INET;
750         client->ipaddr.ipaddr.ip4addr.s_addr = INADDR_NONE;
751         client->prefix = 0;
752         client->longname = client->shortname = data->filename;
753         client->secret = client->shortname;
754         client->nastype = strdup("none");
755
756         return 0;
757 }