]>
Commit | Line | Data |
---|---|---|
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 | } |