1 /*
2 * Copyright (C) 2008 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include <errno.h>
18 #include <fcntl.h>
19 #include <libgen.h>
20 #include <poll.h>
21 #include <pthread.h>
22 #include <stdbool.h>
23 #include <stdio.h>
24 #include <stdlib.h>
25 #include <string.h>
26 #include <sys/socket.h>
27 #include <sys/types.h>
28 #include <sys/wait.h>
29 #include <unistd.h>
30
31 #include <cutils/klog.h>
32 #include <log/log.h>
33 #include <logwrap/logwrap.h>
34
35 #define ARRAY_SIZE(x) (sizeof(x) / sizeof(*(x)))
36 #define MIN(a,b) (((a)<(b))?(a):(b))
37
38 static pthread_mutex_t fd_mutex = PTHREAD_MUTEX_INITIALIZER;
39
40 #define ERROR(fmt, args...) \
41 do { \
42 fprintf(stderr, fmt, ## args); \
43 ALOG(LOG_ERROR, "logwrapper", fmt, ## args); \
44 } while(0)
45
46 #define FATAL_CHILD(fmt, args...) \
47 do { \
48 ERROR(fmt, ## args); \
49 _exit(-1); \
50 } while(0)
51
52 #define MAX_KLOG_TAG 16
53
54 /* This is a simple buffer that holds up to the first beginning_buf->buf_size
55 * bytes of output from a command.
56 */
57 #define BEGINNING_BUF_SIZE 0x1000
58 struct beginning_buf {
59 char *buf;
60 size_t alloc_len;
61 /* buf_size is the usable space, which is one less than the allocated size */
62 size_t buf_size;
63 size_t used_len;
64 };
65
66 /* This is a circular buf that holds up to the last ending_buf->buf_size bytes
67 * of output from a command after the first beginning_buf->buf_size bytes
68 * (which are held in beginning_buf above).
69 */
70 #define ENDING_BUF_SIZE 0x1000
71 struct ending_buf {
72 char *buf;
73 ssize_t alloc_len;
74 /* buf_size is the usable space, which is one less than the allocated size */
75 ssize_t buf_size;
76 ssize_t used_len;
77 /* read and write offsets into the circular buffer */
78 int read;
79 int write;
80 };
81
82 /* A structure to hold all the abbreviated buf data */
83 struct abbr_buf {
84 struct beginning_buf b_buf;
85 struct ending_buf e_buf;
86 int beginning_buf_full;
87 };
88
89 /* Collect all the various bits of info needed for logging in one place. */
90 struct log_info {
91 int log_target;
92 char klog_fmt[MAX_KLOG_TAG * 2];
93 char *btag;
94 bool abbreviated;
95 FILE *fp;
96 struct abbr_buf a_buf;
97 };
98
99 /* Forware declaration */
100 static void add_line_to_abbr_buf(struct abbr_buf *a_buf, char *linebuf, int linelen);
101
102 /* Return 0 on success, and 1 when full */
add_line_to_linear_buf(struct beginning_buf * b_buf,char * line,ssize_t line_len)103 static int add_line_to_linear_buf(struct beginning_buf *b_buf,
104 char *line, ssize_t line_len)
105 {
106 int full = 0;
107
108 if ((line_len + b_buf->used_len) > b_buf->buf_size) {
109 full = 1;
110 } else {
111 /* Add to the end of the buf */
112 memcpy(b_buf->buf + b_buf->used_len, line, line_len);
113 b_buf->used_len += line_len;
114 }
115
116 return full;
117 }
118
add_line_to_circular_buf(struct ending_buf * e_buf,char * line,ssize_t line_len)119 static void add_line_to_circular_buf(struct ending_buf *e_buf,
120 char *line, ssize_t line_len)
121 {
122 ssize_t free_len;
123 ssize_t needed_space;
124 int cnt;
125
126 if (e_buf->buf == NULL) {
127 return;
128 }
129
130 if (line_len > e_buf->buf_size) {
131 return;
132 }
133
134 free_len = e_buf->buf_size - e_buf->used_len;
135
136 if (line_len > free_len) {
137 /* remove oldest entries at read, and move read to make
138 * room for the new string */
139 needed_space = line_len - free_len;
140 e_buf->read = (e_buf->read + needed_space) % e_buf->buf_size;
141 e_buf->used_len -= needed_space;
142 }
143
144 /* Copy the line into the circular buffer, dealing with possible
145 * wraparound.
146 */
147 cnt = MIN(line_len, e_buf->buf_size - e_buf->write);
148 memcpy(e_buf->buf + e_buf->write, line, cnt);
149 if (cnt < line_len) {
150 memcpy(e_buf->buf, line + cnt, line_len - cnt);
151 }
152 e_buf->used_len += line_len;
153 e_buf->write = (e_buf->write + line_len) % e_buf->buf_size;
154 }
155
156 /* Log directly to the specified log */
do_log_line(struct log_info * log_info,char * line)157 static void do_log_line(struct log_info *log_info, char *line) {
158 if (log_info->log_target & LOG_KLOG) {
159 klog_write(6, log_info->klog_fmt, line);
160 }
161 if (log_info->log_target & LOG_ALOG) {
162 ALOG(LOG_INFO, log_info->btag, "%s", line);
163 }
164 if (log_info->log_target & LOG_FILE) {
165 fprintf(log_info->fp, "%s\n", line);
166 }
167 }
168
169 /* Log to either the abbreviated buf, or directly to the specified log
170 * via do_log_line() above.
171 */
log_line(struct log_info * log_info,char * line,int len)172 static void log_line(struct log_info *log_info, char *line, int len) {
173 if (log_info->abbreviated) {
174 add_line_to_abbr_buf(&log_info->a_buf, line, len);
175 } else {
176 do_log_line(log_info, line);
177 }
178 }
179
180 /*
181 * The kernel will take a maximum of 1024 bytes in any single write to
182 * the kernel logging device file, so find and print each line one at
183 * a time. The allocated size for buf should be at least 1 byte larger
184 * than buf_size (the usable size of the buffer) to make sure there is
185 * room to temporarily stuff a null byte to terminate a line for logging.
186 */
print_buf_lines(struct log_info * log_info,char * buf,int buf_size)187 static void print_buf_lines(struct log_info *log_info, char *buf, int buf_size)
188 {
189 char *line_start;
190 char c;
191 int i;
192
193 line_start = buf;
194 for (i = 0; i < buf_size; i++) {
195 if (*(buf + i) == '\n') {
196 /* Found a line ending, print the line and compute new line_start */
197 /* Save the next char and replace with \0 */
198 c = *(buf + i + 1);
199 *(buf + i + 1) = '\0';
200 do_log_line(log_info, line_start);
201 /* Restore the saved char */
202 *(buf + i + 1) = c;
203 line_start = buf + i + 1;
204 } else if (*(buf + i) == '\0') {
205 /* The end of the buffer, print the last bit */
206 do_log_line(log_info, line_start);
207 break;
208 }
209 }
210 /* If the buffer was completely full, and didn't end with a newline, just
211 * ignore the partial last line.
212 */
213 }
214
init_abbr_buf(struct abbr_buf * a_buf)215 static void init_abbr_buf(struct abbr_buf *a_buf) {
216 char *new_buf;
217
218 memset(a_buf, 0, sizeof(struct abbr_buf));
219 new_buf = malloc(BEGINNING_BUF_SIZE);
220 if (new_buf) {
221 a_buf->b_buf.buf = new_buf;
222 a_buf->b_buf.alloc_len = BEGINNING_BUF_SIZE;
223 a_buf->b_buf.buf_size = BEGINNING_BUF_SIZE - 1;
224 }
225 new_buf = malloc(ENDING_BUF_SIZE);
226 if (new_buf) {
227 a_buf->e_buf.buf = new_buf;
228 a_buf->e_buf.alloc_len = ENDING_BUF_SIZE;
229 a_buf->e_buf.buf_size = ENDING_BUF_SIZE - 1;
230 }
231 }
232
free_abbr_buf(struct abbr_buf * a_buf)233 static void free_abbr_buf(struct abbr_buf *a_buf) {
234 free(a_buf->b_buf.buf);
235 free(a_buf->e_buf.buf);
236 }
237
add_line_to_abbr_buf(struct abbr_buf * a_buf,char * linebuf,int linelen)238 static void add_line_to_abbr_buf(struct abbr_buf *a_buf, char *linebuf, int linelen) {
239 if (!a_buf->beginning_buf_full) {
240 a_buf->beginning_buf_full =
241 add_line_to_linear_buf(&a_buf->b_buf, linebuf, linelen);
242 }
243 if (a_buf->beginning_buf_full) {
244 add_line_to_circular_buf(&a_buf->e_buf, linebuf, linelen);
245 }
246 }
247
print_abbr_buf(struct log_info * log_info)248 static void print_abbr_buf(struct log_info *log_info) {
249 struct abbr_buf *a_buf = &log_info->a_buf;
250
251 /* Add the abbreviated output to the kernel log */
252 if (a_buf->b_buf.alloc_len) {
253 print_buf_lines(log_info, a_buf->b_buf.buf, a_buf->b_buf.used_len);
254 }
255
256 /* Print an ellipsis to indicate that the buffer has wrapped or
257 * is full, and some data was not logged.
258 */
259 if (a_buf->e_buf.used_len == a_buf->e_buf.buf_size) {
260 do_log_line(log_info, "...\n");
261 }
262
263 if (a_buf->e_buf.used_len == 0) {
264 return;
265 }
266
267 /* Simplest way to print the circular buffer is allocate a second buf
268 * of the same size, and memcpy it so it's a simple linear buffer,
269 * and then cal print_buf_lines on it */
270 if (a_buf->e_buf.read < a_buf->e_buf.write) {
271 /* no wrap around, just print it */
272 print_buf_lines(log_info, a_buf->e_buf.buf + a_buf->e_buf.read,
273 a_buf->e_buf.used_len);
274 } else {
275 /* The circular buffer will always have at least 1 byte unused,
276 * so by allocating alloc_len here we will have at least
277 * 1 byte of space available as required by print_buf_lines().
278 */
279 char * nbuf = malloc(a_buf->e_buf.alloc_len);
280 if (!nbuf) {
281 return;
282 }
283 int first_chunk_len = a_buf->e_buf.buf_size - a_buf->e_buf.read;
284 memcpy(nbuf, a_buf->e_buf.buf + a_buf->e_buf.read, first_chunk_len);
285 /* copy second chunk */
286 memcpy(nbuf + first_chunk_len, a_buf->e_buf.buf, a_buf->e_buf.write);
287 print_buf_lines(log_info, nbuf, first_chunk_len + a_buf->e_buf.write);
288 free(nbuf);
289 }
290 }
291
parent(const char * tag,int parent_read,pid_t pid,int * chld_sts,int log_target,bool abbreviated,char * file_path)292 static int parent(const char *tag, int parent_read, pid_t pid,
293 int *chld_sts, int log_target, bool abbreviated, char *file_path) {
294 int status = 0;
295 char buffer[4096];
296 struct pollfd poll_fds[] = {
297 [0] = {
298 .fd = parent_read,
299 .events = POLLIN,
300 },
301 };
302 int rc = 0;
303 int fd;
304
305 struct log_info log_info;
306
307 int a = 0; // start index of unprocessed data
308 int b = 0; // end index of unprocessed data
309 int sz;
310 bool found_child = false;
311 char tmpbuf[256];
312
313 log_info.btag = basename(tag);
314 if (!log_info.btag) {
315 log_info.btag = (char*) tag;
316 }
317
318 if (abbreviated && (log_target == LOG_NONE)) {
319 abbreviated = 0;
320 }
321 if (abbreviated) {
322 init_abbr_buf(&log_info.a_buf);
323 }
324
325 if (log_target & LOG_KLOG) {
326 snprintf(log_info.klog_fmt, sizeof(log_info.klog_fmt),
327 "<6>%.*s: %%s\n", MAX_KLOG_TAG, log_info.btag);
328 }
329
330 if ((log_target & LOG_FILE) && !file_path) {
331 /* No file_path specified, clear the LOG_FILE bit */
332 log_target &= ~LOG_FILE;
333 }
334
335 if (log_target & LOG_FILE) {
336 fd = open(file_path, O_WRONLY | O_CREAT, 0664);
337 if (fd < 0) {
338 ERROR("Cannot log to file %s\n", file_path);
339 log_target &= ~LOG_FILE;
340 } else {
341 lseek(fd, 0, SEEK_END);
342 log_info.fp = fdopen(fd, "a");
343 }
344 }
345
346 log_info.log_target = log_target;
347 log_info.abbreviated = abbreviated;
348
349 while (!found_child) {
350 if (TEMP_FAILURE_RETRY(poll(poll_fds, ARRAY_SIZE(poll_fds), -1)) < 0) {
351 ERROR("poll failed\n");
352 rc = -1;
353 goto err_poll;
354 }
355
356 if (poll_fds[0].revents & POLLIN) {
357 sz = TEMP_FAILURE_RETRY(
358 read(parent_read, &buffer[b], sizeof(buffer) - 1 - b));
359
360 sz += b;
361 // Log one line at a time
362 for (b = 0; b < sz; b++) {
363 if (buffer[b] == '\r') {
364 if (abbreviated) {
365 /* The abbreviated logging code uses newline as
366 * the line separator. Lucikly, the pty layer
367 * helpfully cooks the output of the command
368 * being run and inserts a CR before NL. So
369 * I just change it to NL here when doing
370 * abbreviated logging.
371 */
372 buffer[b] = '\n';
373 } else {
374 buffer[b] = '\0';
375 }
376 } else if (buffer[b] == '\n') {
377 buffer[b] = '\0';
378 log_line(&log_info, &buffer[a], b - a);
379 a = b + 1;
380 }
381 }
382
383 if (a == 0 && b == sizeof(buffer) - 1) {
384 // buffer is full, flush
385 buffer[b] = '\0';
386 log_line(&log_info, &buffer[a], b - a);
387 b = 0;
388 } else if (a != b) {
389 // Keep left-overs
390 b -= a;
391 memmove(buffer, &buffer[a], b);
392 a = 0;
393 } else {
394 a = 0;
395 b = 0;
396 }
397 }
398
399 if (poll_fds[0].revents & POLLHUP) {
400 int ret;
401
402 ret = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0));
403 if (ret < 0) {
404 rc = errno;
405 ALOG(LOG_ERROR, "logwrap", "waitpid failed with %s\n", strerror(errno));
406 goto err_waitpid;
407 }
408 if (ret > 0) {
409 found_child = true;
410 }
411 }
412 }
413
414 if (chld_sts != NULL) {
415 *chld_sts = status;
416 } else {
417 if (WIFEXITED(status))
418 rc = WEXITSTATUS(status);
419 else
420 rc = -ECHILD;
421 }
422
423 // Flush remaining data
424 if (a != b) {
425 buffer[b] = '\0';
426 log_line(&log_info, &buffer[a], b - a);
427 }
428
429 /* All the output has been processed, time to dump the abbreviated output */
430 if (abbreviated) {
431 print_abbr_buf(&log_info);
432 }
433
434 if (WIFEXITED(status)) {
435 if (WEXITSTATUS(status)) {
436 snprintf(tmpbuf, sizeof(tmpbuf),
437 "%s terminated by exit(%d)\n", log_info.btag, WEXITSTATUS(status));
438 do_log_line(&log_info, tmpbuf);
439 }
440 } else {
441 if (WIFSIGNALED(status)) {
442 snprintf(tmpbuf, sizeof(tmpbuf),
443 "%s terminated by signal %d\n", log_info.btag, WTERMSIG(status));
444 do_log_line(&log_info, tmpbuf);
445 } else if (WIFSTOPPED(status)) {
446 snprintf(tmpbuf, sizeof(tmpbuf),
447 "%s stopped by signal %d\n", log_info.btag, WSTOPSIG(status));
448 do_log_line(&log_info, tmpbuf);
449 }
450 }
451
452 err_waitpid:
453 err_poll:
454 if (log_target & LOG_FILE) {
455 fclose(log_info.fp); /* Also closes underlying fd */
456 }
457 if (abbreviated) {
458 free_abbr_buf(&log_info.a_buf);
459 }
460 return rc;
461 }
462
child(int argc,char * argv[])463 static void child(int argc, char* argv[]) {
464 // create null terminated argv_child array
465 char* argv_child[argc + 1];
466 memcpy(argv_child, argv, argc * sizeof(char *));
467 argv_child[argc] = NULL;
468
469 if (execvp(argv_child[0], argv_child)) {
470 FATAL_CHILD("executing %s failed: %s\n", argv_child[0],
471 strerror(errno));
472 }
473 }
474
android_fork_execvp_ext(int argc,char * argv[],int * status,bool ignore_int_quit,int log_target,bool abbreviated,char * file_path,void * unused_opts,int unused_opts_len)475 int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit,
476 int log_target, bool abbreviated, char *file_path,
477 void *unused_opts, int unused_opts_len) {
478 pid_t pid;
479 int parent_ptty;
480 int child_ptty;
481 struct sigaction intact;
482 struct sigaction quitact;
483 sigset_t blockset;
484 sigset_t oldset;
485 int rc = 0;
486
487 LOG_ALWAYS_FATAL_IF(unused_opts != NULL);
488 LOG_ALWAYS_FATAL_IF(unused_opts_len != 0);
489
490 rc = pthread_mutex_lock(&fd_mutex);
491 if (rc) {
492 ERROR("failed to lock signal_fd mutex\n");
493 goto err_lock;
494 }
495
496 /* Use ptty instead of socketpair so that STDOUT is not buffered */
497 parent_ptty = TEMP_FAILURE_RETRY(open("/dev/ptmx", O_RDWR));
498 if (parent_ptty < 0) {
499 ERROR("Cannot create parent ptty\n");
500 rc = -1;
501 goto err_open;
502 }
503
504 char child_devname[64];
505 if (grantpt(parent_ptty) || unlockpt(parent_ptty) ||
506 ptsname_r(parent_ptty, child_devname, sizeof(child_devname)) != 0) {
507 ERROR("Problem with /dev/ptmx\n");
508 rc = -1;
509 goto err_ptty;
510 }
511
512 child_ptty = TEMP_FAILURE_RETRY(open(child_devname, O_RDWR));
513 if (child_ptty < 0) {
514 ERROR("Cannot open child_ptty\n");
515 rc = -1;
516 goto err_child_ptty;
517 }
518
519 sigemptyset(&blockset);
520 sigaddset(&blockset, SIGINT);
521 sigaddset(&blockset, SIGQUIT);
522 pthread_sigmask(SIG_BLOCK, &blockset, &oldset);
523
524 pid = fork();
525 if (pid < 0) {
526 close(child_ptty);
527 ERROR("Failed to fork\n");
528 rc = -1;
529 goto err_fork;
530 } else if (pid == 0) {
531 pthread_mutex_unlock(&fd_mutex);
532 pthread_sigmask(SIG_SETMASK, &oldset, NULL);
533 close(parent_ptty);
534
535 dup2(child_ptty, 1);
536 dup2(child_ptty, 2);
537 close(child_ptty);
538
539 child(argc, argv);
540 } else {
541 close(child_ptty);
542 if (ignore_int_quit) {
543 struct sigaction ignact;
544
545 memset(&ignact, 0, sizeof(ignact));
546 ignact.sa_handler = SIG_IGN;
547 sigaction(SIGINT, &ignact, &intact);
548 sigaction(SIGQUIT, &ignact, &quitact);
549 }
550
551 rc = parent(argv[0], parent_ptty, pid, status, log_target,
552 abbreviated, file_path);
553 }
554
555 if (ignore_int_quit) {
556 sigaction(SIGINT, &intact, NULL);
557 sigaction(SIGQUIT, &quitact, NULL);
558 }
559 err_fork:
560 pthread_sigmask(SIG_SETMASK, &oldset, NULL);
561 err_child_ptty:
562 err_ptty:
563 close(parent_ptty);
564 err_open:
565 pthread_mutex_unlock(&fd_mutex);
566 err_lock:
567 return rc;
568 }
569