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