+/*
+ * tl-append: time-logger appending shell
+ * Copyright (C) 2023 Scott Worley <scottworley@scottworley.com>
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, version 3.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program. If not, see <https://www.gnu.org/licenses/>.
+ */
+
#define _POSIX_C_SOURCE 2
#define _XOPEN_SOURCE
+#define _GNU_SOURCE
#include <assert.h>
#include <ctype.h>
#include <errno.h>
+#include <fcntl.h>
+#include <limits.h>
+#include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
+#include <sys/file.h>
#include <time.h>
+#include <unistd.h>
#include "common.h"
+const size_t TIMESTAMP_LEN = 19;
+
typedef struct expectation {
time_t a, b;
const char *message;
} ex_t;
const ex_t END = {((time_t)-1), ((time_t)-1), NULL};
+const ex_t CONSUMED = {((time_t)-2), ((time_t)-2), NULL};
static int is_end(ex_t exp) {
return exp.a == END.a && exp.b == END.b && exp.message == END.message;
}
+static void consume(ex_t *exp) {
+ exp->a = CONSUMED.a;
+ exp->b = CONSUMED.b;
+}
+static int is_consumed(ex_t exp) {
+ return exp.a == CONSUMED.a && exp.b == CONSUMED.b;
+}
static ex_t expectation(time_t a, time_t b, const char *message) {
ex_t exp;
exp.a = a;
return expectation(start, end, content);
}
-static void verify_log_contents(ex_t exps[]) {
+static char *timestamp_problem(const ex_t *ex, const char *line) {
+ struct tm tm;
+
+ /* localtime_r to set tm's timezone */
+ time_t now_time = time(NULL);
+ if (localtime_r(&now_time, &tm) == NULL)
+ return "Can't unpack current time?";
+
+ const char *strptime_result = strptime(line, "%Y %m %d %H %M %S", &tm);
+ if (strptime_result == NULL || strptime_result != &line[TIMESTAMP_LEN])
+ return "Wrong contents in log file: Couldn't parse timestamp";
+ time_t t = mktime(&tm);
+ int t_in_range = ex->a <= t && t <= ex->b;
+ if (!t_in_range)
+ return "Wrong contents in log file: Wrong time";
+ return NULL;
+}
+
+static char *line_problem(const ex_t *ex, const char *line) {
+ size_t line_len = strlen(line);
+ if (line_len < TIMESTAMP_LEN + 1)
+ return "Wrong contents in log file: Line too short";
+ char *trouble = timestamp_problem(ex, line);
+ if (trouble)
+ return trouble;
+ if (line[TIMESTAMP_LEN] != ' ')
+ return "Wrong contents in log file: Bad format";
+ if (strncmp(ex->message, &line[TIMESTAMP_LEN + 1], strlen(ex->message) + 1) !=
+ 0)
+ return "Wrong contents in log file";
+ return NULL;
+}
+
+static void verify_line(const ex_t *ex, const char *line) {
+ char *trouble = line_problem(ex, line);
+ if (trouble)
+ die(trouble);
+}
+static void verify_log_contents(const ex_t exps[]) {
FILE *f = fopen(FILENAME, "r");
if (f == NULL)
die_err("Error opening log file");
for (size_t i = 0; !is_end(exps[i]); i++) {
- size_t len = strlen(exps[i].message);
+ size_t len = TIMESTAMP_LEN + 1 + strlen(exps[i].message);
+ if (len > INT_MAX - 1)
+ die("message too long");
char *buf = (char *)malloc(len + 2);
if (fgets(buf, len + 1, f) == NULL)
die("Error reading log file");
if (ferror(f))
die("Error reading log file");
- if (strncmp(exps[i].message, buf, len + 1) != 0)
- die("Wrong contents in log file");
+ verify_line(&exps[i], buf);
free(buf);
}
if (fclose(f) != 0)
die_err("Error closing log file");
}
+static void consume_expectation(ex_t exps[], const char *line) {
+ for (size_t i = 0; !is_end(exps[i]); i++) {
+ if (line_problem(&exps[i], line) == NULL) {
+ consume(&exps[i]);
+ return;
+ }
+ }
+ die("Wrong contents in log file: Line didn't match any expectation");
+}
+
+static void verify_log_contents_unordered(ex_t exps[]) {
+ FILE *f = fopen(FILENAME, "r");
+ if (f == NULL)
+ die_err("Error opening log file");
+ for (;;) {
+ const int MAX_LEN = 9999;
+ char buf[MAX_LEN];
+ if (fgets(buf, MAX_LEN, f) == NULL) {
+ if (feof(f))
+ break;
+ die("Error reading log file");
+ }
+ if (ferror(f))
+ die("Error reading log file");
+ consume_expectation(exps, buf);
+ }
+ if (fclose(f) != 0)
+ die_err("Error closing log file");
+ for (size_t i = 0; !is_end(exps[i]); i++) {
+ if (!is_consumed(exps[i]))
+ die("Wrong contents in log file: Unconsumed expectation");
+ }
+}
+
static void test_encode_time() {
/* localtime_r to set tm's timezone */
time_t now_time = time(NULL);
if (tt == (time_t)-1)
die_err("Can't pack time?");
- const char *encoded = encode_time(tt);
+ char *encoded = encode_time(tt);
/* Loose check to allow for daylight savings time changes between the current
* time and the target time. :( */
assert(encoded[0] == '2');
assert(encoded[17] == '1');
assert(encoded[18] == '6');
assert(encoded[19] == '\0');
+ free(encoded);
+}
+
+static FILE *take_lock(FILE *f, char *lock_type) {
+ int fd = fileno(f);
+ if (fd == -1)
+ die_err("Couldn't get file descriptor for locking");
+ if (strcmp(lock_type, "fcntl") == 0) {
+ if (fcntl(fd, F_SETLK,
+ &(struct flock){.l_type = F_WRLCK,
+ .l_whence = SEEK_SET,
+ .l_start = 0,
+ .l_len = 0}) == -1)
+ die_err("Couldn't take fcntl lock");
+ } else if (strcmp(lock_type, "flock") == 0) {
+ if (flock(fd, LOCK_EX) == -1)
+ die_err("Couldn't take flock lock");
+ } else {
+ die("Bad lock type");
+ }
+ return f;
+}
+
+static void release_lock(FILE *f) {
+ if (fclose(f) != 0)
+ die_err("Error releasing lock");
+}
+
+static void *release_lock_after_delay(void *f) {
+ sleep(1);
+ release_lock((FILE *)f);
+ return NULL;
+}
+
+static void *writer_thread(void *start_signal) {
+ ex_t *ex = (ex_t *)malloc(sizeof(ex_t));
+ if (ex == NULL)
+ die_err("Couldn't allocate memory");
+ char *message;
+ if (asprintf(&message, "Hello from thread %lu\n", pthread_self()) == -1)
+ die("Couldn't prepare message");
+ pthread_rwlock_rdlock((pthread_rwlock_t *)start_signal);
+ *ex = write_to_tl_append(message);
+ return ex;
}
static void write_and_read_line() {
verify_log_contents((ex_t[]){e1, e2, END});
}
+static void write_to_locked_log(char *lock_types[]) {
+ remove_logfile();
+ ex_t e1 = write_to_tl_append("begin\n");
+ FILE *f = fopen(FILENAME, "ae");
+ if (f == NULL)
+ die_err("Couldn't open file for locking");
+ for (int i = 0; lock_types[i]; i++)
+ take_lock(f, lock_types[0]);
+ pthread_t unlock_thread;
+ int create_ret =
+ pthread_create(&unlock_thread, NULL, &release_lock_after_delay, f);
+ if (create_ret != 0) {
+ errno = create_ret;
+ die_err("Couldn't start thread");
+ }
+ ex_t e2 = write_to_tl_append("delayed\n");
+ int join_ret = pthread_join(unlock_thread, NULL);
+ if (join_ret != 0) {
+ errno = join_ret;
+ die_err("Couldn't join thread");
+ }
+ verify_log_contents((ex_t[]){e1, e2, END});
+}
+
+static void write_concurrently() {
+ remove_logfile();
+ const int PARALLELISM = 250;
+ pthread_t threads[PARALLELISM];
+ pthread_rwlock_t start_signal;
+ pthread_rwlock_init(&start_signal, NULL);
+ for (int i = 0; i < PARALLELISM; i++) {
+ int create_ret =
+ pthread_create(&threads[i], NULL, &writer_thread, &start_signal);
+ if (create_ret != 0) {
+ errno = create_ret;
+ die_err("Couldn't start thread");
+ }
+ }
+ pthread_rwlock_unlock(&start_signal);
+ ex_t results[PARALLELISM + 1];
+ for (int i = 0; i < PARALLELISM; i++) {
+ ex_t *ex;
+ int join_ret = pthread_join(threads[i], (void **)&ex);
+ if (join_ret != 0) {
+ errno = join_ret;
+ die_err("Couldn't join thread");
+ }
+ results[i] = *ex;
+ free(ex);
+ }
+ results[PARALLELISM] = END;
+ verify_log_contents_unordered(results);
+ for (int i = 0; i < PARALLELISM; i++) {
+ free((void *)results[i].message);
+ }
+}
+
int main() {
test_encode_time();
write_and_read_line();
write_and_read_two_lines();
+ write_to_locked_log((char *[]){NULL});
+ write_to_locked_log((char *[]){"fcntl", NULL});
+ write_to_locked_log((char *[]){"flock", NULL});
+ write_to_locked_log((char *[]){"flock", "fcntl", NULL}); /* Deadlock risk! */
+ write_to_locked_log((char *[]){"fcntl", "flock", NULL});
+ write_concurrently();
}