4 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
6 * This program is free software; you can redistribute it and/or modify
7 * it under the terms of the GNU General Public License version 2 only,
8 * as published by the Free Software Foundation.
10 * This program is distributed in the hope that it will be useful, but
11 * WITHOUT ANY WARRANTY; without even the implied warranty of
12 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
13 * General Public License version 2 for more details (a copy is included
14 * in the LICENSE file that accompanied this code).
16 * You should have received a copy of the GNU General Public License
17 * version 2 along with this program; If not, see
18 * http://www.gnu.org/licenses/gpl-2.0.html
22 * Copyright 2020, DataDirect Networks Storage.
24 * This file is part of Lustre, http://www.lustre.org/
26 * Author: John L. Hammond <jhammond@whamcloud.com>
28 * lustre/utils/ofd_access_log_reader.c
30 * Sample utility to discover and read Lustre (ofd) access logs.
32 * This demonstrates the discovery and reading of Lustre access logs
33 * (see linux/lustre/lustre_access_log.h and
34 * lustre/ofd/ofd_access_log.c.). By default it opens the control
35 * device, discovers and opens all access log devices, and consumes
36 * all access log entries. If invoked with the --list option then it
37 * prints information about all available devices to stdout and exits.
39 * Structured trace points (when --trace is used) are added to permit
40 * testing of the access log functionality (see test_165* in
41 * lustre/tests/sanity.sh).
57 #include <sys/epoll.h>
58 #include <sys/ioctl.h>
59 #include <sys/signalfd.h>
61 #include <sys/sysmacros.h>
62 #include <sys/timerfd.h>
63 #include <sys/types.h>
64 #include <linux/types.h>
65 #include <linux/lustre/lustre_user.h>
66 #include <linux/lustre/lustre_access_log.h>
67 #include "ofd_access_batch.h"
70 /* TODO fsname filter */
72 static FILE *debug_file;
73 static FILE *trace_file;
75 #define DEBUG(fmt, args...) \
77 if (debug_file != NULL) \
78 fprintf(debug_file, "DEBUG %s:%d: "fmt, __func__, __LINE__, ##args); \
81 #define TRACE(fmt, args...) \
83 if (trace_file != NULL) \
84 fprintf(trace_file, "TRACE "fmt, ##args); \
87 #define DEBUG_D(x) DEBUG("%s = %"PRIdMAX"\n", #x, (intmax_t)x)
88 #define DEBUG_P(x) DEBUG("%s = %p\n", #x, x)
89 #define DEBUG_S(x) DEBUG("%s = '%s'\n", #x, x)
90 #define DEBUG_U(x) DEBUG("%s = %"PRIuMAX"\n", #x, (uintmax_t)x)
92 #define ERROR(fmt, args...) \
93 fprintf(stderr, "%s: "fmt, program_invocation_short_name, ##args)
95 #define FATAL(fmt, args...) \
97 ERROR("FATAL: "fmt, ##args); \
102 ALR_EXIT_SUCCESS = INT_MIN + EXIT_SUCCESS,
103 ALR_EXIT_FAILURE = INT_MIN + EXIT_FAILURE,
111 int (*alr_io)(int /* epoll_fd */, struct alr_dev * /* this */, unsigned int /* mask */);
112 void (*alr_destroy)(struct alr_dev *);
117 struct alr_dev alr_dev;
120 size_t alr_entry_size;
124 static struct alr_log *alr_log[1 << 20]; /* 20 == MINORBITS */
125 static int oal_version; /* FIXME ... major version, minor version */
126 static unsigned int oal_log_major;
127 static unsigned int oal_log_minor_max;
128 static struct alr_batch *alr_batch;
129 static FILE *alr_batch_file;
130 static const char *alr_batch_file_path;
132 #define D_ALR_DEV "%s %d"
133 #define P_ALR_DEV(ad) \
134 (ad)->alr_name, (ad)->alr_fd
136 #define D_ALR_LOG D_ALR_DEV" %u:%u"
137 #define P_ALR_LOG(al) \
138 P_ALR_DEV(&(al)->alr_dev), major((al)->alr_rdev), minor((al)->alr_rdev)
140 static void alr_dev_free(int epoll_fd, struct alr_dev *ad)
142 TRACE("alr_dev_free %s\n", ad->alr_name);
144 if (!(ad->alr_fd < 0))
145 epoll_ctl(epoll_fd, EPOLL_CTL_DEL, ad->alr_fd, NULL);
147 if (ad->alr_destroy != NULL)
148 (*ad->alr_destroy)(ad);
150 if (!(ad->alr_fd < 0))
157 static struct alr_log **alr_log_lookup(dev_t rdev)
159 assert(major(rdev) == oal_log_major);
161 if (!(minor(rdev) < ARRAY_SIZE(alr_log)))
164 return &alr_log[minor(rdev)];
167 static const char *alr_flags_to_str(unsigned int flags)
169 switch (flags & (OFD_ACCESS_READ | OFD_ACCESS_WRITE)) {
172 case OFD_ACCESS_READ:
174 case OFD_ACCESS_WRITE:
176 case OFD_ACCESS_READ | OFD_ACCESS_WRITE:
181 /* /dev/lustre-access-log/scratch-OST0000 device poll callback: read entries
182 * from log and print. */
183 static int alr_log_io(int epoll_fd, struct alr_dev *ad, unsigned int mask)
185 struct alr_log *al = container_of(ad, struct alr_log, alr_dev);
188 TRACE("alr_log_io %s\n", ad->alr_name);
191 assert(al->alr_entry_size != 0);
192 assert(al->alr_buf_size != 0);
193 assert(al->alr_buf != NULL);
195 count = read(ad->alr_fd, al->alr_buf, al->alr_buf_size);
197 ERROR("cannot read events from '%s': %s\n", ad->alr_name, strerror(errno));
202 TRACE("alr_log_eof %s\n", ad->alr_name);
206 if (count % al->alr_entry_size != 0) {
207 ERROR("invalid read from "D_ALR_LOG": entry_size = %zu, count = %zd\n",
208 P_ALR_LOG(al), al->alr_entry_size, count);
212 DEBUG("read "D_ALR_LOG", count = %zd\n", P_ALR_LOG(al), count);
214 for (i = 0; i < count; i += al->alr_entry_size) {
215 struct ofd_access_entry_v1 *oae =
216 (struct ofd_access_entry_v1 *)&al->alr_buf[i];
218 TRACE("alr_log_entry %s "DFID" %lu %lu %lu %u %u %s\n",
220 PFID(&oae->oae_parent_fid),
221 (unsigned long)oae->oae_begin,
222 (unsigned long)oae->oae_end,
223 (unsigned long)oae->oae_time,
224 (unsigned int)oae->oae_size,
225 (unsigned int)oae->oae_segment_count,
226 alr_flags_to_str(oae->oae_flags));
228 alr_batch_add(alr_batch, ad->alr_name, &oae->oae_parent_fid,
229 oae->oae_time, oae->oae_begin, oae->oae_end,
230 oae->oae_size, oae->oae_segment_count, oae->oae_flags);
236 static void alr_log_destroy(struct alr_dev *ad)
238 struct alr_log *al = container_of(ad, struct alr_log, alr_dev);
239 struct alr_log **pal;
241 TRACE("alr_log_free %s\n", ad->alr_name);
242 assert(major(al->alr_rdev) == oal_log_major);
244 pal = alr_log_lookup(al->alr_rdev);
245 if (pal != NULL && *pal == al)
250 al->alr_buf_size = 0;
253 /* Add an access log (identified by path) to the epoll set. */
254 static int alr_log_add(int epoll_fd, const char *path)
256 struct alr_log **pal, *al = NULL;
263 fd = open(path, O_RDONLY|O_NONBLOCK|O_CLOEXEC);
265 ERROR("cannot open device '%s': %s\n", path, strerror(errno));
266 rc = (errno == ENOENT ? 0 : -1); /* Possible race. */
270 /* Revalidate rdev in case of race. */
273 ERROR("cannot stat '%s': %s\n", path, strerror(errno));
277 if (major(st.st_rdev) != oal_log_major)
280 pal = alr_log_lookup(st.st_rdev);
282 ERROR("no device slot available for '%s' with minor %u\n",
283 path, minor(st.st_rdev));
288 goto out; /* We already have this device. */
290 struct lustre_access_log_info_v1 lali;
292 memset(&lali, 0, sizeof(lali));
294 rc = ioctl(fd, LUSTRE_ACCESS_LOG_IOCTL_INFO, &lali);
296 ERROR("cannot get info for device '%s': %s\n",
297 path, strerror(errno));
301 if (lali.lali_type != LUSTRE_ACCESS_LOG_TYPE_OFD) {
306 al = calloc(1, sizeof(*al));
308 FATAL("cannot allocate struct alr_dev of size %zu: %s\n",
309 sizeof(*al), strerror(errno));
311 al->alr_dev.alr_io = &alr_log_io;
312 al->alr_dev.alr_destroy = &alr_log_destroy;
313 al->alr_dev.alr_fd = fd;
316 al->alr_rdev = st.st_rdev;
318 al->alr_dev.alr_name = strdup(lali.lali_name);
319 if (al->alr_dev.alr_name == NULL)
320 FATAL("cannot copy name of size %zu: %s\n",
321 strlen(lali.lali_name), strerror(errno));
323 al->alr_buf_size = lali.lali_log_size;
324 al->alr_entry_size = lali.lali_entry_size;
326 if (al->alr_entry_size == 0) {
327 ERROR("device '%s' has zero entry size\n", path);
332 if (al->alr_buf_size == 0)
333 al->alr_buf_size = 1048576;
335 al->alr_buf_size = roundup(al->alr_buf_size, al->alr_entry_size);
337 al->alr_buf = malloc(al->alr_buf_size);
338 if (al->alr_buf == NULL)
339 FATAL("cannot allocate log buffer for '%s' of size %zu: %s\n",
340 path, al->alr_buf_size, strerror(errno));
342 struct epoll_event ev = {
343 .events = EPOLLIN | EPOLLHUP,
344 .data.ptr = &al->alr_dev,
347 rc = epoll_ctl(epoll_fd, EPOLL_CTL_ADD, al->alr_dev.alr_fd, &ev);
349 ERROR("cannot add device '%s' to epoll set: %s\n",
350 path, strerror(errno));
354 TRACE("alr_log_add %s\n", al->alr_dev.alr_name);
356 if (oal_log_minor_max < minor(al->alr_rdev))
357 oal_log_minor_max = minor(al->alr_rdev);
359 assert(*pal == NULL);
365 alr_dev_free(epoll_fd, &al->alr_dev);
373 /* Scan /dev/lustre-access-log/ for new access log devices and add to
375 static int alr_scan(int epoll_fd)
377 const char dir_path[] = "/dev/"LUSTRE_ACCESS_LOG_DIR_NAME;
383 dir = opendir(dir_path);
385 ERROR("cannot open '%s' for scanning: %s\n", dir_path, strerror(errno));
386 return ALR_EXIT_FAILURE;
391 /* Scan /dev for devices with major equal to oal_log_major and add
392 * any new devices. */
393 while ((d = readdir(dir)) != NULL) {
394 char path[6 + PATH_MAX];
395 struct alr_log **pal;
398 if (d->d_type != DT_CHR)
401 rc = fstatat(dir_fd, d->d_name, &st, 0);
403 ERROR("cannot stat '%s/%s' while scanning: %s\n",
404 dir_path, d->d_name, strerror(errno));
408 if (!S_ISCHR(st.st_mode))
411 if (major(st.st_rdev) != oal_log_major)
414 pal = alr_log_lookup(st.st_rdev);
416 ERROR("no device slot available for '%s/%s' with minor %u\n",
417 dir_path, d->d_name, minor(st.st_rdev));
422 continue; /* We already have this device. */
424 snprintf(path, sizeof(path), "%s/%s", dir_path, d->d_name);
426 alr_log_add(epoll_fd, path);
434 /* /dev/lustre-access-log/control device poll callback: call prescan
435 * ioctl and scan /dev/lustre-access-log/ for new access log
437 static int alr_ctl_io(int epoll_fd, struct alr_dev *cd, unsigned int mask)
441 TRACE("%s\n", __func__);
445 return ALR_EXIT_FAILURE;
448 return ALR_EXIT_SUCCESS;
450 rc = ioctl(cd->alr_fd, LUSTRE_ACCESS_LOG_IOCTL_PRESCAN);
452 ERROR("cannot start scanning: %s\n", strerror(errno));
453 return ALR_EXIT_FAILURE;
456 return alr_scan(epoll_fd);
459 /* signalfd epoll callback. Handle SIGINT and SIGTERM by breaking from
460 * the epoll loop and exiting normally.*/
461 static int alr_signal_io(int epoll_fd, struct alr_dev *sd, unsigned int mask)
463 struct signalfd_siginfo ssi;
466 TRACE("%s\n", __func__);
469 rc = read(sd->alr_fd, &ssi, sizeof(ssi));
473 DEBUG_U(ssi.ssi_signo);
474 switch (ssi.ssi_signo) {
477 return ALR_EXIT_SUCCESS;
483 /* batching timerfd epoll callback. Print batched access entries to
485 static int alr_batch_timer_io(int epoll_fd, struct alr_dev *td, unsigned int mask)
487 time_t now = time(NULL);
488 uint64_t expire_count;
491 TRACE("%s\n", __func__);
495 rc = read(td->alr_fd, &expire_count, sizeof(expire_count));
499 DEBUG_U(expire_count);
501 rc = alr_batch_print(alr_batch, alr_batch_file);
503 ERROR("cannot write to '%s': %s\n",
504 alr_batch_file_path, strerror(errno));
508 /* FIXME: blocking write to batch file. */
509 rc = fflush(alr_batch_file);
511 ERROR("cannot write to '%s': %s\n",
512 alr_batch_file_path, strerror(errno));
516 /* Failed writes will leave alr_batch_file (pipe) in a
517 * weird state so make that fatal. */
518 return (rc < 0) ? ALR_EXIT_FAILURE : ALR_OK;
521 /* Call LUSTRE_ACCESS_LOG_IOCTL_INFO to get access log info and print
522 * YAML formatted info to stdout. */
523 static int alr_log_info(struct alr_log *al)
525 struct lustre_access_log_info_v1 lali;
528 rc = ioctl(al->alr_dev.alr_fd, LUSTRE_ACCESS_LOG_IOCTL_INFO, &lali);
530 ERROR("cannot get info for device '%s': %s\n",
531 al->alr_dev.alr_name, strerror(errno));
535 printf("- name: %s\n"
542 " _entry_space: %u\n"
543 " _entry_count: %u\n"
550 lali.lali_entry_size,
553 lali._lali_entry_space,
554 lali._lali_entry_count,
555 lali._lali_drop_count,
556 lali._lali_is_closed);
561 static struct alr_dev *alr_dev_create(int epoll_fd, int fd, const char *name,
562 int (*io)(int, struct alr_dev *, unsigned int),
563 void (*destroy)(struct alr_dev *))
568 alr = calloc(1, sizeof(*alr));
572 alr->alr_name = strdup(name);
573 if (alr->alr_name == NULL) {
578 alr->alr_destroy = destroy;
581 struct epoll_event event = {
582 .events = EPOLLIN | EPOLLHUP,
586 rc = epoll_ctl(epoll_fd, EPOLL_CTL_ADD, alr->alr_fd, &event);
597 printf("Usage: %s: [OPTION]...\n"
598 "Discover, read, batch, and write Lustre access logs\n"
600 "Mandatory arguments to long options are mandatory for short options too.\n"
601 " -f, --batch-file=FILE print batch to file (default stdout)\n"
602 " -i, --batch-interval=INTERVAL print batch every INTERVAL seconds\n"
603 " -o, --batch-offset=OFFSET print batch at OFFSET seconds\n"
604 " -d, --debug[=FILE] print debug messages to FILE (stderr)\n"
605 " -h, --help display this help and exit\n"
606 " -l, --list print YAML list of available access logs\n"
607 " -t, --trace[=FILE] print trace messages to FILE (stderr)\n",
608 program_invocation_short_name);
611 int main(int argc, char *argv[])
613 const char ctl_path[] = "/dev/"LUSTRE_ACCESS_LOG_DIR_NAME"/control";
614 struct alr_dev *alr_signal = NULL;
615 struct alr_dev *alr_batch_timer = NULL;
616 struct alr_dev *alr_ctl = NULL;
617 time_t batch_interval = 0;
618 time_t batch_offset = 0;
626 static struct option options[] = {
627 { .name = "batch-file", .has_arg = required_argument, .val = 'f', },
628 { .name = "batch-interval", .has_arg = required_argument, .val = 'i', },
629 { .name = "batch-offset", .has_arg = required_argument, .val = 'o', },
630 { .name = "debug", .has_arg = optional_argument, .val = 'd', },
631 { .name = "help", .has_arg = no_argument, .val = 'h', },
632 { .name = "list", .has_arg = no_argument, .val = 'l', },
633 { .name = "trace", .has_arg = optional_argument, .val = 't', },
637 while ((c = getopt_long(argc, argv, "d::f:hi:lt::", options, NULL)) != -1) {
640 alr_batch_file_path = optarg;
644 batch_interval = strtoll(optarg, NULL, 0);
645 if (batch_interval < 0 || batch_interval >= 1048576 ||
647 FATAL("invalid batch interval '%s'\n", optarg);
651 batch_offset = strtoll(optarg, NULL, 0);
652 if (batch_offset < 0 || batch_offset >= 1048576 ||
654 FATAL("invalid batch offset '%s'\n", optarg);
657 if (optarg == NULL) {
659 } else if (strcmp(optarg, "-") == 0) {
662 debug_file = fopen(optarg, "a");
663 if (debug_file == NULL)
664 FATAL("cannot open debug file '%s': %s\n",
665 optarg, strerror(errno));
676 if (optarg == NULL) {
678 } else if (strcmp(optarg, "-") == 0) {
681 trace_file = fopen(optarg, "a");
682 if (debug_file == NULL)
683 FATAL("cannot open debug file '%s': %s\n",
684 optarg, strerror(errno));
689 fprintf(stderr, "Try '%s --help' for more information.\n",
690 program_invocation_short_name);
695 if (batch_interval > 0) {
696 alr_batch = alr_batch_create(-1);
697 if (alr_batch == NULL)
698 FATAL("cannot create batch struct: %s\n",
702 if (alr_batch_file_path != NULL) {
703 alr_batch_file = fopen(alr_batch_file_path, "w");
704 if (alr_batch_file == NULL)
705 FATAL("cannot open batch file '%s': %s\n",
706 alr_batch_file_path, strerror(errno));
708 alr_batch_file_path = "stdout";
709 alr_batch_file = stdout;
712 epoll_fd = epoll_create1(EPOLL_CLOEXEC);
714 FATAL("cannot create epoll set: %s\n", strerror(errno));
716 /* Setup signal FD and add to epoll set. */
717 sigset_t signal_mask;
718 sigemptyset(&signal_mask);
719 sigaddset(&signal_mask, SIGINT);
720 sigaddset(&signal_mask, SIGTERM);
721 rc = sigprocmask(SIG_BLOCK, &signal_mask, NULL);
723 FATAL("cannot set process signal mask: %s\n", strerror(errno));
725 int signal_fd = signalfd(-1, &signal_mask, SFD_NONBLOCK|SFD_CLOEXEC);
727 FATAL("cannot create signalfd: %s\n", strerror(errno));
729 alr_signal = alr_dev_create(epoll_fd, signal_fd, "signal", &alr_signal_io, NULL);
730 if (alr_signal == NULL)
731 FATAL("cannot register signalfd: %s\n", strerror(errno));
735 /* Setup batch timer FD and add to epoll set. */
737 rc = clock_gettime(CLOCK_REALTIME, &now);
739 FATAL("cannot read realtime clock: %s\n", strerror(errno));
741 int timer_fd = timerfd_create(CLOCK_REALTIME, TFD_NONBLOCK|TFD_CLOEXEC);
743 FATAL("cannot create batch timerfd: %s\n", strerror(errno));
745 struct itimerspec it = {
746 .it_value.tv_sec = (batch_interval > 0) ?
747 roundup(now.tv_sec, batch_interval) +
748 (batch_offset % batch_interval) :
750 .it_interval.tv_sec = batch_interval,
753 DEBUG_D(it.it_value.tv_sec);
755 rc = timerfd_settime(timer_fd, TFD_TIMER_ABSTIME, &it, NULL);
757 FATAL("cannot arm timerfd: %s\n", strerror(errno));
759 alr_batch_timer = alr_dev_create(epoll_fd, timer_fd, "batch_timer",
760 &alr_batch_timer_io, NULL);
761 if (alr_batch_timer == NULL)
762 FATAL("cannot register batch timerfd: %s\n", strerror(errno));
766 /* Open control device. */
767 int ctl_fd = open(ctl_path, O_RDONLY|O_NONBLOCK|O_CLOEXEC);
769 FATAL("cannot open '%s': %s\n", ctl_path, strerror(errno));
771 /* Get and print interface version. */
772 oal_version = ioctl(ctl_fd, LUSTRE_ACCESS_LOG_IOCTL_VERSION);
774 FATAL("cannot get ofd access log interface version: %s\n", strerror(errno));
776 DEBUG_D(oal_version);
778 /* Get and print device major used for access log devices. */
779 oal_log_major = ioctl(ctl_fd, LUSTRE_ACCESS_LOG_IOCTL_MAJOR);
780 if (oal_log_major < 0)
781 FATAL("cannot get ofd access log major: %s\n", strerror(errno));
783 DEBUG_D(oal_log_major);
785 /* Add control device to epoll set. */
786 alr_ctl = alr_dev_create(epoll_fd, ctl_fd, "control", &alr_ctl_io, NULL);
788 FATAL("cannot register control device: %s\n", strerror(errno));
793 struct epoll_event ev[32];
794 int timeout = (list_info ? 0 : -1);
797 ev_count = epoll_wait(epoll_fd, ev, ARRAY_SIZE(ev), timeout);
799 if (errno == EINTR) /* Signal or timeout. */
802 ERROR("cannot wait on epoll set: %s\n", strerror(errno));
803 exit_status = EXIT_FAILURE;
809 for (i = 0; i < ev_count; i++) {
810 struct alr_dev *ad = ev[i].data.ptr;
811 unsigned int mask = ev[i].events;
813 rc = (*ad->alr_io)(epoll_fd, ad, mask);
815 case ALR_EXIT_FAILURE:
816 exit_status = EXIT_FAILURE;
818 case ALR_EXIT_SUCCESS:
819 exit_status = EXIT_SUCCESS;
823 alr_dev_free(epoll_fd, ad);
830 } while (!list_info);
832 exit_status = EXIT_SUCCESS;
834 assert(oal_log_minor_max < ARRAY_SIZE(alr_log));
836 for (m = 0; m <= oal_log_minor_max; m++) {
837 if (alr_log[m] == NULL)
841 rc = alr_log_info(alr_log[m]);
843 exit_status = EXIT_FAILURE;
846 alr_dev_free(epoll_fd, &alr_log[m]->alr_dev);
849 alr_dev_free(epoll_fd, alr_ctl);
850 alr_dev_free(epoll_fd, alr_signal);
851 alr_dev_free(epoll_fd, alr_batch_timer);
854 alr_batch_destroy(alr_batch);
856 DEBUG_D(exit_status);