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).
58 #include <sys/epoll.h>
59 #include <sys/ioctl.h>
60 #include <sys/signalfd.h>
62 #include <sys/sysmacros.h>
63 #include <sys/timerfd.h>
64 #include <sys/types.h>
65 #include <linux/types.h>
66 #include <linux/lustre/lustre_user.h>
67 #include <linux/lustre/lustre_access_log.h>
68 #include "ofd_access_batch.h"
71 /* TODO fsname filter */
73 static FILE *debug_file;
74 static FILE *trace_file;
76 #define DEBUG(fmt, args...) \
78 if (debug_file != NULL) \
79 fprintf(debug_file, "DEBUG %s:%d: "fmt, __func__, __LINE__, ##args); \
82 #define TRACE(fmt, args...) \
84 if (trace_file != NULL) \
85 fprintf(trace_file, "TRACE "fmt, ##args); \
88 #define DEBUG_D(x) DEBUG("%s = %"PRIdMAX"\n", #x, (intmax_t)x)
89 #define DEBUG_P(x) DEBUG("%s = %p\n", #x, x)
90 #define DEBUG_S(x) DEBUG("%s = '%s'\n", #x, x)
91 #define DEBUG_U(x) DEBUG("%s = %"PRIuMAX"\n", #x, (uintmax_t)x)
93 #define ERROR(fmt, args...) \
94 fprintf(stderr, "%s: "fmt, program_invocation_short_name, ##args)
96 #define FATAL(fmt, args...) \
98 ERROR("FATAL: "fmt, ##args); \
103 ALR_EXIT_SUCCESS = INT_MIN + EXIT_SUCCESS,
104 ALR_EXIT_FAILURE = INT_MIN + EXIT_FAILURE,
112 int (*alr_io)(int /* epoll_fd */, struct alr_dev * /* this */, unsigned int /* mask */);
113 void (*alr_destroy)(struct alr_dev *);
118 struct alr_dev alr_dev;
121 size_t alr_entry_size;
125 static struct alr_log *alr_log[1 << 20]; /* 20 == MINORBITS */
126 static int oal_version; /* FIXME ... major version, minor version */
127 static unsigned int oal_log_major;
128 static unsigned int oal_log_minor_max;
129 static struct alr_batch *alr_batch;
130 static FILE *alr_batch_file;
131 static pthread_mutex_t alr_batch_file_mutex = PTHREAD_MUTEX_INITIALIZER;
132 static const char *alr_batch_file_path;
133 static int alr_print_fraction = 100;
135 #define D_ALR_DEV "%s %d"
136 #define P_ALR_DEV(ad) \
137 (ad)->alr_name, (ad)->alr_fd
139 #define D_ALR_LOG D_ALR_DEV" %u:%u"
140 #define P_ALR_LOG(al) \
141 P_ALR_DEV(&(al)->alr_dev), major((al)->alr_rdev), minor((al)->alr_rdev)
143 static void alr_dev_free(int epoll_fd, struct alr_dev *ad)
145 TRACE("alr_dev_free %s\n", ad->alr_name);
147 if (!(ad->alr_fd < 0))
148 epoll_ctl(epoll_fd, EPOLL_CTL_DEL, ad->alr_fd, NULL);
150 if (ad->alr_destroy != NULL)
151 (*ad->alr_destroy)(ad);
153 if (!(ad->alr_fd < 0))
160 static struct alr_log **alr_log_lookup(dev_t rdev)
162 assert(major(rdev) == oal_log_major);
164 if (!(minor(rdev) < ARRAY_SIZE(alr_log)))
167 return &alr_log[minor(rdev)];
170 static const char *alr_flags_to_str(unsigned int flags)
172 switch (flags & (OFD_ACCESS_READ | OFD_ACCESS_WRITE)) {
175 case OFD_ACCESS_READ:
177 case OFD_ACCESS_WRITE:
179 case OFD_ACCESS_READ | OFD_ACCESS_WRITE:
184 /* /dev/lustre-access-log/scratch-OST0000 device poll callback: read entries
185 * from log and print. */
186 static int alr_log_io(int epoll_fd, struct alr_dev *ad, unsigned int mask)
188 struct alr_log *al = container_of(ad, struct alr_log, alr_dev);
191 TRACE("alr_log_io %s\n", ad->alr_name);
194 assert(al->alr_entry_size != 0);
195 assert(al->alr_buf_size != 0);
196 assert(al->alr_buf != NULL);
198 count = read(ad->alr_fd, al->alr_buf, al->alr_buf_size);
200 ERROR("cannot read events from '%s': %s\n", ad->alr_name, strerror(errno));
205 TRACE("alr_log_eof %s\n", ad->alr_name);
209 if (count % al->alr_entry_size != 0) {
210 ERROR("invalid read from "D_ALR_LOG": entry_size = %zu, count = %zd\n",
211 P_ALR_LOG(al), al->alr_entry_size, count);
215 DEBUG("read "D_ALR_LOG", count = %zd\n", P_ALR_LOG(al), count);
217 for (i = 0; i < count; i += al->alr_entry_size) {
218 struct ofd_access_entry_v1 *oae =
219 (struct ofd_access_entry_v1 *)&al->alr_buf[i];
221 TRACE("alr_log_entry %s "DFID" %lu %lu %lu %u %u %s\n",
223 PFID(&oae->oae_parent_fid),
224 (unsigned long)oae->oae_begin,
225 (unsigned long)oae->oae_end,
226 (unsigned long)oae->oae_time,
227 (unsigned int)oae->oae_size,
228 (unsigned int)oae->oae_segment_count,
229 alr_flags_to_str(oae->oae_flags));
231 alr_batch_add(alr_batch, ad->alr_name, &oae->oae_parent_fid,
232 oae->oae_time, oae->oae_begin, oae->oae_end,
233 oae->oae_size, oae->oae_segment_count, oae->oae_flags);
239 static void alr_log_destroy(struct alr_dev *ad)
241 struct alr_log *al = container_of(ad, struct alr_log, alr_dev);
242 struct alr_log **pal;
244 TRACE("alr_log_free %s\n", ad->alr_name);
245 assert(major(al->alr_rdev) == oal_log_major);
247 pal = alr_log_lookup(al->alr_rdev);
248 if (pal != NULL && *pal == al)
253 al->alr_buf_size = 0;
256 /* Add an access log (identified by path) to the epoll set. */
257 static int alr_log_add(int epoll_fd, const char *path)
259 struct alr_log **pal, *al = NULL;
266 fd = open(path, O_RDONLY|O_NONBLOCK|O_CLOEXEC);
268 ERROR("cannot open device '%s': %s\n", path, strerror(errno));
269 rc = (errno == ENOENT ? 0 : -1); /* Possible race. */
273 /* Revalidate rdev in case of race. */
276 ERROR("cannot stat '%s': %s\n", path, strerror(errno));
280 if (major(st.st_rdev) != oal_log_major)
283 pal = alr_log_lookup(st.st_rdev);
285 ERROR("no device slot available for '%s' with minor %u\n",
286 path, minor(st.st_rdev));
291 goto out; /* We already have this device. */
293 struct lustre_access_log_info_v1 lali;
295 memset(&lali, 0, sizeof(lali));
297 rc = ioctl(fd, LUSTRE_ACCESS_LOG_IOCTL_INFO, &lali);
299 ERROR("cannot get info for device '%s': %s\n",
300 path, strerror(errno));
304 if (lali.lali_type != LUSTRE_ACCESS_LOG_TYPE_OFD) {
309 al = calloc(1, sizeof(*al));
311 FATAL("cannot allocate struct alr_dev of size %zu: %s\n",
312 sizeof(*al), strerror(errno));
314 al->alr_dev.alr_io = &alr_log_io;
315 al->alr_dev.alr_destroy = &alr_log_destroy;
316 al->alr_dev.alr_fd = fd;
319 al->alr_rdev = st.st_rdev;
321 al->alr_dev.alr_name = strdup(lali.lali_name);
322 if (al->alr_dev.alr_name == NULL)
323 FATAL("cannot copy name of size %zu: %s\n",
324 strlen(lali.lali_name), strerror(errno));
326 al->alr_buf_size = lali.lali_log_size;
327 al->alr_entry_size = lali.lali_entry_size;
329 if (al->alr_entry_size == 0) {
330 ERROR("device '%s' has zero entry size\n", path);
335 if (al->alr_buf_size == 0)
336 al->alr_buf_size = 1048576;
338 al->alr_buf_size = roundup(al->alr_buf_size, al->alr_entry_size);
340 al->alr_buf = malloc(al->alr_buf_size);
341 if (al->alr_buf == NULL)
342 FATAL("cannot allocate log buffer for '%s' of size %zu: %s\n",
343 path, al->alr_buf_size, strerror(errno));
345 struct epoll_event ev = {
346 .events = EPOLLIN | EPOLLHUP,
347 .data.ptr = &al->alr_dev,
350 rc = epoll_ctl(epoll_fd, EPOLL_CTL_ADD, al->alr_dev.alr_fd, &ev);
352 ERROR("cannot add device '%s' to epoll set: %s\n",
353 path, strerror(errno));
357 TRACE("alr_log_add %s\n", al->alr_dev.alr_name);
359 if (oal_log_minor_max < minor(al->alr_rdev))
360 oal_log_minor_max = minor(al->alr_rdev);
362 assert(*pal == NULL);
368 alr_dev_free(epoll_fd, &al->alr_dev);
376 /* Scan /dev/lustre-access-log/ for new access log devices and add to
378 static int alr_scan(int epoll_fd)
380 const char dir_path[] = "/dev/"LUSTRE_ACCESS_LOG_DIR_NAME;
386 dir = opendir(dir_path);
388 ERROR("cannot open '%s' for scanning: %s\n", dir_path, strerror(errno));
389 return ALR_EXIT_FAILURE;
394 /* Scan /dev for devices with major equal to oal_log_major and add
395 * any new devices. */
396 while ((d = readdir(dir)) != NULL) {
397 char path[6 + PATH_MAX];
398 struct alr_log **pal;
401 if (d->d_type != DT_CHR)
404 rc = fstatat(dir_fd, d->d_name, &st, 0);
406 ERROR("cannot stat '%s/%s' while scanning: %s\n",
407 dir_path, d->d_name, strerror(errno));
411 if (!S_ISCHR(st.st_mode))
414 if (major(st.st_rdev) != oal_log_major)
417 pal = alr_log_lookup(st.st_rdev);
419 ERROR("no device slot available for '%s/%s' with minor %u\n",
420 dir_path, d->d_name, minor(st.st_rdev));
425 continue; /* We already have this device. */
427 snprintf(path, sizeof(path), "%s/%s", dir_path, d->d_name);
429 alr_log_add(epoll_fd, path);
437 /* /dev/lustre-access-log/control device poll callback: call prescan
438 * ioctl and scan /dev/lustre-access-log/ for new access log
440 static int alr_ctl_io(int epoll_fd, struct alr_dev *cd, unsigned int mask)
444 TRACE("%s\n", __func__);
448 return ALR_EXIT_FAILURE;
451 return ALR_EXIT_SUCCESS;
453 rc = ioctl(cd->alr_fd, LUSTRE_ACCESS_LOG_IOCTL_PRESCAN);
455 ERROR("cannot start scanning: %s\n", strerror(errno));
456 return ALR_EXIT_FAILURE;
459 return alr_scan(epoll_fd);
462 /* signalfd epoll callback. Handle SIGINT and SIGTERM by breaking from
463 * the epoll loop and exiting normally.*/
464 static int alr_signal_io(int epoll_fd, struct alr_dev *sd, unsigned int mask)
466 struct signalfd_siginfo ssi;
469 TRACE("%s\n", __func__);
472 rc = read(sd->alr_fd, &ssi, sizeof(ssi));
476 DEBUG_U(ssi.ssi_signo);
477 switch (ssi.ssi_signo) {
480 return ALR_EXIT_SUCCESS;
486 /* batching timerfd epoll callback. Print batched access entries to
488 static int alr_batch_timer_io(int epoll_fd, struct alr_dev *td, unsigned int mask)
490 time_t now = time(NULL);
491 uint64_t expire_count;
494 TRACE("%s\n", __func__);
498 rc = read(td->alr_fd, &expire_count, sizeof(expire_count));
502 DEBUG_U(expire_count);
504 rc = alr_batch_print(alr_batch, alr_batch_file, &alr_batch_file_mutex,
507 ERROR("cannot write to '%s': %s\n",
508 alr_batch_file_path, strerror(errno));
512 /* Failed writes will leave alr_batch_file (pipe) in a
513 * weird state so make that fatal. */
514 return (rc < 0) ? ALR_EXIT_FAILURE : ALR_OK;
517 /* Call LUSTRE_ACCESS_LOG_IOCTL_INFO to get access log info and print
518 * YAML formatted info to stdout. */
519 static int alr_log_info(struct alr_log *al)
521 struct lustre_access_log_info_v1 lali;
524 rc = ioctl(al->alr_dev.alr_fd, LUSTRE_ACCESS_LOG_IOCTL_INFO, &lali);
526 ERROR("cannot get info for device '%s': %s\n",
527 al->alr_dev.alr_name, strerror(errno));
531 printf("- name: %s\n"
538 " _entry_space: %u\n"
539 " _entry_count: %u\n"
546 lali.lali_entry_size,
549 lali._lali_entry_space,
550 lali._lali_entry_count,
551 lali._lali_drop_count,
552 lali._lali_is_closed);
557 static struct alr_dev *alr_dev_create(int epoll_fd, int fd, const char *name,
558 int (*io)(int, struct alr_dev *, unsigned int),
559 void (*destroy)(struct alr_dev *))
564 alr = calloc(1, sizeof(*alr));
568 alr->alr_name = strdup(name);
569 if (alr->alr_name == NULL) {
574 alr->alr_destroy = destroy;
577 struct epoll_event event = {
578 .events = EPOLLIN | EPOLLHUP,
582 rc = epoll_ctl(epoll_fd, EPOLL_CTL_ADD, alr->alr_fd, &event);
593 printf("Usage: %s: [OPTION]...\n"
594 "Discover, read, batch, and write Lustre access logs\n"
596 "Mandatory arguments to long options are mandatory for short options too.\n"
597 " -f, --batch-file=FILE print batch to file (default stdout)\n"
598 " -i, --batch-interval=INTERVAL print batch every INTERVAL seconds\n"
599 " -o, --batch-offset=OFFSET print batch at OFFSET seconds\n"
600 " -d, --debug[=FILE] print debug messages to FILE (stderr)\n"
601 " -h, --help display this help and exit\n"
602 " -l, --list print YAML list of available access logs\n"
603 " -t, --trace[=FILE] print trace messages to FILE (stderr)\n",
604 program_invocation_short_name);
607 int main(int argc, char *argv[])
609 const char ctl_path[] = "/dev/"LUSTRE_ACCESS_LOG_DIR_NAME"/control";
610 struct alr_dev *alr_signal = NULL;
611 struct alr_dev *alr_batch_timer = NULL;
612 struct alr_dev *alr_ctl = NULL;
613 time_t batch_interval = 0;
614 time_t batch_offset = 0;
622 static struct option options[] = {
623 { .name = "batch-file", .has_arg = required_argument, .val = 'f', },
624 { .name = "batch-interval", .has_arg = required_argument, .val = 'i', },
625 { .name = "batch-offset", .has_arg = required_argument, .val = 'o', },
626 { .name = "debug", .has_arg = optional_argument, .val = 'd', },
627 { .name = "help", .has_arg = no_argument, .val = 'h', },
628 { .name = "fraction", .has_arg = required_argument, .val = 'F', },
629 { .name = "list", .has_arg = no_argument, .val = 'l', },
630 { .name = "trace", .has_arg = optional_argument, .val = 't', },
634 while ((c = getopt_long(argc, argv, "d::f:F:hi:lt::", options, NULL)) != -1) {
637 alr_batch_file_path = optarg;
641 batch_interval = strtoll(optarg, NULL, 0);
642 if (batch_interval < 0 || batch_interval >= 1048576 ||
644 FATAL("invalid batch interval '%s'\n", optarg);
648 batch_offset = strtoll(optarg, NULL, 0);
649 if (batch_offset < 0 || batch_offset >= 1048576 ||
651 FATAL("invalid batch offset '%s'\n", optarg);
654 if (optarg == NULL) {
656 } else if (strcmp(optarg, "-") == 0) {
659 debug_file = fopen(optarg, "a");
660 if (debug_file == NULL)
661 FATAL("cannot open debug file '%s': %s\n",
662 optarg, strerror(errno));
670 alr_print_fraction = strtoll(optarg, NULL, 0);
671 if (alr_print_fraction < 1 || alr_print_fraction > 100)
672 FATAL("invalid batch offset '%s'\n", optarg);
678 if (optarg == NULL) {
680 } else if (strcmp(optarg, "-") == 0) {
683 trace_file = fopen(optarg, "a");
684 if (debug_file == NULL)
685 FATAL("cannot open debug file '%s': %s\n",
686 optarg, strerror(errno));
691 fprintf(stderr, "Try '%s --help' for more information.\n",
692 program_invocation_short_name);
697 if (batch_interval > 0) {
698 alr_batch = alr_batch_create(-1);
699 if (alr_batch == NULL)
700 FATAL("cannot create batch struct: %s\n",
704 if (alr_batch_file_path != NULL) {
705 alr_batch_file = fopen(alr_batch_file_path, "w");
706 if (alr_batch_file == NULL)
707 FATAL("cannot open batch file '%s': %s\n",
708 alr_batch_file_path, strerror(errno));
710 alr_batch_file_path = "stdout";
711 alr_batch_file = stdout;
714 epoll_fd = epoll_create1(EPOLL_CLOEXEC);
716 FATAL("cannot create epoll set: %s\n", strerror(errno));
718 /* Setup signal FD and add to epoll set. */
719 sigset_t signal_mask;
720 sigemptyset(&signal_mask);
721 sigaddset(&signal_mask, SIGINT);
722 sigaddset(&signal_mask, SIGTERM);
723 rc = sigprocmask(SIG_BLOCK, &signal_mask, NULL);
725 FATAL("cannot set process signal mask: %s\n", strerror(errno));
727 int signal_fd = signalfd(-1, &signal_mask, SFD_NONBLOCK|SFD_CLOEXEC);
729 FATAL("cannot create signalfd: %s\n", strerror(errno));
731 alr_signal = alr_dev_create(epoll_fd, signal_fd, "signal", &alr_signal_io, NULL);
732 if (alr_signal == NULL)
733 FATAL("cannot register signalfd: %s\n", strerror(errno));
737 /* Setup batch timer FD and add to epoll set. */
739 rc = clock_gettime(CLOCK_REALTIME, &now);
741 FATAL("cannot read realtime clock: %s\n", strerror(errno));
743 int timer_fd = timerfd_create(CLOCK_REALTIME, TFD_NONBLOCK|TFD_CLOEXEC);
745 FATAL("cannot create batch timerfd: %s\n", strerror(errno));
747 struct itimerspec it = {
748 .it_value.tv_sec = (batch_interval > 0) ?
749 roundup(now.tv_sec, batch_interval) +
750 (batch_offset % batch_interval) :
752 .it_interval.tv_sec = batch_interval,
755 DEBUG_D(it.it_value.tv_sec);
757 rc = timerfd_settime(timer_fd, TFD_TIMER_ABSTIME, &it, NULL);
759 FATAL("cannot arm timerfd: %s\n", strerror(errno));
761 alr_batch_timer = alr_dev_create(epoll_fd, timer_fd, "batch_timer",
762 &alr_batch_timer_io, NULL);
763 if (alr_batch_timer == NULL)
764 FATAL("cannot register batch timerfd: %s\n", strerror(errno));
768 /* Open control device. */
769 int ctl_fd = open(ctl_path, O_RDONLY|O_NONBLOCK|O_CLOEXEC);
771 FATAL("cannot open '%s': %s\n", ctl_path, strerror(errno));
773 /* Get and print interface version. */
774 oal_version = ioctl(ctl_fd, LUSTRE_ACCESS_LOG_IOCTL_VERSION);
776 FATAL("cannot get ofd access log interface version: %s\n", strerror(errno));
778 DEBUG_D(oal_version);
780 /* Get and print device major used for access log devices. */
781 oal_log_major = ioctl(ctl_fd, LUSTRE_ACCESS_LOG_IOCTL_MAJOR);
782 if (oal_log_major < 0)
783 FATAL("cannot get ofd access log major: %s\n", strerror(errno));
785 DEBUG_D(oal_log_major);
787 /* Add control device to epoll set. */
788 alr_ctl = alr_dev_create(epoll_fd, ctl_fd, "control", &alr_ctl_io, NULL);
790 FATAL("cannot register control device: %s\n", strerror(errno));
795 struct epoll_event ev[32];
796 int timeout = (list_info ? 0 : -1);
799 ev_count = epoll_wait(epoll_fd, ev, ARRAY_SIZE(ev), timeout);
801 if (errno == EINTR) /* Signal or timeout. */
804 ERROR("cannot wait on epoll set: %s\n", strerror(errno));
805 exit_status = EXIT_FAILURE;
811 for (i = 0; i < ev_count; i++) {
812 struct alr_dev *ad = ev[i].data.ptr;
813 unsigned int mask = ev[i].events;
815 rc = (*ad->alr_io)(epoll_fd, ad, mask);
817 case ALR_EXIT_FAILURE:
818 exit_status = EXIT_FAILURE;
820 case ALR_EXIT_SUCCESS:
821 exit_status = EXIT_SUCCESS;
825 alr_dev_free(epoll_fd, ad);
832 } while (!list_info);
834 exit_status = EXIT_SUCCESS;
836 assert(oal_log_minor_max < ARRAY_SIZE(alr_log));
838 for (m = 0; m <= oal_log_minor_max; m++) {
839 if (alr_log[m] == NULL)
843 rc = alr_log_info(alr_log[m]);
845 exit_status = EXIT_FAILURE;
848 alr_dev_free(epoll_fd, &alr_log[m]->alr_dev);
851 alr_dev_free(epoll_fd, alr_ctl);
852 alr_dev_free(epoll_fd, alr_signal);
853 alr_dev_free(epoll_fd, alr_batch_timer);
856 alr_batch_destroy(alr_batch);
858 DEBUG_D(exit_status);