]>
Commit | Line | Data |
---|---|---|
ef591a4f SW |
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 | ||
b3d5ed96 | 18 | #define _POSIX_C_SOURCE 2 |
bab98a3a | 19 | #define _XOPEN_SOURCE |
8559ce11 | 20 | #define _GNU_SOURCE |
bab98a3a SW |
21 | #include <assert.h> |
22 | #include <ctype.h> | |
27dfbfeb | 23 | #include <errno.h> |
8559ce11 | 24 | #include <fcntl.h> |
90df84eb | 25 | #include <limits.h> |
8559ce11 | 26 | #include <pthread.h> |
b3d5ed96 SW |
27 | #include <stdio.h> |
28 | #include <stdlib.h> | |
29 | #include <string.h> | |
a1160bb5 | 30 | #include <sys/file.h> |
853b83c4 | 31 | #include <time.h> |
8559ce11 | 32 | #include <unistd.h> |
b3d5ed96 | 33 | |
d522116b SW |
34 | #include "common.h" |
35 | ||
2998af81 SW |
36 | const size_t TIMESTAMP_LEN = 19; |
37 | ||
71a7e5c5 | 38 | typedef struct expectation { |
853b83c4 | 39 | time_t a, b; |
eaaa0046 | 40 | const char *message; |
71a7e5c5 | 41 | } ex_t; |
eaaa0046 | 42 | |
853b83c4 | 43 | const ex_t END = {((time_t)-1), ((time_t)-1), NULL}; |
8559ce11 | 44 | const ex_t CONSUMED = {((time_t)-2), ((time_t)-2), NULL}; |
853b83c4 SW |
45 | static int is_end(ex_t exp) { |
46 | return exp.a == END.a && exp.b == END.b && exp.message == END.message; | |
47 | } | |
ee028f60 SW |
48 | static void consume(ex_t *exp) { |
49 | exp->a = CONSUMED.a; | |
50 | exp->b = CONSUMED.b; | |
51 | } | |
8559ce11 | 52 | static int is_consumed(ex_t exp) { |
ee028f60 | 53 | return exp.a == CONSUMED.a && exp.b == CONSUMED.b; |
8559ce11 | 54 | } |
853b83c4 | 55 | static ex_t expectation(time_t a, time_t b, const char *message) { |
71a7e5c5 | 56 | ex_t exp; |
853b83c4 SW |
57 | exp.a = a; |
58 | exp.b = b; | |
eaaa0046 SW |
59 | exp.message = message; |
60 | return exp; | |
61 | } | |
62 | ||
27dfbfeb | 63 | static void remove_logfile() { |
d522116b | 64 | if (remove(FILENAME) != 0) { |
27dfbfeb SW |
65 | if (errno != ENOENT) { |
66 | die_err("Error removing log file"); | |
67 | } | |
68 | } | |
69 | } | |
70 | ||
71a7e5c5 | 71 | static ex_t write_to_tl_append(const char *content) { |
b3d5ed96 SW |
72 | FILE *p = popen("./tl-append", "w"); |
73 | if (p == NULL) | |
74 | die_err("Couldn't run tl-append"); | |
d753115a | 75 | time_t start = time(NULL); |
aacfb261 | 76 | if (fputs(content, p) == EOF) |
b3d5ed96 SW |
77 | die("Couldn't write to pipe"); |
78 | int status = pclose(p); | |
d753115a | 79 | time_t end = time(NULL); |
b3d5ed96 SW |
80 | if (status < 0) |
81 | die_err("Error closing pipe"); | |
82 | if (status != 0) | |
83 | die("tl-append exited abnormally"); | |
d753115a | 84 | return expectation(start, end, content); |
aacfb261 SW |
85 | } |
86 | ||
8559ce11 | 87 | static char *timestamp_problem(const ex_t *ex, const char *line) { |
2998af81 SW |
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) | |
8559ce11 | 93 | return "Can't unpack current time?"; |
2998af81 SW |
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]) | |
8559ce11 | 97 | return "Wrong contents in log file: Couldn't parse timestamp"; |
2998af81 SW |
98 | time_t t = mktime(&tm); |
99 | int t_in_range = ex->a <= t && t <= ex->b; | |
100 | if (!t_in_range) | |
8559ce11 SW |
101 | return "Wrong contents in log file: Wrong time"; |
102 | return NULL; | |
2998af81 SW |
103 | } |
104 | ||
8559ce11 | 105 | static char *line_problem(const ex_t *ex, const char *line) { |
2998af81 SW |
106 | size_t line_len = strlen(line); |
107 | if (line_len < TIMESTAMP_LEN + 1) | |
8559ce11 SW |
108 | return "Wrong contents in log file: Line too short"; |
109 | char *trouble = timestamp_problem(ex, line); | |
110 | if (trouble) | |
111 | return trouble; | |
2998af81 | 112 | if (line[TIMESTAMP_LEN] != ' ') |
8559ce11 | 113 | return "Wrong contents in log file: Bad format"; |
2998af81 SW |
114 | if (strncmp(ex->message, &line[TIMESTAMP_LEN + 1], strlen(ex->message) + 1) != |
115 | 0) | |
8559ce11 SW |
116 | return "Wrong contents in log file"; |
117 | return NULL; | |
83acbf7e SW |
118 | } |
119 | ||
8559ce11 SW |
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 | } | |
b3d5ed96 | 125 | |
8559ce11 | 126 | static void verify_log_contents(const ex_t exps[]) { |
d522116b | 127 | FILE *f = fopen(FILENAME, "r"); |
b3d5ed96 SW |
128 | if (f == NULL) |
129 | die_err("Error opening log file"); | |
71a7e5c5 | 130 | for (size_t i = 0; !is_end(exps[i]); i++) { |
2998af81 | 131 | size_t len = TIMESTAMP_LEN + 1 + strlen(exps[i].message); |
90df84eb SW |
132 | if (len > INT_MAX - 1) |
133 | die("message too long"); | |
71a7e5c5 SW |
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"); | |
83acbf7e | 139 | verify_line(&exps[i], buf); |
71a7e5c5 SW |
140 | free(buf); |
141 | } | |
b3d5ed96 SW |
142 | if (fclose(f) != 0) |
143 | die_err("Error closing log file"); | |
144 | } | |
145 | ||
8559ce11 SW |
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) { | |
ee028f60 | 149 | consume(&exps[i]); |
8559ce11 SW |
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 | ||
bab98a3a SW |
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 | ||
9b76e9d2 | 194 | char *encoded = encode_time(tt); |
bab98a3a SW |
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'); | |
9b76e9d2 | 217 | free(encoded); |
bab98a3a SW |
218 | } |
219 | ||
a1160bb5 | 220 | static FILE *take_lock(FILE *f, char *lock_type) { |
8559ce11 SW |
221 | int fd = fileno(f); |
222 | if (fd == -1) | |
223 | die_err("Couldn't get file descriptor for locking"); | |
a1160bb5 SW |
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 | } | |
8559ce11 SW |
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) { | |
a1160bb5 | 246 | sleep(1); |
8559ce11 SW |
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 | ||
aacfb261 | 263 | static void write_and_read_line() { |
27dfbfeb | 264 | remove_logfile(); |
71a7e5c5 SW |
265 | ex_t e = write_to_tl_append("foo\n"); |
266 | verify_log_contents((ex_t[]){e, END}); | |
aacfb261 SW |
267 | } |
268 | ||
27dfbfeb SW |
269 | static void write_and_read_two_lines() { |
270 | remove_logfile(); | |
71a7e5c5 SW |
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}); | |
27dfbfeb SW |
274 | } |
275 | ||
a1160bb5 | 276 | static void write_to_locked_log(char *lock_types[]) { |
8559ce11 SW |
277 | remove_logfile(); |
278 | ex_t e1 = write_to_tl_append("begin\n"); | |
d212cd99 | 279 | FILE *f = fopen(FILENAME, "ae"); |
a1160bb5 SW |
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]); | |
8559ce11 SW |
284 | pthread_t unlock_thread; |
285 | int create_ret = | |
a1160bb5 | 286 | pthread_create(&unlock_thread, NULL, &release_lock_after_delay, f); |
8559ce11 SW |
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); | |
ee028f60 SW |
328 | for (int i = 0; i < PARALLELISM; i++) { |
329 | free((void *)results[i].message); | |
330 | } | |
8559ce11 SW |
331 | } |
332 | ||
27dfbfeb | 333 | int main() { |
bab98a3a | 334 | test_encode_time(); |
27dfbfeb SW |
335 | write_and_read_line(); |
336 | write_and_read_two_lines(); | |
a1160bb5 SW |
337 | write_to_locked_log((char *[]){NULL}); |
338 | write_to_locked_log((char *[]){"fcntl", NULL}); | |
339 | write_to_locked_log((char *[]){"flock", NULL}); | |
d212cd99 | 340 | write_to_locked_log((char *[]){"flock", "fcntl", NULL}); /* Deadlock risk! */ |
a1160bb5 | 341 | write_to_locked_log((char *[]){"fcntl", "flock", NULL}); |
8559ce11 | 342 | write_concurrently(); |
27dfbfeb | 343 | } |