1
2 #include "inc.h"
3
4 #include <fcntl.h>
5 #include <unistd.h>
6
7 /*
8 * The maximum number of bytes that may be buffered before writing the buffered
9 * output to the underlying file. This is a performance optimization only.
10 * Writing more than this number of bytes at once will be handled correctly.
11 */
12 #define OUTPUT_BUFSZ 512
13
14 static int out_fd;
15 static char out_buf[OUTPUT_BUFSZ];
16 static int out_len;
17 static int out_err;
18
19 static pid_t last_pid; /* not a trace_proc pointer; it could become invalid! */
20 static unsigned int line_off;
21 static unsigned int prefix_off;
22 static int print_pid;
23 static int print_susp;
24 static int add_space;
25
26 /*
27 * Initialize the output channel. Called before any other output functions,
28 * but after a child process (to be traced) has already been spawned. If the
29 * given file string is not NULL, it is the path to a file that is to be used
30 * to write output to. If it is NULL, output is written to standard error.
31 */
32 int
output_init(const char * file)33 output_init(const char * file)
34 {
35
36 /* Initialize state. */
37 out_len = 0;
38 out_err = FALSE;
39
40 last_pid = 0;
41 line_off = 0;
42 prefix_off = 0;
43 print_pid = FALSE;
44 print_susp = FALSE;
45 add_space = FALSE;
46
47 /*
48 * Ignore signals resulting from writing to a closed pipe. We can
49 * handle write errors properly ourselves. Setting O_NOSIGPIPE is an
50 * alternative, but that would affect other processes writing to the
51 * same file object, even after we have terminated.
52 */
53 signal(SIGPIPE, SIG_IGN);
54
55 /* Initialize the output file descriptor. */
56 if (file == NULL) {
57 /* No output file given? Use standard error. */
58 out_fd = STDERR_FILENO;
59
60 return 0;
61 } else {
62 /*
63 * Use a restrictive mask for the output file. Traces may
64 * contain sensitive information (for security and otherwise),
65 * and the user might not always be careful about the location
66 * of the file.
67 */
68 /* The file descriptor is not closed explicitly. */
69 out_fd = open(file, O_WRONLY | O_CREAT | O_TRUNC | O_APPEND,
70 0600);
71
72 return (out_fd < 0) ? -1 : 0;
73 }
74 }
75
76 /*
77 * Write the given data to the given file descriptor, taking into account the
78 * possibility of partial writes and write errors.
79 */
80 static void
write_fd(int fd,const char * buf,size_t len)81 write_fd(int fd, const char *buf, size_t len)
82 {
83 ssize_t r;
84
85 /* If we got a write error before, do not try to write more. */
86 if (out_err)
87 return;
88
89 /* Write all output, in chunks if we have to. */
90 while (len > 0) {
91 r = write(fd, buf, len);
92
93 /*
94 * A write error (and that includes EOF) causes the program to
95 * terminate with an error code. For obvious reasons we cannot
96 * print an error about this. Do not even report to standard
97 * error if the output was redirected, because that may mess
98 * with the actual programs being run right now.
99 */
100 if (r <= 0) {
101 out_err = TRUE;
102
103 break;
104 }
105
106 len -= r;
107 }
108 }
109
110 /*
111 * Return TRUE iff an output error occurred and the program should terminate.
112 */
113 int
output_error(void)114 output_error(void)
115 {
116
117 return out_err;
118 }
119
120 /*
121 * Print the given null-terminated string to the output channel. Return the
122 * number of characters printed, for alignment purposes. In the future, this
123 * number may end up being different from the number of bytes given to print,
124 * due to multibyte encoding or colors or whatnot.
125 */
126 static unsigned int
output_write(const char * text)127 output_write(const char * text)
128 {
129 size_t len;
130
131 len = strlen(text);
132
133 if (out_len + len > sizeof(out_buf)) {
134 write_fd(out_fd, out_buf, out_len);
135
136 out_len = 0;
137
138 /* Write large buffers right away. */
139 if (len > sizeof(out_buf)) {
140 write_fd(out_fd, text, len);
141
142 return len;
143 }
144 }
145
146 memcpy(&out_buf[out_len], text, len);
147
148 out_len += len;
149
150 return len;
151 }
152
153 /*
154 * Flush any pending output to the output channel.
155 */
156 void
output_flush(void)157 output_flush(void)
158 {
159
160 if (out_len > 0) {
161 write_fd(out_fd, out_buf, out_len);
162
163 out_len = 0;
164 }
165 }
166
167 /*
168 * Print a prefix for a line of output. Possibly print a timestamp first.
169 * Then, if applicable, print a PID prefix for the given process, or an info
170 * prefix if no process (NULL) is given.
171 *
172 * PIDs are relevant only when multiple processes are traced. As long as there
173 * are multiple processes, each line is prefixed with the PID of the process.
174 * As soon as the number of processes has been reduced back to one, one more
175 * line is prefixed with the PID of the remaining process (with a "'" instead
176 * of a "|") to help the user identify which process remains. In addition,
177 * whenever a preempted call is about to be resumed, a "*" is printed instead
178 * of a space, so as to show that it is a continuation of a previous line. An
179 * example of all these cases:
180 *
181 * fork() = 3
182 * 3| Tracing test (pid 3)
183 * 3| fork() = 0
184 * 3| read(0, <..>
185 * 2| waitpid(-1, <..>
186 * INFO| This is an example info line.
187 * 3|*read(0, "", 1024) = 0
188 * 3| exit(1)
189 * 3| Process exited normally with code 1
190 * 2'*waitpid(-1, W_EXITED(1), 0) = 3
191 * exit(0)
192 * Process exited normally with code 0
193 */
194 static void
put_prefix(struct trace_proc * proc,int resuming)195 put_prefix(struct trace_proc * proc, int resuming)
196 {
197 struct timeval tv;
198 struct tm *tm;
199 char prefix[32];
200 unsigned int off, count;
201
202 assert(line_off == 0);
203
204 off = 0;
205
206 if (timestamps > 0) {
207 gettimeofday(&tv, NULL);
208
209 tm = gmtime(&tv.tv_sec);
210
211 off = strftime(prefix, sizeof(prefix), "%T", tm);
212
213 if (timestamps > 1)
214 off += snprintf(&prefix[off], sizeof(prefix) - off,
215 ".%06u", tv.tv_usec);
216
217 assert(off < sizeof(prefix) - 2);
218 prefix[off++] = ' ';
219 prefix[off] = '\0';
220
221 off = output_write(prefix);
222 }
223
224 count = proc_count();
225
226 /* TODO: add a command line option for always printing the pid. */
227 if (print_pid || count > 1 || proc == NULL) {
228 /*
229 * TODO: we currently rely on the highest PID having at most
230 * five digits, but this will eventually change. There are
231 * several ways to deal with that, but none are great.
232 */
233 if (proc == NULL)
234 snprintf(prefix, sizeof(prefix), "%5s| ", "INFO");
235 else
236 snprintf(prefix, sizeof(prefix), "%5d%c%c",
237 proc->pid, (count > 1) ? '|' : '\'',
238 resuming ? '*' : ' ');
239
240 off += output_write(prefix);
241
242 last_pid = (proc != NULL ? proc->pid : 0);
243 } else
244 assert(!resuming);
245
246 prefix_off = off;
247 line_off += off;
248
249 /* Remember whether the next line should get prefixed regardless. */
250 print_pid = (count > 1 || proc == NULL);
251 }
252
253 /*
254 * Add a string to the end of the text recording for the given process.
255 * This is used only to record the call-enter output of system calls.
256 */
257 static void
record_add(struct trace_proc * proc,const char * text)258 record_add(struct trace_proc * proc, const char * text)
259 {
260 size_t len;
261
262 assert(proc->recording);
263
264 /* If the recording buffer is already full, do not record more. */
265 if (proc->outlen == sizeof(proc->outbuf))
266 return;
267
268 len = strlen(text);
269
270 /* If nonempty, the recording buffer is always null terminated. */
271 if (len < sizeof(proc->outbuf) - proc->outlen - 1) {
272 strcpy(&proc->outbuf[proc->outlen], text);
273
274 proc->outlen += len;
275 } else
276 proc->outlen = sizeof(proc->outbuf); /* buffer exhausted */
277 }
278
279 /*
280 * Start recording text for the given process. Since this marks the start of
281 * a call, remember to print a preemption marker when the call gets preempted.
282 */
283 void
record_start(struct trace_proc * proc)284 record_start(struct trace_proc * proc)
285 {
286
287 proc->recording = TRUE;
288
289 print_susp = TRUE;
290 }
291
292 /*
293 * Stop recording text for the given process.
294 */
295 void
record_stop(struct trace_proc * proc)296 record_stop(struct trace_proc * proc)
297 {
298
299 proc->recording = FALSE;
300 }
301
302 /*
303 * Clear recorded text for the given process. Since this also marks the end of
304 * the entire call, no longer print a supension marker before the next newline.
305 */
306 void
record_clear(struct trace_proc * proc)307 record_clear(struct trace_proc * proc)
308 {
309
310 assert(!proc->recording);
311 proc->outlen = 0;
312
313 if (proc->pid == last_pid)
314 print_susp = FALSE;
315 }
316
317 /*
318 * Replay the record for the given process on a new line, if the current line
319 * does not already have output for this process. If it does, do nothing.
320 * If the process has no recorded output, just start a new line. Return TRUE
321 * iff the caller must print its own replay text due to a recording overflow.
322 */
323 int
record_replay(struct trace_proc * proc)324 record_replay(struct trace_proc * proc)
325 {
326 int space;
327
328 assert(!proc->recording);
329
330 /*
331 * If there is output on the current line, and it is for the current
332 * process, we must assume that it is the original, recorded text, and
333 * thus, we should do nothing. If output on the current line is for
334 * another process, we must force a new line before replaying.
335 */
336 if (line_off > 0) {
337 if (proc->pid == last_pid)
338 return FALSE;
339
340 put_newline();
341 }
342
343 /*
344 * If there is nothing to replay, do nothing further. This case may
345 * occur when printing signals, in which case the caller still expects
346 * a new line to be started. This line must not be prefixed with a
347 * "resuming" marker though--after all, nothing is being resumed here.
348 */
349 if (proc->outlen == 0)
350 return FALSE;
351
352 /*
353 * If there is text to replay, then this does mean we are in effect
354 * resuming the recorded call, even if it is just to print a signal.
355 * Thus, we must print a prefix that shows the call is being resumed.
356 * Similarly, unless the recording is cleared before a newline, we must
357 * suspend the line again, too.
358 */
359 put_prefix(proc, TRUE /*resuming*/);
360
361 print_susp = TRUE;
362
363 /*
364 * If the recording buffer was exhausted during recording, the caller
365 * must generate the replay text instead.
366 */
367 if (proc->outlen == sizeof(proc->outbuf))
368 return TRUE;
369
370 /*
371 * Replay the recording. If it ends with a space, turn it into a soft
372 * space, because the recording may be followed immediately by a
373 * newline; an example of this is the exit() exception.
374 */
375 space = proc->outbuf[proc->outlen - 1] == ' ';
376 if (space)
377 proc->outbuf[proc->outlen - 1] = 0;
378
379 put_text(proc, proc->outbuf);
380
381 if (space) {
382 put_space(proc);
383
384 /* Restore the space, in case another replay takes place. */
385 proc->outbuf[proc->outlen - 1] = ' ';
386 }
387
388 return FALSE;
389 }
390
391 /*
392 * Start a new line, and adjust the local state accordingly. If nothing has
393 * been printed on the current line yet, this function is a no-op. Otherwise,
394 * the output so far may have to be marked as preempted with the "<..>"
395 * preemption marker.
396 */
397 void
put_newline(void)398 put_newline(void)
399 {
400
401 if (line_off == 0)
402 return;
403
404 if (print_susp) {
405 if (add_space)
406 (void)output_write(" ");
407
408 (void)output_write("<..>");
409 }
410
411 #if DEBUG
412 (void)output_write("|");
413 #endif
414
415 (void)output_write("\n");
416 output_flush();
417
418 line_off = 0;
419 add_space = FALSE;
420 print_susp = FALSE;
421 last_pid = 0;
422 }
423
424 /*
425 * Print a string as part of the output associated with a process. If the
426 * current line contains output for another process, a newline will be printed
427 * first. If the current line contains output for the same process, then the
428 * text will simply continue on the same line. If the current line is empty,
429 * a process PID prefix may have to be printed first. Either way, after this
430 * operation, the current line will contain text for the given process. If
431 * requested, the text may also be recorded for the process, for later replay.
432 * As an exception, proc may be NULL when printing general information lines.
433 */
434 void
put_text(struct trace_proc * proc,const char * text)435 put_text(struct trace_proc * proc, const char * text)
436 {
437
438 if (line_off > 0 && (proc == NULL || proc->pid != last_pid)) {
439 /*
440 * The current line has not been terminated with a newline yet.
441 * Start a new line. Note that this means that for lines not
442 * associated to a process, the whole line must be printed at
443 * once. This can be fixed but is currently not an issue.
444 */
445 put_newline();
446 }
447
448 /* See if we must add a prefix at the start of the line. */
449 if (line_off == 0)
450 put_prefix(proc, FALSE /*resuming*/);
451
452 /* If needed, record the given text. */
453 if (proc != NULL && proc->recording)
454 record_add(proc, text);
455
456 /*
457 * If we delayed printing a space, print one now. This is never part
458 * of text that must be saved. In fact, we support these soft spaces
459 * for exactly one case; see put_space() for details.
460 */
461 if (add_space) {
462 line_off += output_write(" ");
463
464 add_space = FALSE;
465 }
466
467 /* Finally, print the actual text. */
468 line_off += output_write(text);
469
470 last_pid = (proc != NULL) ? proc->pid : 0;
471 }
472
473 /*
474 * Add a space to the output for the given process, but only if and once more
475 * text is printed for the process afterwards. The aim is to ensure that no
476 * lines ever end with a space, to prevent needless line wrapping on terminals.
477 * The space may have to be remembered for the current line (for preemption,
478 * which does not have a process pointer to work with) as well as recorded for
479 * later replay, if recording is enabled. Consider the following example:
480 *
481 * [A] 3| execve(..) <..>
482 * 2| getpid(0) = 2 (ppid=1)
483 * [B] 3| execve(..) = -1 [ENOENT]
484 * [A] 3| exit(1) <..>
485 * 2| getpid(0) = 2 (ppid=1)
486 * 3| exit(1)
487 * 3| Process exited normally with code 1
488 *
489 * On the [A] lines, the space between the call's closing parenthesis and the
490 * "<..>" preemption marker is the result of add_space being set to TRUE; on
491 * the [B] line, the space between the closing parenthesis and the equals sign
492 * is the result of the space being recorded.
493 */
494 void
put_space(struct trace_proc * proc)495 put_space(struct trace_proc * proc)
496 {
497
498 /* This call must only be used after output for the given process. */
499 assert(last_pid == proc->pid);
500
501 /* In case the call does not get preempted. */
502 add_space = TRUE;
503
504 /* In case the call does get preempted. */
505 if (proc->recording)
506 record_add(proc, " ");
507 }
508
509 /*
510 * Indent the remainders of the text on the line for this process, such that
511 * similar remainders are similarly aligned. In particular, the remainder is
512 * the equals sign of a call, and everything after it. Of course, alignment
513 * can only be used if the call has not already printed beyond the alignment
514 * position. Also, the prefix must not be counted toward the alignment, as it
515 * is possible that a line without prefix may be preempted and later continued
516 * with prefix. All things considered, the result would look like this:
517 *
518 * getuid() = 1 (euid=1)
519 * setuid(0) = -1 [EPERM]
520 * write(2, "Permission denied\n", 18) = 18
521 * fork() = 3
522 * 3| Tracing test (pid 3)
523 * 3| fork() = 0
524 * 3| exit(0)
525 * 3| Process exited normally with code 0
526 * 2' waitpid(-1, W_EXITED(0), 0) = 3
527 *
528 */
put_align(struct trace_proc * __unused proc)529 void put_align(struct trace_proc * __unused proc)
530 {
531
532 /*
533 * TODO: add actual support for this. The following code works,
534 * although not so efficiently. The difficulty is the default
535 * configuration and corresponding options.
536
537 while (line_off - prefix_off < 20)
538 put_text(proc, " ");
539
540 */
541 }
542