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

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