]>
Commit | Line | Data |
---|---|---|
b3d5ed96 | 1 | #define _POSIX_C_SOURCE 2 |
bab98a3a | 2 | #define _XOPEN_SOURCE |
8559ce11 | 3 | #define _GNU_SOURCE |
bab98a3a SW |
4 | #include <assert.h> |
5 | #include <ctype.h> | |
27dfbfeb | 6 | #include <errno.h> |
8559ce11 | 7 | #include <fcntl.h> |
90df84eb | 8 | #include <limits.h> |
8559ce11 | 9 | #include <pthread.h> |
b3d5ed96 SW |
10 | #include <stdio.h> |
11 | #include <stdlib.h> | |
12 | #include <string.h> | |
a1160bb5 | 13 | #include <sys/file.h> |
853b83c4 | 14 | #include <time.h> |
8559ce11 | 15 | #include <unistd.h> |
b3d5ed96 | 16 | |
d522116b SW |
17 | #include "common.h" |
18 | ||
2998af81 SW |
19 | const size_t TIMESTAMP_LEN = 19; |
20 | ||
71a7e5c5 | 21 | typedef struct expectation { |
853b83c4 | 22 | time_t a, b; |
eaaa0046 | 23 | const char *message; |
71a7e5c5 | 24 | } ex_t; |
eaaa0046 | 25 | |
853b83c4 | 26 | const ex_t END = {((time_t)-1), ((time_t)-1), NULL}; |
8559ce11 | 27 | const ex_t CONSUMED = {((time_t)-2), ((time_t)-2), NULL}; |
853b83c4 SW |
28 | static int is_end(ex_t exp) { |
29 | return exp.a == END.a && exp.b == END.b && exp.message == END.message; | |
30 | } | |
ee028f60 SW |
31 | static void consume(ex_t *exp) { |
32 | exp->a = CONSUMED.a; | |
33 | exp->b = CONSUMED.b; | |
34 | } | |
8559ce11 | 35 | static int is_consumed(ex_t exp) { |
ee028f60 | 36 | return exp.a == CONSUMED.a && exp.b == CONSUMED.b; |
8559ce11 | 37 | } |
853b83c4 | 38 | static ex_t expectation(time_t a, time_t b, const char *message) { |
71a7e5c5 | 39 | ex_t exp; |
853b83c4 SW |
40 | exp.a = a; |
41 | exp.b = b; | |
eaaa0046 SW |
42 | exp.message = message; |
43 | return exp; | |
44 | } | |
45 | ||
27dfbfeb | 46 | static void remove_logfile() { |
d522116b | 47 | if (remove(FILENAME) != 0) { |
27dfbfeb SW |
48 | if (errno != ENOENT) { |
49 | die_err("Error removing log file"); | |
50 | } | |
51 | } | |
52 | } | |
53 | ||
71a7e5c5 | 54 | static ex_t write_to_tl_append(const char *content) { |
b3d5ed96 SW |
55 | FILE *p = popen("./tl-append", "w"); |
56 | if (p == NULL) | |
57 | die_err("Couldn't run tl-append"); | |
d753115a | 58 | time_t start = time(NULL); |
aacfb261 | 59 | if (fputs(content, p) == EOF) |
b3d5ed96 SW |
60 | die("Couldn't write to pipe"); |
61 | int status = pclose(p); | |
d753115a | 62 | time_t end = time(NULL); |
b3d5ed96 SW |
63 | if (status < 0) |
64 | die_err("Error closing pipe"); | |
65 | if (status != 0) | |
66 | die("tl-append exited abnormally"); | |
d753115a | 67 | return expectation(start, end, content); |
aacfb261 SW |
68 | } |
69 | ||
8559ce11 | 70 | static char *timestamp_problem(const ex_t *ex, const char *line) { |
2998af81 SW |
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) | |
8559ce11 | 76 | return "Can't unpack current time?"; |
2998af81 SW |
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]) | |
8559ce11 | 80 | return "Wrong contents in log file: Couldn't parse timestamp"; |
2998af81 SW |
81 | time_t t = mktime(&tm); |
82 | int t_in_range = ex->a <= t && t <= ex->b; | |
83 | if (!t_in_range) | |
8559ce11 SW |
84 | return "Wrong contents in log file: Wrong time"; |
85 | return NULL; | |
2998af81 SW |
86 | } |
87 | ||
8559ce11 | 88 | static char *line_problem(const ex_t *ex, const char *line) { |
2998af81 SW |
89 | size_t line_len = strlen(line); |
90 | if (line_len < TIMESTAMP_LEN + 1) | |
8559ce11 SW |
91 | return "Wrong contents in log file: Line too short"; |
92 | char *trouble = timestamp_problem(ex, line); | |
93 | if (trouble) | |
94 | return trouble; | |
2998af81 | 95 | if (line[TIMESTAMP_LEN] != ' ') |
8559ce11 | 96 | return "Wrong contents in log file: Bad format"; |
2998af81 SW |
97 | if (strncmp(ex->message, &line[TIMESTAMP_LEN + 1], strlen(ex->message) + 1) != |
98 | 0) | |
8559ce11 SW |
99 | return "Wrong contents in log file"; |
100 | return NULL; | |
83acbf7e SW |
101 | } |
102 | ||
8559ce11 SW |
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 | } | |
b3d5ed96 | 108 | |
8559ce11 | 109 | static void verify_log_contents(const ex_t exps[]) { |
d522116b | 110 | FILE *f = fopen(FILENAME, "r"); |
b3d5ed96 SW |
111 | if (f == NULL) |
112 | die_err("Error opening log file"); | |
71a7e5c5 | 113 | for (size_t i = 0; !is_end(exps[i]); i++) { |
2998af81 | 114 | size_t len = TIMESTAMP_LEN + 1 + strlen(exps[i].message); |
90df84eb SW |
115 | if (len > INT_MAX - 1) |
116 | die("message too long"); | |
71a7e5c5 SW |
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"); | |
83acbf7e | 122 | verify_line(&exps[i], buf); |
71a7e5c5 SW |
123 | free(buf); |
124 | } | |
b3d5ed96 SW |
125 | if (fclose(f) != 0) |
126 | die_err("Error closing log file"); | |
127 | } | |
128 | ||
8559ce11 SW |
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) { | |
ee028f60 | 132 | consume(&exps[i]); |
8559ce11 SW |
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 | ||
bab98a3a SW |
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 | ||
9b76e9d2 | 177 | char *encoded = encode_time(tt); |
bab98a3a SW |
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'); | |
9b76e9d2 | 200 | free(encoded); |
bab98a3a SW |
201 | } |
202 | ||
a1160bb5 | 203 | static FILE *take_lock(FILE *f, char *lock_type) { |
8559ce11 SW |
204 | int fd = fileno(f); |
205 | if (fd == -1) | |
206 | die_err("Couldn't get file descriptor for locking"); | |
a1160bb5 SW |
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 | } | |
8559ce11 SW |
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) { | |
a1160bb5 | 229 | sleep(1); |
8559ce11 SW |
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 | ||
aacfb261 | 246 | static void write_and_read_line() { |
27dfbfeb | 247 | remove_logfile(); |
71a7e5c5 SW |
248 | ex_t e = write_to_tl_append("foo\n"); |
249 | verify_log_contents((ex_t[]){e, END}); | |
aacfb261 SW |
250 | } |
251 | ||
27dfbfeb SW |
252 | static void write_and_read_two_lines() { |
253 | remove_logfile(); | |
71a7e5c5 SW |
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}); | |
27dfbfeb SW |
257 | } |
258 | ||
a1160bb5 | 259 | static void write_to_locked_log(char *lock_types[]) { |
8559ce11 SW |
260 | remove_logfile(); |
261 | ex_t e1 = write_to_tl_append("begin\n"); | |
d212cd99 | 262 | FILE *f = fopen(FILENAME, "ae"); |
a1160bb5 SW |
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]); | |
8559ce11 SW |
267 | pthread_t unlock_thread; |
268 | int create_ret = | |
a1160bb5 | 269 | pthread_create(&unlock_thread, NULL, &release_lock_after_delay, f); |
8559ce11 SW |
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); | |
ee028f60 SW |
311 | for (int i = 0; i < PARALLELISM; i++) { |
312 | free((void *)results[i].message); | |
313 | } | |
8559ce11 SW |
314 | } |
315 | ||
27dfbfeb | 316 | int main() { |
bab98a3a | 317 | test_encode_time(); |
27dfbfeb SW |
318 | write_and_read_line(); |
319 | write_and_read_two_lines(); | |
a1160bb5 SW |
320 | write_to_locked_log((char *[]){NULL}); |
321 | write_to_locked_log((char *[]){"fcntl", NULL}); | |
322 | write_to_locked_log((char *[]){"flock", NULL}); | |
d212cd99 | 323 | write_to_locked_log((char *[]){"flock", "fcntl", NULL}); /* Deadlock risk! */ |
a1160bb5 | 324 | write_to_locked_log((char *[]){"fcntl", "flock", NULL}); |
8559ce11 | 325 | write_concurrently(); |
27dfbfeb | 326 | } |