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 #include <private/android_filesystem_config.h>
35
36 #define ARRAY_SIZE(x) (sizeof(x) / sizeof(*(x)))
37 #define MIN(a,b) (((a)<(b))?(a):(b))
38
39 static pthread_mutex_t fd_mutex = PTHREAD_MUTEX_INITIALIZER;
40
41 #define ERROR(fmt, args...) \
42 do { \
43 fprintf(stderr, fmt, ## args); \
44 ALOG(LOG_ERROR, "logwrapper", fmt, ## args); \
45 } while(0)
46
47 #define FATAL_CHILD(fmt, args...) \
48 do { \
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
59 struct 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
72 struct 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 */
84 struct 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. */
91 struct 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 */
101 static 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 */
add_line_to_linear_buf(struct beginning_buf * b_buf,char * line,ssize_t line_len)104 static int add_line_to_linear_buf(struct beginning_buf *b_buf,
105 char *line, ssize_t line_len)
106 {
107 int full = 0;
108
109 if ((line_len + b_buf->used_len) > b_buf->buf_size) {
110 full = 1;
111 } else {
112 /* Add to the end of the buf */
113 memcpy(b_buf->buf + b_buf->used_len, line, line_len);
114 b_buf->used_len += line_len;
115 }
116
117 return full;
118 }
119
add_line_to_circular_buf(struct ending_buf * e_buf,char * line,ssize_t line_len)120 static void add_line_to_circular_buf(struct ending_buf *e_buf,
121 char *line, ssize_t line_len)
122 {
123 ssize_t free_len;
124 ssize_t needed_space;
125 int cnt;
126
127 if (e_buf->buf == NULL) {
128 return;
129 }
130
131 if (line_len > e_buf->buf_size) {
132 return;
133 }
134
135 free_len = e_buf->buf_size - e_buf->used_len;
136
137 if (line_len > free_len) {
138 /* remove oldest entries at read, and move read to make
139 * room for the new string */
140 needed_space = line_len - free_len;
141 e_buf->read = (e_buf->read + needed_space) % e_buf->buf_size;
142 e_buf->used_len -= needed_space;
143 }
144
145 /* Copy the line into the circular buffer, dealing with possible
146 * wraparound.
147 */
148 cnt = MIN(line_len, e_buf->buf_size - e_buf->write);
149 memcpy(e_buf->buf + e_buf->write, line, cnt);
150 if (cnt < line_len) {
151 memcpy(e_buf->buf, line + cnt, line_len - cnt);
152 }
153 e_buf->used_len += line_len;
154 e_buf->write = (e_buf->write + line_len) % e_buf->buf_size;
155 }
156
157 /* Log directly to the specified log */
do_log_line(struct log_info * log_info,char * line)158 static void do_log_line(struct log_info *log_info, char *line) {
159 if (log_info->log_target & LOG_KLOG) {
160 klog_write(6, log_info->klog_fmt, line);
161 }
162 if (log_info->log_target & LOG_ALOG) {
163 ALOG(LOG_INFO, log_info->btag, "%s", line);
164 }
165 if (log_info->log_target & LOG_FILE) {
166 fprintf(log_info->fp, "%s\n", line);
167 }
168 }
169
170 /* Log to either the abbreviated buf, or directly to the specified log
171 * via do_log_line() above.
172 */
log_line(struct log_info * log_info,char * line,int len)173 static void log_line(struct log_info *log_info, char *line, int len) {
174 if (log_info->abbreviated) {
175 add_line_to_abbr_buf(&log_info->a_buf, line, len);
176 } else {
177 do_log_line(log_info, line);
178 }
179 }
180
181 /*
182 * The kernel will take a maximum of 1024 bytes in any single write to
183 * the kernel logging device file, so find and print each line one at
184 * a time. The allocated size for buf should be at least 1 byte larger
185 * than buf_size (the usable size of the buffer) to make sure there is
186 * room to temporarily stuff a null byte to terminate a line for logging.
187 */
print_buf_lines(struct log_info * log_info,char * buf,int buf_size)188 static void print_buf_lines(struct log_info *log_info, char *buf, int buf_size)
189 {
190 char *line_start;
191 char c;
192 int i;
193
194 line_start = buf;
195 for (i = 0; i < buf_size; i++) {
196 if (*(buf + i) == '\n') {
197 /* Found a line ending, print the line and compute new line_start */
198 /* Save the next char and replace with \0 */
199 c = *(buf + i + 1);
200 *(buf + i + 1) = '\0';
201 do_log_line(log_info, line_start);
202 /* Restore the saved char */
203 *(buf + i + 1) = c;
204 line_start = buf + i + 1;
205 } else if (*(buf + i) == '\0') {
206 /* The end of the buffer, print the last bit */
207 do_log_line(log_info, line_start);
208 break;
209 }
210 }
211 /* If the buffer was completely full, and didn't end with a newline, just
212 * ignore the partial last line.
213 */
214 }
215
init_abbr_buf(struct abbr_buf * a_buf)216 static void init_abbr_buf(struct abbr_buf *a_buf) {
217 char *new_buf;
218
219 memset(a_buf, 0, sizeof(struct abbr_buf));
220 new_buf = malloc(BEGINNING_BUF_SIZE);
221 if (new_buf) {
222 a_buf->b_buf.buf = new_buf;
223 a_buf->b_buf.alloc_len = BEGINNING_BUF_SIZE;
224 a_buf->b_buf.buf_size = BEGINNING_BUF_SIZE - 1;
225 }
226 new_buf = malloc(ENDING_BUF_SIZE);
227 if (new_buf) {
228 a_buf->e_buf.buf = new_buf;
229 a_buf->e_buf.alloc_len = ENDING_BUF_SIZE;
230 a_buf->e_buf.buf_size = ENDING_BUF_SIZE - 1;
231 }
232 }
233
free_abbr_buf(struct abbr_buf * a_buf)234 static void free_abbr_buf(struct abbr_buf *a_buf) {
235 free(a_buf->b_buf.buf);
236 free(a_buf->e_buf.buf);
237 }
238
add_line_to_abbr_buf(struct abbr_buf * a_buf,char * linebuf,int linelen)239 static void add_line_to_abbr_buf(struct abbr_buf *a_buf, char *linebuf, int linelen) {
240 if (!a_buf->beginning_buf_full) {
241 a_buf->beginning_buf_full =
242 add_line_to_linear_buf(&a_buf->b_buf, linebuf, linelen);
243 }
244 if (a_buf->beginning_buf_full) {
245 add_line_to_circular_buf(&a_buf->e_buf, linebuf, linelen);
246 }
247 }
248
print_abbr_buf(struct log_info * log_info)249 static void print_abbr_buf(struct log_info *log_info) {
250 struct abbr_buf *a_buf = &log_info->a_buf;
251
252 /* Add the abbreviated output to the kernel log */
253 if (a_buf->b_buf.alloc_len) {
254 print_buf_lines(log_info, a_buf->b_buf.buf, a_buf->b_buf.used_len);
255 }
256
257 /* Print an ellipsis to indicate that the buffer has wrapped or
258 * is full, and some data was not logged.
259 */
260 if (a_buf->e_buf.used_len == a_buf->e_buf.buf_size) {
261 do_log_line(log_info, "...\n");
262 }
263
264 if (a_buf->e_buf.used_len == 0) {
265 return;
266 }
267
268 /* Simplest way to print the circular buffer is allocate a second buf
269 * of the same size, and memcpy it so it's a simple linear buffer,
270 * and then cal print_buf_lines on it */
271 if (a_buf->e_buf.read < a_buf->e_buf.write) {
272 /* no wrap around, just print it */
273 print_buf_lines(log_info, a_buf->e_buf.buf + a_buf->e_buf.read,
274 a_buf->e_buf.used_len);
275 } else {
276 /* The circular buffer will always have at least 1 byte unused,
277 * so by allocating alloc_len here we will have at least
278 * 1 byte of space available as required by print_buf_lines().
279 */
280 char * nbuf = malloc(a_buf->e_buf.alloc_len);
281 if (!nbuf) {
282 return;
283 }
284 int first_chunk_len = a_buf->e_buf.buf_size - a_buf->e_buf.read;
285 memcpy(nbuf, a_buf->e_buf.buf + a_buf->e_buf.read, first_chunk_len);
286 /* copy second chunk */
287 memcpy(nbuf + first_chunk_len, a_buf->e_buf.buf, a_buf->e_buf.write);
288 print_buf_lines(log_info, nbuf, first_chunk_len + a_buf->e_buf.write);
289 free(nbuf);
290 }
291 }
292
parent(const char * tag,int parent_read,pid_t pid,int * chld_sts,int log_target,bool abbreviated,char * file_path)293 static int parent(const char *tag, int parent_read, pid_t pid,
294 int *chld_sts, int log_target, bool abbreviated, char *file_path) {
295 int status = 0;
296 char buffer[4096];
297 struct pollfd poll_fds[] = {
298 [0] = {
299 .fd = parent_read,
300 .events = POLLIN,
301 },
302 };
303 int rc = 0;
304 int fd;
305
306 struct log_info log_info;
307
308 int a = 0; // start index of unprocessed data
309 int b = 0; // end index of unprocessed data
310 int sz;
311 bool found_child = false;
312 char tmpbuf[256];
313
314 log_info.btag = basename(tag);
315 if (!log_info.btag) {
316 log_info.btag = (char*) tag;
317 }
318
319 if (abbreviated && (log_target == LOG_NONE)) {
320 abbreviated = 0;
321 }
322 if (abbreviated) {
323 init_abbr_buf(&log_info.a_buf);
324 }
325
326 if (log_target & LOG_KLOG) {
327 snprintf(log_info.klog_fmt, sizeof(log_info.klog_fmt),
328 "<6>%.*s: %%s\n", MAX_KLOG_TAG, log_info.btag);
329 }
330
331 if ((log_target & LOG_FILE) && !file_path) {
332 /* No file_path specified, clear the LOG_FILE bit */
333 log_target &= ~LOG_FILE;
334 }
335
336 if (log_target & LOG_FILE) {
337 fd = open(file_path, O_WRONLY | O_CREAT, 0664);
338 if (fd < 0) {
339 ERROR("Cannot log to file %s\n", file_path);
340 log_target &= ~LOG_FILE;
341 } else {
342 lseek(fd, 0, SEEK_END);
343 log_info.fp = fdopen(fd, "a");
344 }
345 }
346
347 log_info.log_target = log_target;
348 log_info.abbreviated = abbreviated;
349
350 while (!found_child) {
351 if (TEMP_FAILURE_RETRY(poll(poll_fds, ARRAY_SIZE(poll_fds), -1)) < 0) {
352 ERROR("poll failed\n");
353 rc = -1;
354 goto err_poll;
355 }
356
357 if (poll_fds[0].revents & POLLIN) {
358 sz = TEMP_FAILURE_RETRY(
359 read(parent_read, &buffer[b], sizeof(buffer) - 1 - b));
360
361 sz += b;
362 // Log one line at a time
363 for (b = 0; b < sz; b++) {
364 if (buffer[b] == '\r') {
365 if (abbreviated) {
366 /* The abbreviated logging code uses newline as
367 * the line separator. Lucikly, the pty layer
368 * helpfully cooks the output of the command
369 * being run and inserts a CR before NL. So
370 * I just change it to NL here when doing
371 * abbreviated logging.
372 */
373 buffer[b] = '\n';
374 } else {
375 buffer[b] = '\0';
376 }
377 } else if (buffer[b] == '\n') {
378 buffer[b] = '\0';
379 log_line(&log_info, &buffer[a], b - a);
380 a = b + 1;
381 }
382 }
383
384 if (a == 0 && b == sizeof(buffer) - 1) {
385 // buffer is full, flush
386 buffer[b] = '\0';
387 log_line(&log_info, &buffer[a], b - a);
388 b = 0;
389 } else if (a != b) {
390 // Keep left-overs
391 b -= a;
392 memmove(buffer, &buffer[a], b);
393 a = 0;
394 } else {
395 a = 0;
396 b = 0;
397 }
398 }
399
400 if (poll_fds[0].revents & POLLHUP) {
401 int ret;
402
403 ret = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0));
404 if (ret < 0) {
405 rc = errno;
406 ALOG(LOG_ERROR, "logwrap", "waitpid failed with %s\n", strerror(errno));
407 goto err_waitpid;
408 }
409 if (ret > 0) {
410 found_child = true;
411 }
412 }
413 }
414
415 if (chld_sts != NULL) {
416 *chld_sts = status;
417 } else {
418 if (WIFEXITED(status))
419 rc = WEXITSTATUS(status);
420 else
421 rc = -ECHILD;
422 }
423
424 // Flush remaining data
425 if (a != b) {
426 buffer[b] = '\0';
427 log_line(&log_info, &buffer[a], b - a);
428 }
429
430 /* All the output has been processed, time to dump the abbreviated output */
431 if (abbreviated) {
432 print_abbr_buf(&log_info);
433 }
434
435 if (WIFEXITED(status)) {
436 if (WEXITSTATUS(status)) {
437 snprintf(tmpbuf, sizeof(tmpbuf),
438 "%s terminated by exit(%d)\n", log_info.btag, WEXITSTATUS(status));
439 do_log_line(&log_info, tmpbuf);
440 }
441 } else {
442 if (WIFSIGNALED(status)) {
443 snprintf(tmpbuf, sizeof(tmpbuf),
444 "%s terminated by signal %d\n", log_info.btag, WTERMSIG(status));
445 do_log_line(&log_info, tmpbuf);
446 } else if (WIFSTOPPED(status)) {
447 snprintf(tmpbuf, sizeof(tmpbuf),
448 "%s stopped by signal %d\n", log_info.btag, WSTOPSIG(status));
449 do_log_line(&log_info, tmpbuf);
450 }
451 }
452
453 err_waitpid:
454 err_poll:
455 if (log_target & LOG_FILE) {
456 fclose(log_info.fp); /* Also closes underlying fd */
457 }
458 if (abbreviated) {
459 free_abbr_buf(&log_info.a_buf);
460 }
461 return rc;
462 }
463
child(int argc,char * argv[])464 static void child(int argc, char* argv[]) {
465 // create null terminated argv_child array
466 char* argv_child[argc + 1];
467 memcpy(argv_child, argv, argc * sizeof(char *));
468 argv_child[argc] = NULL;
469
470 if (execvp(argv_child[0], argv_child)) {
471 FATAL_CHILD("executing %s failed: %s\n", argv_child[0],
472 strerror(errno));
473 }
474 }
475
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)476 int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit,
477 int log_target, bool abbreviated, char *file_path,
478 void *unused_opts, int unused_opts_len) {
479 pid_t pid;
480 int parent_ptty;
481 int child_ptty;
482 struct sigaction intact;
483 struct sigaction quitact;
484 sigset_t blockset;
485 sigset_t oldset;
486 int rc = 0;
487
488 LOG_ALWAYS_FATAL_IF(unused_opts != NULL);
489 LOG_ALWAYS_FATAL_IF(unused_opts_len != 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 = TEMP_FAILURE_RETRY(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 char child_devname[64];
506 if (grantpt(parent_ptty) || unlockpt(parent_ptty) ||
507 ptsname_r(parent_ptty, child_devname, sizeof(child_devname)) != 0) {
508 ERROR("Problem with /dev/ptmx\n");
509 rc = -1;
510 goto err_ptty;
511 }
512
513 child_ptty = TEMP_FAILURE_RETRY(open(child_devname, O_RDWR));
514 if (child_ptty < 0) {
515 ERROR("Cannot open child_ptty\n");
516 rc = -1;
517 goto err_child_ptty;
518 }
519
520 sigemptyset(&blockset);
521 sigaddset(&blockset, SIGINT);
522 sigaddset(&blockset, SIGQUIT);
523 pthread_sigmask(SIG_BLOCK, &blockset, &oldset);
524
525 pid = fork();
526 if (pid < 0) {
527 close(child_ptty);
528 ERROR("Failed to fork\n");
529 rc = -1;
530 goto err_fork;
531 } else if (pid == 0) {
532 pthread_mutex_unlock(&fd_mutex);
533 pthread_sigmask(SIG_SETMASK, &oldset, NULL);
534 close(parent_ptty);
535
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 }
560 err_fork:
561 pthread_sigmask(SIG_SETMASK, &oldset, NULL);
562 err_child_ptty:
563 err_ptty:
564 close(parent_ptty);
565 err_open:
566 pthread_mutex_unlock(&fd_mutex);
567 err_lock:
568 return rc;
569 }
570