git.scottworley.com Git - tl-append/blob - tl-append-test.c

   1 /*
   2  * tl-append: time-logger appending shell
   3  * Copyright (C) 2023  Scott Worley <scottworley@scottworley.com>
   4  *
   5  * This program is free software: you can redistribute it and/or modify
   6  * it under the terms of the GNU General Public License as published by
   7  * the Free Software Foundation, version 3.
   8  *
   9  * This program is distributed in the hope that it will be useful,
  10  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  11  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  12  * GNU General Public License for more details.
  13  *
  14  * You should have received a copy of the GNU General Public License
  15  * along with this program.  If not, see <https://www.gnu.org/licenses/>.
  16  */
  17
  18 #define _POSIX_C_SOURCE 2
  19 #define _XOPEN_SOURCE
  20 #define _GNU_SOURCE
  21 #include <assert.h>
  22 #include <ctype.h>
  23 #include <errno.h>
  24 #include <fcntl.h>
  25 #include <limits.h>
  26 #include <pthread.h>
  27 #include <stdio.h>
  28 #include <stdlib.h>
  29 #include <string.h>
  30 #include <sys/file.h>
  31 #include <time.h>
  32 #include <unistd.h>
  33
  34 #include "common.h"
  35
  36 const size_t TIMESTAMP_LEN = 19;
  37
  38 typedef struct expectation {
  39   time_t a, b;
  40   const char *message;
  41 } ex_t;
  42
  43 const ex_t END = {((time_t)-1), ((time_t)-1), NULL};
  44 const ex_t CONSUMED = {((time_t)-2), ((time_t)-2), NULL};
  45 static int is_end(ex_t exp) {
  46   return exp.a == END.a && exp.b == END.b && exp.message == END.message;
  47 }
  48 static void consume(ex_t *exp) {
  49   exp->a = CONSUMED.a;
  50   exp->b = CONSUMED.b;
  51 }
  52 static int is_consumed(ex_t exp) {
  53   return exp.a == CONSUMED.a && exp.b == CONSUMED.b;
  54 }
  55 static ex_t expectation(time_t a, time_t b, const char *message) {
  56   ex_t exp;
  57   exp.a = a;
  58   exp.b = b;
  59   exp.message = message;
  60   return exp;
  61 }
  62
  63 static void remove_logfile() {
  64   if (remove(FILENAME) != 0) {
  65     if (errno != ENOENT) {
  66       die_err("Error removing log file");
  67     }
  68   }
  69 }
  70
  71 static ex_t write_to_tl_append(const char *content) {
  72   FILE *p = popen("./tl-append", "w");
  73   if (p == NULL)
  74     die_err("Couldn't run tl-append");
  75   time_t start = time(NULL);
  76   if (fputs(content, p) == EOF)
  77     die("Couldn't write to pipe");
  78   int status = pclose(p);
  79   time_t end = time(NULL);
  80   if (status < 0)
  81     die_err("Error closing pipe");
  82   if (status != 0)
  83     die("tl-append exited abnormally");
  84   return expectation(start, end, content);
  85 }
  86
  87 static char *timestamp_problem(const ex_t *ex, const char *line) {
  88   struct tm tm;
  89
  90   /* localtime_r to set tm's timezone */
  91   time_t now_time = time(NULL);
  92   if (localtime_r(&now_time, &tm) == NULL)
  93     return "Can't unpack current time?";
  94
  95   const char *strptime_result = strptime(line, "%Y %m %d %H %M %S", &tm);
  96   if (strptime_result == NULL || strptime_result != &line[TIMESTAMP_LEN])
  97     return "Wrong contents in log file: Couldn't parse timestamp";
  98   time_t t = mktime(&tm);
  99   int t_in_range = ex->a <= t && t <= ex->b;
 100   if (!t_in_range)
 101     return "Wrong contents in log file: Wrong time";
 102   return NULL;
 103 }
 104
 105 static char *line_problem(const ex_t *ex, const char *line) {
 106   size_t line_len = strlen(line);
 107   if (line_len < TIMESTAMP_LEN + 1)
 108     return "Wrong contents in log file: Line too short";
 109   char *trouble = timestamp_problem(ex, line);
 110   if (trouble)
 111     return trouble;
 112   if (line[TIMESTAMP_LEN] != ' ')
 113     return "Wrong contents in log file: Bad format";
 114   if (strncmp(ex->message, &line[TIMESTAMP_LEN + 1], strlen(ex->message) + 1) !=
 115       0)
 116     return "Wrong contents in log file";
 117   return NULL;
 118 }
 119
 120 static void verify_line(const ex_t *ex, const char *line) {
 121   char *trouble = line_problem(ex, line);
 122   if (trouble)
 123     die(trouble);
 124 }
 125
 126 static void verify_log_contents(const ex_t exps[]) {
 127   FILE *f = fopen(FILENAME, "r");
 128   if (f == NULL)
 129     die_err("Error opening log file");
 130   for (size_t i = 0; !is_end(exps[i]); i++) {
 131     size_t len = TIMESTAMP_LEN + 1 + strlen(exps[i].message);
 132     if (len > INT_MAX - 1)
 133       die("message too long");
 134     char *buf = (char *)malloc(len + 2);
 135     if (fgets(buf, len + 1, f) == NULL)
 136       die("Error reading log file");
 137     if (ferror(f))
 138       die("Error reading log file");
 139     verify_line(&exps[i], buf);
 140     free(buf);
 141   }
 142   if (fclose(f) != 0)
 143     die_err("Error closing log file");
 144 }
 145
 146 static void consume_expectation(ex_t exps[], const char *line) {
 147   for (size_t i = 0; !is_end(exps[i]); i++) {
 148     if (line_problem(&exps[i], line) == NULL) {
 149       consume(&exps[i]);
 150       return;
 151     }
 152   }
 153   die("Wrong contents in log file: Line didn't match any expectation");
 154 }
 155
 156 static void verify_log_contents_unordered(ex_t exps[]) {
 157   FILE *f = fopen(FILENAME, "r");
 158   if (f == NULL)
 159     die_err("Error opening log file");
 160   for (;;) {
 161     const int MAX_LEN = 9999;
 162     char buf[MAX_LEN];
 163     if (fgets(buf, MAX_LEN, f) == NULL) {
 164       if (feof(f))
 165         break;
 166       die("Error reading log file");
 167     }
 168     if (ferror(f))
 169       die("Error reading log file");
 170     consume_expectation(exps, buf);
 171   }
 172   if (fclose(f) != 0)
 173     die_err("Error closing log file");
 174   for (size_t i = 0; !is_end(exps[i]); i++) {
 175     if (!is_consumed(exps[i]))
 176       die("Wrong contents in log file: Unconsumed expectation");
 177   }
 178 }
 179
 180 static void test_encode_time() {
 181   /* localtime_r to set tm's timezone */
 182   time_t now_time = time(NULL);
 183   struct tm tm;
 184   if (localtime_r(&now_time, &tm) == NULL)
 185     die_err("Can't unpack current time?");
 186
 187   const char *strptime_result = strptime("2011-12-13 14:15:16", "%F %T", &tm);
 188   if (strptime_result == NULL || *strptime_result != '\0')
 189     die("Couldn't parse time?");
 190   time_t tt = mktime(&tm);
 191   if (tt == (time_t)-1)
 192     die_err("Can't pack time?");
 193
 194   char *encoded = encode_time(tt);
 195   /* Loose check to allow for daylight savings time changes between the current
 196    * time and the target time.  :( */
 197   assert(encoded[0] == '2');
 198   assert(encoded[1] == '0');
 199   assert(encoded[2] == '1');
 200   assert(encoded[3] == '1');
 201   assert(encoded[4] == ' ');
 202   assert(encoded[5] == '1');
 203   assert(encoded[6] == '2');
 204   assert(encoded[7] == ' ');
 205   assert(encoded[8] == '1');
 206   assert(encoded[9] == '3');
 207   assert(encoded[10] == ' ');
 208   assert(encoded[11] == '1');
 209   assert(isdigit(encoded[12]));
 210   assert(encoded[13] == ' ');
 211   assert(isdigit(encoded[14]));
 212   assert(isdigit(encoded[15]));
 213   assert(encoded[16] == ' ');
 214   assert(encoded[17] == '1');
 215   assert(encoded[18] == '6');
 216   assert(encoded[19] == '\0');
 217   free(encoded);
 218 }
 219
 220 static FILE *take_lock(FILE *f, char *lock_type) {
 221   int fd = fileno(f);
 222   if (fd == -1)
 223     die_err("Couldn't get file descriptor for locking");
 224   if (strcmp(lock_type, "fcntl") == 0) {
 225     if (fcntl(fd, F_SETLK,
 226               &(struct flock){.l_type = F_WRLCK,
 227                               .l_whence = SEEK_SET,
 228                               .l_start = 0,
 229                               .l_len = 0}) == -1)
 230       die_err("Couldn't take fcntl lock");
 231   } else if (strcmp(lock_type, "flock") == 0) {
 232     if (flock(fd, LOCK_EX) == -1)
 233       die_err("Couldn't take flock lock");
 234   } else {
 235     die("Bad lock type");
 236   }
 237   return f;
 238 }
 239
 240 static void release_lock(FILE *f) {
 241   if (fclose(f) != 0)
 242     die_err("Error releasing lock");
 243 }
 244
 245 static void *release_lock_after_delay(void *f) {
 246   sleep(1);
 247   release_lock((FILE *)f);
 248   return NULL;
 249 }
 250
 251 static void *writer_thread(void *start_signal) {
 252   ex_t *ex = (ex_t *)malloc(sizeof(ex_t));
 253   if (ex == NULL)
 254     die_err("Couldn't allocate memory");
 255   char *message;
 256   if (asprintf(&message, "Hello from thread %lu\n", pthread_self()) == -1)
 257     die("Couldn't prepare message");
 258   pthread_rwlock_rdlock((pthread_rwlock_t *)start_signal);
 259   *ex = write_to_tl_append(message);
 260   return ex;
 261 }
 262
 263 static void write_and_read_line() {
 264   remove_logfile();
 265   ex_t e = write_to_tl_append("foo\n");
 266   verify_log_contents((ex_t[]){e, END});
 267 }
 268
 269 static void write_and_read_two_lines() {
 270   remove_logfile();
 271   ex_t e1 = write_to_tl_append("foo\n");
 272   ex_t e2 = write_to_tl_append("bar\n");
 273   verify_log_contents((ex_t[]){e1, e2, END});
 274 }
 275
 276 static void write_to_locked_log(char *lock_types[]) {
 277   remove_logfile();
 278   ex_t e1 = write_to_tl_append("begin\n");
 279   FILE *f = fopen(FILENAME, "ae");
 280   if (f == NULL)
 281     die_err("Couldn't open file for locking");
 282   for (int i = 0; lock_types[i]; i++)
 283     take_lock(f, lock_types[0]);
 284   pthread_t unlock_thread;
 285   int create_ret =
 286       pthread_create(&unlock_thread, NULL, &release_lock_after_delay, f);
 287   if (create_ret != 0) {
 288     errno = create_ret;
 289     die_err("Couldn't start thread");
 290   }
 291   ex_t e2 = write_to_tl_append("delayed\n");
 292   int join_ret = pthread_join(unlock_thread, NULL);
 293   if (join_ret != 0) {
 294     errno = join_ret;
 295     die_err("Couldn't join thread");
 296   }
 297   verify_log_contents((ex_t[]){e1, e2, END});
 298 }
 299
 300 static void write_concurrently() {
 301   remove_logfile();
 302   const int PARALLELISM = 250;
 303   pthread_t threads[PARALLELISM];
 304   pthread_rwlock_t start_signal;
 305   pthread_rwlock_init(&start_signal, NULL);
 306   for (int i = 0; i < PARALLELISM; i++) {
 307     int create_ret =
 308         pthread_create(&threads[i], NULL, &writer_thread, &start_signal);
 309     if (create_ret != 0) {
 310       errno = create_ret;
 311       die_err("Couldn't start thread");
 312     }
 313   }
 314   pthread_rwlock_unlock(&start_signal);
 315   ex_t results[PARALLELISM + 1];
 316   for (int i = 0; i < PARALLELISM; i++) {
 317     ex_t *ex;
 318     int join_ret = pthread_join(threads[i], (void **)&ex);
 319     if (join_ret != 0) {
 320       errno = join_ret;
 321       die_err("Couldn't join thread");
 322     }
 323     results[i] = *ex;
 324     free(ex);
 325   }
 326   results[PARALLELISM] = END;
 327   verify_log_contents_unordered(results);
 328   for (int i = 0; i < PARALLELISM; i++) {
 329     free((void *)results[i].message);
 330   }
 331 }
 332
 333 int main() {
 334   test_encode_time();
 335   write_and_read_line();
 336   write_and_read_two_lines();
 337   write_to_locked_log((char *[]){NULL});
 338   write_to_locked_log((char *[]){"fcntl", NULL});
 339   write_to_locked_log((char *[]){"flock", NULL});
 340   write_to_locked_log((char *[]){"flock", "fcntl", NULL}); /* Deadlock risk! */
 341   write_to_locked_log((char *[]){"fcntl", "flock", NULL});
 342   write_concurrently();
 343 }