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