Merge pull request #1859 from njm506/v3.0.x
[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 RCSID("$Id$")
25
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>
31
32 #ifdef HAVE_SYS_STAT_H
33 #include <sys/stat.h>
34 #endif
35
36 #ifdef HAVE_GLOB_H
37 #include <glob.h>
38 #endif
39
40 #include <fcntl.h>
41
42 #ifdef WITH_DETAIL
43
44 #define USEC (1000000)
45
46 static FR_NAME_NUMBER state_names[] = {
47         { "unopened", STATE_UNOPENED },
48         { "unlocked", STATE_UNLOCKED },
49         { "header", STATE_HEADER },
50         { "reading", STATE_READING },
51         { "queued", STATE_QUEUED },
52         { "running", STATE_RUNNING },
53         { "no-reply", STATE_NO_REPLY },
54         { "replied", STATE_REPLIED },
55
56         { NULL, 0 }
57 };
58
59
60 /*
61  *      If we're limiting outstanding packets, then mark the response
62  *      as being sent.
63  */
64 int detail_send(rad_listen_t *listener, REQUEST *request)
65 {
66 #ifdef WITH_DETAIL_THREAD
67         char c = 0;
68 #endif
69         listen_detail_t *data = listener->data;
70
71         rad_assert(request->listener == listener);
72         rad_assert(listener->send == detail_send);
73
74         /*
75          *      This request timed out.  Remember that, and tell the
76          *      caller it's OK to read more "detail" file stuff.
77          */
78         if (request->reply->code == 0) {
79                 data->delay_time = data->retry_interval * USEC;
80                 data->signal = 1;
81                 data->state = STATE_NO_REPLY;
82
83                 RDEBUG("detail (%s): No response to request.  Will retry in %d seconds",
84                        data->name, data->retry_interval);
85         } else {
86                 int rtt;
87                 struct timeval now;
88
89                 RDEBUG("detail (%s): Done %s packet.", data->name, fr_packet_codes[request->packet->code]);
90
91                 /*
92                  *      We call gettimeofday a lot.  But it should be OK,
93                  *      because there's nothing else to do.
94                  */
95                 gettimeofday(&now, NULL);
96
97                 /*
98                  *      If we haven't sent a packet in the last second, reset
99                  *      the RTT.
100                  */
101                 now.tv_sec -= 1;
102                 if (timercmp(&data->last_packet, &now, <)) {
103                         data->has_rtt = false;
104                 }
105                 now.tv_sec += 1;
106
107                 /*
108                  *      Only one detail packet may be outstanding at a time,
109                  *      so it's safe to update some entries in the detail
110                  *      structure.
111                  *
112                  *      We keep smoothed round trip time (SRTT), but not round
113                  *      trip timeout (RTO).  We use SRTT to calculate a rough
114                  *      load factor.
115                  */
116                 rtt = now.tv_sec - request->packet->timestamp.tv_sec;
117                 rtt *= USEC;
118                 rtt += now.tv_usec;
119                 rtt -= request->packet->timestamp.tv_usec;
120
121                 /*
122                  *      If we're proxying, the RTT is our processing time,
123                  *      plus the network delay there and back, plus the time
124                  *      on the other end to process the packet.  Ideally, we
125                  *      should remove the network delays from the RTT, but we
126                  *      don't know what they are.
127                  *
128                  *      So, to be safe, we over-estimate the total cost of
129                  *      processing the packet.
130                  */
131                 if (!data->has_rtt) {
132                         data->has_rtt = true;
133                         data->srtt = rtt;
134                         data->rttvar = rtt / 2;
135
136                 } else {
137                         data->rttvar -= data->rttvar >> 2;
138                         data->rttvar += (data->srtt - rtt);
139                         data->srtt -= data->srtt >> 3;
140                         data->srtt += rtt >> 3;
141                 }
142
143                 /*
144                  *      Calculate the time we wait before sending the next
145                  *      packet.
146                  *
147                  *      rtt / (rtt + delay) = load_factor / 100
148                  */
149                 data->delay_time = (data->srtt * (100 - data->load_factor)) / (data->load_factor);
150
151                 /*
152                  *      Cap delay at no less than 4 packets/s.  If the
153                  *      end system can't handle this, then it's very
154                  *      broken.
155                  */
156                 if (data->delay_time > (USEC / 4)) data->delay_time= USEC / 4;
157
158                 RDEBUG3("detail (%s): Received response for request %d.  Will read the next packet in %d seconds",
159                         data->name, request->number, data->delay_time / USEC);
160
161                 data->last_packet = now;
162                 data->signal = 1;
163                 data->state = STATE_REPLIED;
164                 data->counter++;
165         }
166
167 #ifdef WITH_DETAIL_THREAD
168         if (write(data->child_pipe[1], &c, 1) < 0) {
169                 RERROR("detail (%s): Failed writing ack to reader thread: %s", data->name, fr_syserror(errno));
170         }
171 #else
172         radius_signal_self(RADIUS_SIGNAL_SELF_DETAIL);
173 #endif
174
175         return 0;
176 }
177
178
179 /*
180  *      Open the detail file, if we can.
181  *
182  *      FIXME: create it, if it's not already there, so that the main
183  *      server select() will wake us up if there's anything to read.
184  */
185 static int detail_open(rad_listen_t *this)
186 {
187         struct stat st;
188         listen_detail_t *data = this->data;
189
190         rad_assert(data->state == STATE_UNOPENED);
191         data->delay_time = USEC;
192
193         /*
194          *      Open detail.work first, so we don't lose
195          *      accounting packets.  It's probably better to
196          *      duplicate them than to lose them.
197          *
198          *      Note that we're not writing to the file, but
199          *      we've got to open it for writing in order to
200          *      establish the lock, to prevent rlm_detail from
201          *      writing to it.
202          *
203          *      This also means that if we're doing globbing,
204          *      this file will be read && processed before the
205          *      file globbing is done.
206          */
207         data->fp = NULL;
208         data->work_fd = open(data->filename_work, O_RDWR);
209
210         /*
211          *      Couldn't open it for a reason OTHER than "it doesn't
212          *      exist".  Complain and tell the admin.
213          */
214         if ((data->work_fd < 0) && (errno != ENOENT)) {
215                 ERROR("Failed opening detail file %s: %s",
216                       data->filename_work, fr_syserror(errno));
217                 return 0;
218         }
219
220         /*
221          *      The file doesn't exist.  Poll for it again.
222          */
223         if (data->work_fd < 0) {
224 #ifndef HAVE_GLOB_H
225                 return 0;
226 #else
227                 unsigned int    i;
228                 int             found;
229                 time_t          chtime;
230                 char const      *filename;
231                 glob_t          files;
232
233                 DEBUG2("detail (%s): Polling for detail file", data->name);
234
235                 memset(&files, 0, sizeof(files));
236                 if (glob(data->filename, 0, NULL, &files) != 0) {
237                 noop:
238                         globfree(&files);
239                         return 0;
240                 }
241
242                 /*
243                  *      Loop over the glob'd files, looking for the
244                  *      oldest one.
245                  */
246                 chtime = 0;
247                 found = -1;
248                 for (i = 0; i < files.gl_pathc; i++) {
249                         if (stat(files.gl_pathv[i], &st) < 0) continue;
250
251                         if ((i == 0) || (st.st_ctime < chtime)) {
252                                 chtime = st.st_ctime;
253                                 found = i;
254                         }
255                 }
256
257                 if (found < 0) goto noop;
258
259                 /*
260                  *      Rename detail to detail.work
261                  */
262                 filename = files.gl_pathv[found];
263
264                 DEBUG("detail (%s): Renaming %s -> %s", data->name, filename, data->filename_work);
265                 if (rename(filename, data->filename_work) < 0) {
266                         ERROR("detail (%s): Failed renaming %s to %s: %s",
267                               data->name, filename, data->filename_work, fr_syserror(errno));
268                         goto noop;
269                 }
270
271                 globfree(&files);       /* Shouldn't be using anything in files now */
272
273                 /*
274                  *      And try to open the filename.
275                  */
276                 data->work_fd = open(data->filename_work, O_RDWR);
277                 if (data->work_fd < 0) {
278                         ERROR("Failed opening detail file %s: %s",
279                                         data->filename_work, fr_syserror(errno));
280                         return 0;
281                 }
282 #endif
283         } /* else detail.work existed, and we opened it */
284
285         rad_assert(data->vps == NULL);
286         rad_assert(data->fp == NULL);
287
288         data->state = STATE_UNLOCKED;
289
290         data->client_ip.af = AF_UNSPEC;
291         data->timestamp = 0;
292         data->offset = data->last_offset = data->timestamp_offset = 0;
293         data->packets = 0;
294         data->tries = 0;
295         data->done_entry = false;
296
297         return 1;
298 }
299
300
301 /*
302  *      FIXME: add a configuration "exit when done" so that the detail
303  *      file reader can be used as a one-off tool to update stuff.
304  *
305  *      The time sequence for reading from the detail file is:
306  *
307  *      t_0             signalled that the server is idle, and we
308  *                      can read from the detail file.
309  *
310  *      t_rtt           the packet has been processed successfully,
311  *                      wait for t_delay to enforce load factor.
312  *
313  *      t_rtt + t_delay wait for signal that the server is idle.
314  *
315  */
316 #ifndef WITH_DETAIL_THREAD
317 static RADIUS_PACKET *detail_poll(rad_listen_t *listener);
318
319 int detail_recv(rad_listen_t *listener)
320 {
321         RADIUS_PACKET *packet;
322         listen_detail_t *data = listener->data;
323         RAD_REQUEST_FUNP fun = NULL;
324
325         /*
326          *      We may be in the main thread.  It needs to update the
327          *      timers before we try to read from the file again.
328          */
329         if (data->signal) return 0;
330
331         packet = detail_poll(listener);
332         if (!packet) return -1;
333
334         if (DEBUG_ENABLED2) {
335                 VALUE_PAIR *vp;
336                 vp_cursor_t cursor;
337
338                 DEBUG2("detail (%s): Read packet from %s", data->name, data->filename_work);
339                 for (vp = fr_cursor_init(&cursor, &packet->vps);
340                      vp;
341                      vp = fr_cursor_next(&cursor)) {
342                         debug_pair(vp);
343                 }
344         }
345
346         switch (packet->code) {
347         case PW_CODE_ACCOUNTING_REQUEST:
348                 fun = rad_accounting;
349                 break;
350
351         case PW_CODE_COA_REQUEST:
352         case PW_CODE_DISCONNECT_REQUEST:
353                 fun = rad_coa_recv;
354                 break;
355
356         default:
357                 rad_free(&packet);
358                 data->state = STATE_REPLIED;
359                 return 0;
360         }
361
362         /*
363          *      Don't bother doing limit checks, etc.
364          */
365         if (!request_receive(NULL, listener, packet, &data->detail_client, fun)) {
366                 rad_free(&packet);
367                 data->state = STATE_NO_REPLY;   /* try again later */
368                 return 0;
369         }
370
371         return 1;
372 }
373 #else
374 int detail_recv(rad_listen_t *listener)
375 {
376         char c = 0;
377         ssize_t rcode;
378         RADIUS_PACKET *packet;
379         listen_detail_t *data = listener->data;
380         RAD_REQUEST_FUNP fun = NULL;
381
382         /*
383          *      Block until there's a packet ready.
384          */
385         rcode = read(data->master_pipe[0], &packet, sizeof(packet));
386         if (rcode <= 0) return rcode;
387
388         if (DEBUG_ENABLED2) {
389                 VALUE_PAIR *vp;
390                 vp_cursor_t cursor;
391
392                 DEBUG2("detail (%s): Read packet from %s", data->name, data->filename_work);
393                 for (vp = fr_cursor_init(&cursor, &packet->vps);
394                      vp;
395                      vp = fr_cursor_next(&cursor)) {
396                         debug_pair(vp);
397                 }
398         }
399         rad_assert(packet != NULL);
400
401         switch (packet->code) {
402         case PW_CODE_ACCOUNTING_REQUEST:
403                 fun = rad_accounting;
404                 break;
405
406         case PW_CODE_COA_REQUEST:
407         case PW_CODE_DISCONNECT_REQUEST:
408                 fun = rad_coa_recv;
409                 break;
410
411         default:
412                 data->state = STATE_REPLIED;
413                 goto signal_thread;
414         }
415
416         if (!request_receive(NULL, listener, packet, &data->detail_client, fun)) {
417                 data->state = STATE_NO_REPLY;   /* try again later */
418
419         signal_thread:
420                 rad_free(&packet);
421                 if (write(data->child_pipe[1], &c, 1) < 0) {
422                         ERROR("detail (%s): Failed writing ack to reader thread: %s", data->name,
423                               fr_syserror(errno));
424                 }
425         }
426
427         /*
428          *      Wait for the child thread to write an answer to the pipe
429          */
430         return 0;
431 }
432 #endif
433
434 static RADIUS_PACKET *detail_poll(rad_listen_t *listener)
435 {
436         int             y;
437         char            key[256], op[8], value[1024];
438         vp_cursor_t     cursor;
439         VALUE_PAIR      *vp;
440         RADIUS_PACKET   *packet;
441         char            buffer[2048];
442         listen_detail_t *data = listener->data;
443
444         switch (data->state) {
445         case STATE_UNOPENED:
446 open_file:
447                 rad_assert(data->work_fd < 0);
448
449                 if (!detail_open(listener)) return NULL;
450
451                 rad_assert(data->state == STATE_UNLOCKED);
452                 rad_assert(data->work_fd >= 0);
453
454                 /* FALL-THROUGH */
455
456         /*
457          *      Try to lock fd.  If we can't, return.
458          *      If we can, continue.  This means that
459          *      the server doesn't block while waiting
460          *      for the lock to open...
461          */
462         case STATE_UNLOCKED:
463                 /*
464                  *      Note that we do NOT block waiting for
465                  *      the lock.  We've re-named the file
466                  *      above, so we've already guaranteed
467                  *      that any *new* detail writer will not
468                  *      be opening this file.  The only
469                  *      purpose of the lock is to catch a race
470                  *      condition where the execution
471                  *      "ping-pongs" between radiusd &
472                  *      radrelay.
473                  */
474                 if (rad_lockfd_nonblock(data->work_fd, 0) < 0) {
475                         /*
476                          *      Close the FD.  The main loop
477                          *      will wake up in a second and
478                          *      try again.
479                          */
480                         close(data->work_fd);
481                         data->fp = NULL;
482                         data->work_fd = -1;
483                         data->state = STATE_UNOPENED;
484                         return NULL;
485                 }
486
487                 /*
488                  *      Only open for writing if we're
489                  *      marking requests as completed.
490                  */
491                 data->fp = fdopen(data->work_fd, data->track ? "r+" : "r");
492                 if (!data->fp) {
493                         ERROR("detail (%s): FATAL: Failed to re-open detail file: %s",
494                               data->name, fr_syserror(errno));
495                         fr_exit(1);
496                 }
497
498                 /*
499                  *      Look for the header
500                  */
501                 data->state = STATE_HEADER;
502                 data->delay_time = USEC;
503                 data->vps = NULL;
504
505                 /* FALL-THROUGH */
506
507         case STATE_HEADER:
508         do_header:
509                 data->done_entry = false;
510                 data->timestamp_offset = 0;
511
512                 data->tries = 0;
513                 if (!data->fp) {
514                         data->state = STATE_UNOPENED;
515                         goto open_file;
516                 }
517
518                 {
519                         struct stat buf;
520
521                         if (fstat(data->work_fd, &buf) < 0) {
522                                 ERROR("detail (%s): Failed to stat detail file: %s",
523                                       data->name, fr_syserror(errno));
524
525                                 goto cleanup;
526                         }
527                         if (((off_t) ftell(data->fp)) == buf.st_size) {
528                                 goto cleanup;
529                         }
530                 }
531
532                 /*
533                  *      End of file.  Delete it, and re-set
534                  *      everything.
535                  */
536                 if (feof(data->fp)) {
537                 cleanup:
538                         DEBUG("detail (%s): Unlinking %s", data->name, data->filename_work);
539                         unlink(data->filename_work);
540                         if (data->fp) fclose(data->fp);
541                         data->fp = NULL;
542                         data->work_fd = -1;
543                         data->state = STATE_UNOPENED;
544                         rad_assert(data->vps == NULL);
545
546                         if (data->one_shot) {
547                                 INFO("detail (%s): Finished reading \"one shot\" detail file - Exiting", data->name);
548                                 radius_signal_self(RADIUS_SIGNAL_SELF_EXIT);
549                         }
550
551                         return NULL;
552                 }
553
554                 /*
555                  *      Else go read something.
556                  */
557                 if (!fgets(buffer, sizeof(buffer), data->fp)) {
558                         DEBUG("detail (%s): Failed reading header from file - %s",
559                               data->name, data->filename_work);
560                         goto cleanup;
561                 }
562
563                 /*
564                  *      Badly formatted file: delete it.
565                  */
566                 if (!strchr(buffer, '\n')) {
567                         DEBUG("detail (%s): Invalid line without trailing LF - %s", data->name, buffer);
568                         goto cleanup;
569                 }
570
571                 if (!sscanf(buffer, "%*s %*s %*d %*d:%*d:%*d %d", &y)) {
572                         DEBUG("detail (%s): Failed reading detail file header in line - %s", data->name, buffer);
573                         goto cleanup;
574                 }
575
576                 data->state = STATE_READING;
577                 /* FALL-THROUGH */
578
579
580         /*
581          *      Read more value-pair's, unless we're
582          *      at EOF.  In that case, queue whatever
583          *      we have.
584          */
585         case STATE_READING:
586                 rad_assert(data->fp != NULL);
587
588                 fr_cursor_init(&cursor, &data->vps);
589
590                 /*
591                  *      Read a header, OR a value-pair.
592                  */
593                 while (fgets(buffer, sizeof(buffer), data->fp)) {
594                         data->last_offset = data->offset;
595                         data->offset = ftell(data->fp); /* for statistics */
596
597                         /*
598                          *      Badly formatted file: delete it.
599                          */
600                         if (!strchr(buffer, '\n')) {
601                                 WARN("detail (%s): Skipping line without trailing LF - %s", data->name, buffer);
602                                 fr_pair_list_free(&data->vps);
603                                 goto cleanup;
604                         }
605
606                         /*
607                          *      We're reading VP's, and got a blank line.
608                          *      That indicates the end of an entry.  Queue the
609                          *      packet.
610                          */
611                         if (buffer[0] == '\n') {
612                                 data->state = STATE_QUEUED;
613                                 data->tries = 0;
614                                 data->packets++;
615                                 goto alloc_packet;
616                         }
617
618                         /*
619                          *      We have a full "attribute = value" line.
620                          *      If it doesn't look reasonable, skip it.
621                          *
622                          *      FIXME: print an error for badly formatted attributes?
623                          */
624                         if (sscanf(buffer, "%255s %7s %1023s", key, op, value) != 3) {
625                                 DEBUG("detail (%s): Skipping badly formatted line - %s", data->name, buffer);
626                                 continue;
627                         }
628
629                         /*
630                          *      Should be =, :=, +=, ...
631                          */
632                         if (!strchr(op, '=')) {
633                                 DEBUG("detail (%s): Skipping line without operator - %s", data->name, buffer);
634                                 continue;
635                         }
636
637                         /*
638                          *      Skip non-protocol attributes.
639                          */
640                         if (!strcasecmp(key, "Request-Authenticator")) continue;
641
642                         /*
643                          *      Set the original client IP address, based on
644                          *      what's in the detail file.
645                          *
646                          *      Hmm... we don't set the server IP address.
647                          *      or port.  Oh well.
648                          */
649                         if (!strcasecmp(key, "Client-IP-Address")) {
650                                 data->client_ip.af = AF_INET;
651                                 if (ip_hton(&data->client_ip, AF_INET, value, false) < 0) {
652                                         DEBUG("detail (%s): Failed parsing Client-IP-Address", data->name);
653                                         fr_pair_list_free(&data->vps);
654                                         goto cleanup;
655                                 }
656                                 continue;
657                         }
658
659                         /*
660                          *      The original time at which we received the
661                          *      packet.  We need this to properly calculate
662                          *      Acct-Delay-Time.
663                          */
664                         if (!strcasecmp(key, "Timestamp")) {
665                                 data->timestamp = atoi(value);
666                                 data->timestamp_offset = data->last_offset;
667
668                                 vp = fr_pair_afrom_num(data, PW_PACKET_ORIGINAL_TIMESTAMP, 0);
669                                 if (vp) {
670                                         vp->vp_date = (uint32_t) data->timestamp;
671                                         vp->type = VT_DATA;
672                                         fr_cursor_insert(&cursor, vp);
673                                 }
674                                 continue;
675                         }
676
677                         if (!strcasecmp(key, "Donestamp")) {
678                                 data->timestamp = atoi(value);
679                                 data->done_entry = true;
680                                 continue;
681                         }
682
683                         DEBUG3("detail (%s): Trying to read VP from line - %s", data->name, buffer);
684
685                         /*
686                          *      Read one VP.
687                          *
688                          *      FIXME: do we want to check for non-protocol
689                          *      attributes like radsqlrelay does?
690                          */
691                         vp = NULL;
692                         if ((fr_pair_list_afrom_str(data, buffer, &vp) > 0) &&
693                             (vp != NULL)) {
694                                 fr_cursor_merge(&cursor, vp);
695                         } else {
696                                 DEBUG("detail (%s): Failed reading VP from line - %s", data->name, buffer);
697                                 goto cleanup;
698                         }
699                 }
700
701                 /*
702                  *      The writer doesn't check that the
703                  *      record was completely written.  If the
704                  *      disk is full, this can result in a
705                  *      truncated record which has no trailing
706                  *      blank line.  When that happens, it's a
707                  *      bad record, and we ignore it.
708                  */
709                 if (feof(data->fp)) {
710                         DEBUG("detail (%s): Truncated record: treating it as EOF for detail file %s",
711                               data->name, data->filename_work);
712                         fr_pair_list_free(&data->vps);
713                         goto cleanup;
714                 }
715
716                 /*
717                  *      Some kind of non-eof error.
718                  *
719                  *      FIXME: Leave the file in-place, and warn the
720                  *      administrator?
721                  */
722                 DEBUG("detail (%s): Unknown error, deleting detail file %s",
723                       data->name, data->filename_work);
724                 goto cleanup;
725
726         case STATE_QUEUED:
727                 goto alloc_packet;
728
729         /*
730          *      Periodically check what's going on.
731          *      If the request is taking too long,
732          *      retry it.
733          */
734         case STATE_RUNNING:
735                 if (time(NULL) < (data->running + (int)data->retry_interval)) {
736                         return NULL;
737                 }
738
739                 DEBUG("detail (%s): No response to detail request.  Retrying", data->name);
740                 /* FALL-THROUGH */
741
742         /*
743          *      If there's no reply, keep
744          *      retransmitting the current packet
745          *      forever.
746          */
747         case STATE_NO_REPLY:
748                 data->state = STATE_QUEUED;
749                 goto alloc_packet;
750
751         /*
752          *      We have a reply.  Clean up the old
753          *      request, and go read another one.
754          */
755         case STATE_REPLIED:
756                 if (data->track) {
757                         rad_assert(data->fp != NULL);
758
759                         if (fseek(data->fp, data->timestamp_offset, SEEK_SET) < 0) {
760                                 DEBUG("detail (%s): Failed seeking to timestamp offset: %s",
761                                      data->name, fr_syserror(errno));
762                         } else if (fwrite("\tDone", 1, 5, data->fp) < 5) {
763                                 DEBUG("detail (%s): Failed marking request as done: %s",
764                                      data->name, fr_syserror(errno));
765                         } else if (fflush(data->fp) != 0) {
766                                 DEBUG("detail (%s): Failed flushing marked detail file to disk: %s",
767                                      data->name, fr_syserror(errno));
768                         }
769
770                         if (fseek(data->fp, data->offset, SEEK_SET) < 0) {
771                                 DEBUG("detail (%s): Failed seeking to next detail request: %s",
772                                      data->name, fr_syserror(errno));
773                         }
774                 }
775
776                 fr_pair_list_free(&data->vps);
777                 data->state = STATE_HEADER;
778                 goto do_header;
779         }
780
781         /*
782          *      Process the packet.
783          */
784  alloc_packet:
785         if (data->done_entry) {
786                 DEBUG2("detail (%s): Skipping record for timestamp %lu", data->name, data->timestamp);
787                 fr_pair_list_free(&data->vps);
788                 data->state = STATE_HEADER;
789                 goto do_header;
790         }
791
792         data->tries++;
793
794         /*
795          *      We're done reading the file, but we didn't read
796          *      anything.  Clean up, and don't return anything.
797          */
798         if (!data->vps) {
799                 WARN("detail (%s): Read empty packet from file %s",
800                      data->name, data->filename_work);
801                 data->state = STATE_HEADER;
802                 return NULL;
803         }
804
805         /*
806          *      Allocate the packet.  If we fail, it's a serious
807          *      problem.
808          */
809         packet = rad_alloc(NULL, true);
810         if (!packet) {
811                 ERROR("detail (%s): FATAL: Failed allocating memory for detail", data->name);
812                 fr_exit(1);
813         }
814
815         memset(packet, 0, sizeof(*packet));
816         packet->sockfd = -1;
817         packet->src_ipaddr.af = AF_INET;
818         packet->src_ipaddr.ipaddr.ip4addr.s_addr = htonl(INADDR_NONE);
819
820         /*
821          *      If everything's OK, this is a waste of memory.
822          *      Otherwise, it lets us re-send the original packet
823          *      contents, unmolested.
824          */
825         packet->vps = fr_pair_list_copy(packet, data->vps);
826
827         packet->code = PW_CODE_ACCOUNTING_REQUEST;
828         vp = fr_pair_find_by_num(packet->vps, PW_PACKET_TYPE, 0, TAG_ANY);
829         if (vp) packet->code = vp->vp_integer;
830
831         gettimeofday(&packet->timestamp, NULL);
832
833         /*
834          *      Remember where it came from, so that we don't
835          *      proxy it to the place it came from...
836          */
837         if (data->client_ip.af != AF_UNSPEC) {
838                 packet->src_ipaddr = data->client_ip;
839         }
840
841         vp = fr_pair_find_by_num(packet->vps, PW_PACKET_SRC_IP_ADDRESS, 0, TAG_ANY);
842         if (vp) {
843                 packet->src_ipaddr.af = AF_INET;
844                 packet->src_ipaddr.ipaddr.ip4addr.s_addr = vp->vp_ipaddr;
845                 packet->src_ipaddr.prefix = 32;
846         } else {
847                 vp = fr_pair_find_by_num(packet->vps, PW_PACKET_SRC_IPV6_ADDRESS, 0, TAG_ANY);
848                 if (vp) {
849                         packet->src_ipaddr.af = AF_INET6;
850                         memcpy(&packet->src_ipaddr.ipaddr.ip6addr,
851                                &vp->vp_ipv6addr, sizeof(vp->vp_ipv6addr));
852                         packet->src_ipaddr.prefix = 128;
853                 }
854         }
855
856         vp = fr_pair_find_by_num(packet->vps, PW_PACKET_DST_IP_ADDRESS, 0, TAG_ANY);
857         if (vp) {
858                 packet->dst_ipaddr.af = AF_INET;
859                 packet->dst_ipaddr.ipaddr.ip4addr.s_addr = vp->vp_ipaddr;
860                 packet->dst_ipaddr.prefix = 32;
861         } else {
862                 vp = fr_pair_find_by_num(packet->vps, PW_PACKET_DST_IPV6_ADDRESS, 0, TAG_ANY);
863                 if (vp) {
864                         packet->dst_ipaddr.af = AF_INET6;
865                         memcpy(&packet->dst_ipaddr.ipaddr.ip6addr,
866                                &vp->vp_ipv6addr, sizeof(vp->vp_ipv6addr));
867                         packet->dst_ipaddr.prefix = 128;
868                 }
869         }
870
871         /*
872          *      Generate packet ID, ports, IP via a counter.
873          */
874         packet->id = data->counter & 0xff;
875         packet->src_port = 1024 + ((data->counter >> 8) & 0xff);
876         packet->dst_port = 1024 + ((data->counter >> 16) & 0xff);
877
878         packet->dst_ipaddr.af = AF_INET;
879         packet->dst_ipaddr.ipaddr.ip4addr.s_addr = htonl((INADDR_LOOPBACK & ~0xffffff) | ((data->counter >> 24) & 0xff));
880
881         /*
882          *      Create / update accounting attributes.
883          */
884         if (packet->code == PW_CODE_ACCOUNTING_REQUEST) {
885                 /*
886                  *      Prefer the Event-Timestamp in the packet, if it
887                  *      exists.  That is when the event occurred, whereas the
888                  *      "Timestamp" field is when we wrote the packet to the
889                  *      detail file, which could have been much later.
890                  */
891                 vp = fr_pair_find_by_num(packet->vps, PW_EVENT_TIMESTAMP, 0, TAG_ANY);
892                 if (vp) {
893                         data->timestamp = vp->vp_integer;
894                 }
895
896                 /*
897                  *      Look for Acct-Delay-Time, and update
898                  *      based on Acct-Delay-Time += (time(NULL) - timestamp)
899                  */
900                 vp = fr_pair_find_by_num(packet->vps, PW_ACCT_DELAY_TIME, 0, TAG_ANY);
901                 if (!vp) {
902                         vp = fr_pair_afrom_num(packet, PW_ACCT_DELAY_TIME, 0);
903                         rad_assert(vp != NULL);
904                         fr_pair_add(&packet->vps, vp);
905                 }
906                 if (data->timestamp != 0) {
907                         vp->vp_integer += time(NULL) - data->timestamp;
908                 }
909         }
910
911         /*
912          *      Set the transmission count.
913          */
914         vp = fr_pair_find_by_num(packet->vps, PW_PACKET_TRANSMIT_COUNTER, 0, TAG_ANY);
915         if (!vp) {
916                 vp = fr_pair_afrom_num(packet, PW_PACKET_TRANSMIT_COUNTER, 0);
917                 rad_assert(vp != NULL);
918                 fr_pair_add(&packet->vps, vp);
919         }
920         vp->vp_integer = data->tries;
921
922         data->state = STATE_RUNNING;
923         data->running = packet->timestamp.tv_sec;
924
925         return packet;
926 }
927
928 /*
929  *      Free detail-specific stuff.
930  */
931 void detail_free(rad_listen_t *this)
932 {
933         listen_detail_t *data = this->data;
934
935 #ifdef WITH_DETAIL_THREAD
936         if (!check_config) {
937                 ssize_t ret;
938                 void *arg = NULL;
939
940                 /*
941                  *      Mark the child pipes as unusable
942                  */
943                 close(data->child_pipe[0]);
944                 close(data->child_pipe[1]);
945                 data->child_pipe[0] = -1;
946
947                 /*
948                  *      Tell it to stop (interrupting its sleep)
949                  */
950                 pthread_kill(data->pthread_id, SIGTERM);
951
952                 /*
953                  *      Wait for it to acknowledge that it's stopped.
954                  */
955                 ret = read(data->master_pipe[0], &arg, sizeof(arg));
956                 if (ret < 0) {
957                         ERROR("detail (%s): Reader thread exited without informing the master: %s",
958                               data->name, fr_syserror(errno));
959                 } else if (ret != sizeof(arg)) {
960                         ERROR("detail (%s): Invalid thread pointer received from reader thread during exit",
961                               data->name);
962                         ERROR("detail (%s): Expected %zu bytes, got %zi bytes", data->name, sizeof(arg), ret);
963                 }
964
965                 close(data->master_pipe[0]);
966                 close(data->master_pipe[1]);
967
968                 if (arg) pthread_join(data->pthread_id, &arg);
969         }
970 #endif
971
972         if (data->fp != NULL) {
973                 fclose(data->fp);
974                 data->fp = NULL;
975         }
976 }
977
978
979 int detail_print(rad_listen_t const *this, char *buffer, size_t bufsize)
980 {
981         if (!this->server) {
982                 return snprintf(buffer, bufsize, "%s",
983                                 ((listen_detail_t *)(this->data))->filename);
984         }
985
986         return snprintf(buffer, bufsize, "detail file %s as server %s",
987                         ((listen_detail_t *)(this->data))->filename,
988                         this->server);
989 }
990
991
992 /*
993  *      Delay while waiting for a file to be ready
994  */
995 static int detail_delay(listen_detail_t *data)
996 {
997         int delay = (data->poll_interval - 1) * USEC;
998
999         /*
1000          *      Add +/- 0.25s of jitter
1001          */
1002         delay += (USEC * 3) / 4;
1003         delay += fr_rand() % (USEC / 2);
1004
1005         DEBUG2("detail (%s): Detail listener state %s waiting %d.%06d sec",
1006                data->name,
1007                fr_int2str(state_names, data->state, "?"),
1008                (delay / USEC), delay % USEC);
1009
1010         return delay;
1011 }
1012
1013 /*
1014  *      Overloaded to return delay times.
1015  */
1016 int detail_encode(UNUSED rad_listen_t *this, UNUSED REQUEST *request)
1017 {
1018 #ifdef WITH_DETAIL_THREAD
1019         return 0;
1020 #else
1021         listen_detail_t *data = this->data;
1022
1023         /*
1024          *      We haven't sent a packet... delay things a bit.
1025          */
1026         if (!data->signal) return detail_delay(data);
1027
1028         data->signal = 0;
1029
1030         DEBUG2("detail (%s): Detail listener state %s signalled %d waiting %d.%06d sec",
1031                data->name,
1032                fr_int2str(state_names, data->state, "?"),
1033                data->signal,
1034                data->delay_time / USEC,
1035                data->delay_time % USEC);
1036
1037         return data->delay_time;
1038 #endif
1039 }
1040
1041 /*
1042  *      Overloaded to return "should we fix delay times"
1043  */
1044 int detail_decode(rad_listen_t *this, REQUEST *request)
1045 {
1046 #ifdef WITH_DETAIL_THREAD
1047         listen_detail_t *data = this->data;
1048
1049         RDEBUG("Received %s from detail file %s",
1050                fr_packet_codes[request->packet->code], data->filename_work);
1051
1052         rdebug_pair_list(L_DBG_LVL_1, request, request->packet->vps, "\t");
1053
1054         return 0;
1055 #else
1056         listen_detail_t *data = this->data;
1057
1058         RDEBUG("Received %s from detail file %s",
1059                fr_packet_codes[request->packet->code], data->filename_work);
1060
1061         rdebug_pair_list(L_DBG_LVL_1, request, request->packet->vps, "\t");
1062
1063         return data->signal;
1064 #endif
1065 }
1066
1067
1068 #ifdef WITH_DETAIL_THREAD
1069 static void *detail_handler_thread(void *arg)
1070 {
1071         char c;
1072         rad_listen_t *this = arg;
1073         listen_detail_t *data = this->data;
1074
1075         while (true) {
1076                 RADIUS_PACKET *packet;
1077
1078                 while ((packet = detail_poll(this)) == NULL) {
1079                         usleep(detail_delay(data));
1080
1081                         /*
1082                          *      If we're supposed to exit then tell
1083                          *      the master thread we've exited.
1084                          */
1085                         if (data->child_pipe[0] < 0) {
1086                                 packet = NULL;
1087                                 if (write(data->master_pipe[1], &packet, sizeof(packet)) < 0) {
1088                                         ERROR("detail (%s): Failed writing exit status to master: %s",
1089                                               data->name, fr_syserror(errno));
1090                                 }
1091                                 return NULL;
1092                         }
1093                 }
1094
1095                 /*
1096                  *      Keep retrying forever.
1097                  *
1098                  *      FIXME: cap the retries.
1099                  */
1100                 do {
1101                         if (write(data->master_pipe[1], &packet, sizeof(packet)) < 0) {
1102                                 ERROR("detail (%s): Failed passing detail packet pointer to master: %s",
1103                                       data->name, fr_syserror(errno));
1104                         }
1105
1106                         if (read(data->child_pipe[0], &c, 1) < 0) {
1107                                 ERROR("detail (%s): Failed getting detail packet ack from master: %s",
1108                                       data->name, fr_syserror(errno));
1109                                 break;
1110                         }
1111
1112                         if (data->delay_time > 0) usleep(data->delay_time);
1113
1114                         packet = detail_poll(this);
1115                         if (!packet) break;
1116                 } while (data->state != STATE_REPLIED);
1117         }
1118
1119         return NULL;
1120 }
1121 #endif
1122
1123
1124 static const CONF_PARSER detail_config[] = {
1125         { "detail", FR_CONF_OFFSET(PW_TYPE_FILE_OUTPUT | PW_TYPE_DEPRECATED, listen_detail_t, filename), NULL },
1126         { "filename", FR_CONF_OFFSET(PW_TYPE_FILE_OUTPUT | PW_TYPE_REQUIRED, listen_detail_t, filename), NULL },
1127         { "load_factor", FR_CONF_OFFSET(PW_TYPE_INTEGER, listen_detail_t, load_factor), STRINGIFY(10) },
1128         { "poll_interval", FR_CONF_OFFSET(PW_TYPE_INTEGER, listen_detail_t, poll_interval), STRINGIFY(1) },
1129         { "retry_interval", FR_CONF_OFFSET(PW_TYPE_INTEGER, listen_detail_t, retry_interval), STRINGIFY(30) },
1130         { "one_shot", FR_CONF_OFFSET(PW_TYPE_BOOLEAN, listen_detail_t, one_shot), "no" },
1131         { "track", FR_CONF_OFFSET(PW_TYPE_BOOLEAN, listen_detail_t, track), "no" },
1132         CONF_PARSER_TERMINATOR
1133 };
1134
1135 /*
1136  *      Parse a detail section.
1137  */
1138 int detail_parse(CONF_SECTION *cs, rad_listen_t *this)
1139 {
1140         int             rcode;
1141         listen_detail_t *data;
1142         RADCLIENT       *client;
1143         char            buffer[2048];
1144
1145         data = this->data;
1146
1147         rcode = cf_section_parse(cs, data, detail_config);
1148         if (rcode < 0) {
1149                 cf_log_err_cs(cs, "Failed parsing listen section");
1150                 return -1;
1151         }
1152
1153         data->name = cf_section_name2(cs);
1154         if (!data->name) data->name = data->filename;
1155
1156         /*
1157          *      We don't do duplicate detection for "detail" sockets.
1158          */
1159         this->nodup = true;
1160         this->synchronous = false;
1161
1162         if (!data->filename) {
1163                 cf_log_err_cs(cs, "No detail file specified in listen section");
1164                 return -1;
1165         }
1166
1167         FR_INTEGER_BOUND_CHECK("load_factor", data->load_factor, >=, 1);
1168         FR_INTEGER_BOUND_CHECK("load_factor", data->load_factor, <=, 100);
1169
1170         FR_INTEGER_BOUND_CHECK("poll_interval", data->poll_interval, >=, 1);
1171         FR_INTEGER_BOUND_CHECK("poll_interval", data->poll_interval, <=, 60);
1172
1173         FR_INTEGER_BOUND_CHECK("retry_interval", data->retry_interval, >=, 4);
1174         FR_INTEGER_BOUND_CHECK("retry_interval", data->retry_interval, <=, 3600);
1175
1176         /*
1177          *      Only checking the config.  Don't start threads or anything else.
1178          */
1179         if (check_config) return 0;
1180
1181         /*
1182          *      If the filename is a glob, use "detail.work" as the
1183          *      work file name.
1184          */
1185         if ((strchr(data->filename, '*') != NULL) ||
1186             (strchr(data->filename, '[') != NULL)) {
1187                 char *p;
1188
1189 #ifndef HAVE_GLOB_H
1190                 WARN("detail (%s): File \"%s\" appears to use file globbing, but it is not supported on this system",
1191                      data->name, data->filename);
1192 #endif
1193                 strlcpy(buffer, data->filename, sizeof(buffer));
1194                 p = strrchr(buffer, FR_DIR_SEP);
1195                 if (p) {
1196                         p[1] = '\0';
1197                 } else {
1198                         buffer[0] = '\0';
1199                 }
1200
1201                 /*
1202                  *      Globbing cannot be done across directories.
1203                  */
1204                 if ((strchr(buffer, '*') != NULL) ||
1205                     (strchr(buffer, '[') != NULL)) {
1206                         cf_log_err_cs(cs, "Wildcard directories are not supported");
1207                         return -1;
1208                 }
1209
1210                 strlcat(buffer, "detail.work",
1211                         sizeof(buffer) - strlen(buffer));
1212
1213         } else {
1214                 snprintf(buffer, sizeof(buffer), "%s.work", data->filename);
1215         }
1216
1217         data->filename_work = talloc_strdup(data, buffer);
1218
1219         data->work_fd = -1;
1220         data->vps = NULL;
1221         data->fp = NULL;
1222         data->state = STATE_UNOPENED;
1223         data->delay_time = data->poll_interval * USEC;
1224         data->signal = 1;
1225
1226         /*
1227          *      Initialize the fake client.
1228          */
1229         client = &data->detail_client;
1230         memset(client, 0, sizeof(*client));
1231         client->ipaddr.af = AF_INET;
1232         client->ipaddr.ipaddr.ip4addr.s_addr = INADDR_NONE;
1233         client->ipaddr.prefix = 0;
1234         client->longname = client->shortname = data->filename;
1235         client->secret = client->shortname;
1236         client->nas_type = talloc_strdup(data, "none"); /* Part of 'data' not dynamically allocated */
1237
1238 #ifdef WITH_DETAIL_THREAD
1239         /*
1240          *      Create the communication pipes.
1241          */
1242         if (pipe(data->master_pipe) < 0) {
1243                 ERROR("detail (%s): Error opening internal pipe: %s", data->name, fr_syserror(errno));
1244                 fr_exit(1);
1245         }
1246
1247         if (pipe(data->child_pipe) < 0) {
1248                 ERROR("detail (%s): Error opening internal pipe: %s", data->name, fr_syserror(errno));
1249                 fr_exit(1);
1250         }
1251
1252         pthread_create(&data->pthread_id, NULL, detail_handler_thread, this);
1253
1254         this->fd = data->master_pipe[0];
1255 #endif
1256
1257         return 0;
1258 }
1259 #endif