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 <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 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 */ 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 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 */ 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 */ 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 */ 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 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 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 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 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 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 const struct AndroidForkExecvpOption* opts, size_t opts_len) { 296 int status = 0; 297 char buffer[4096]; 298 struct pollfd poll_fds[] = { 299 [0] = { 300 .fd = parent_read, 301 .events = POLLIN, 302 }, 303 }; 304 int rc = 0; 305 int fd; 306 307 struct log_info log_info; 308 309 int a = 0; // start index of unprocessed data 310 int b = 0; // end index of unprocessed data 311 int sz; 312 bool found_child = false; 313 char tmpbuf[256]; 314 315 log_info.btag = basename(tag); 316 if (!log_info.btag) { 317 log_info.btag = (char*) tag; 318 } 319 320 if (abbreviated && (log_target == LOG_NONE)) { 321 abbreviated = 0; 322 } 323 if (abbreviated) { 324 init_abbr_buf(&log_info.a_buf); 325 } 326 327 if (log_target & LOG_KLOG) { 328 snprintf(log_info.klog_fmt, sizeof(log_info.klog_fmt), 329 "<6>%.*s: %%s\n", MAX_KLOG_TAG, log_info.btag); 330 } 331 332 if ((log_target & LOG_FILE) && !file_path) { 333 /* No file_path specified, clear the LOG_FILE bit */ 334 log_target &= ~LOG_FILE; 335 } 336 337 if (log_target & LOG_FILE) { 338 fd = open(file_path, O_WRONLY | O_CREAT, 0664); 339 if (fd < 0) { 340 ERROR("Cannot log to file %s\n", file_path); 341 log_target &= ~LOG_FILE; 342 } else { 343 lseek(fd, 0, SEEK_END); 344 log_info.fp = fdopen(fd, "a"); 345 } 346 } 347 348 log_info.log_target = log_target; 349 log_info.abbreviated = abbreviated; 350 351 while (!found_child) { 352 if (TEMP_FAILURE_RETRY(poll(poll_fds, ARRAY_SIZE(poll_fds), -1)) < 0) { 353 ERROR("poll failed\n"); 354 rc = -1; 355 goto err_poll; 356 } 357 358 if (poll_fds[0].revents & POLLIN) { 359 sz = TEMP_FAILURE_RETRY( 360 read(parent_read, &buffer[b], sizeof(buffer) - 1 - b)); 361 362 for (size_t i = 0; sz > 0 && i < opts_len; ++i) { 363 if (opts[i].opt_type == FORK_EXECVP_OPTION_CAPTURE_OUTPUT) { 364 opts[i].opt_capture_output.on_output( 365 (uint8_t*)&buffer[b], sz, opts[i].opt_capture_output.user_pointer); 366 } 367 } 368 369 sz += b; 370 // Log one line at a time 371 for (b = 0; b < sz; b++) { 372 if (buffer[b] == '\r') { 373 if (abbreviated) { 374 /* The abbreviated logging code uses newline as 375 * the line separator. Lucikly, the pty layer 376 * helpfully cooks the output of the command 377 * being run and inserts a CR before NL. So 378 * I just change it to NL here when doing 379 * abbreviated logging. 380 */ 381 buffer[b] = '\n'; 382 } else { 383 buffer[b] = '\0'; 384 } 385 } else if (buffer[b] == '\n') { 386 buffer[b] = '\0'; 387 log_line(&log_info, &buffer[a], b - a); 388 a = b + 1; 389 } 390 } 391 392 if (a == 0 && b == sizeof(buffer) - 1) { 393 // buffer is full, flush 394 buffer[b] = '\0'; 395 log_line(&log_info, &buffer[a], b - a); 396 b = 0; 397 } else if (a != b) { 398 // Keep left-overs 399 b -= a; 400 memmove(buffer, &buffer[a], b); 401 a = 0; 402 } else { 403 a = 0; 404 b = 0; 405 } 406 } 407 408 if (poll_fds[0].revents & POLLHUP) { 409 int ret; 410 411 ret = waitpid(pid, &status, WNOHANG); 412 if (ret < 0) { 413 rc = errno; 414 ALOG(LOG_ERROR, "logwrap", "waitpid failed with %s\n", strerror(errno)); 415 goto err_waitpid; 416 } 417 if (ret > 0) { 418 found_child = true; 419 } 420 } 421 } 422 423 if (chld_sts != NULL) { 424 *chld_sts = status; 425 } else { 426 if (WIFEXITED(status)) 427 rc = WEXITSTATUS(status); 428 else 429 rc = -ECHILD; 430 } 431 432 // Flush remaining data 433 if (a != b) { 434 buffer[b] = '\0'; 435 log_line(&log_info, &buffer[a], b - a); 436 } 437 438 /* All the output has been processed, time to dump the abbreviated output */ 439 if (abbreviated) { 440 print_abbr_buf(&log_info); 441 } 442 443 if (WIFEXITED(status)) { 444 if (WEXITSTATUS(status)) { 445 snprintf(tmpbuf, sizeof(tmpbuf), 446 "%s terminated by exit(%d)\n", log_info.btag, WEXITSTATUS(status)); 447 do_log_line(&log_info, tmpbuf); 448 } 449 } else { 450 if (WIFSIGNALED(status)) { 451 snprintf(tmpbuf, sizeof(tmpbuf), 452 "%s terminated by signal %d\n", log_info.btag, WTERMSIG(status)); 453 do_log_line(&log_info, tmpbuf); 454 } else if (WIFSTOPPED(status)) { 455 snprintf(tmpbuf, sizeof(tmpbuf), 456 "%s stopped by signal %d\n", log_info.btag, WSTOPSIG(status)); 457 do_log_line(&log_info, tmpbuf); 458 } 459 } 460 461 err_waitpid: 462 err_poll: 463 if (log_target & LOG_FILE) { 464 fclose(log_info.fp); /* Also closes underlying fd */ 465 } 466 if (abbreviated) { 467 free_abbr_buf(&log_info.a_buf); 468 } 469 return rc; 470 } 471 472 static void child(int argc, char* argv[]) { 473 // create null terminated argv_child array 474 char* argv_child[argc + 1]; 475 memcpy(argv_child, argv, argc * sizeof(char *)); 476 argv_child[argc] = NULL; 477 478 if (execvp(argv_child[0], argv_child)) { 479 FATAL_CHILD("executing %s failed: %s\n", argv_child[0], 480 strerror(errno)); 481 } 482 } 483 484 int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit, 485 int log_target, bool abbreviated, char *file_path, 486 const struct AndroidForkExecvpOption* opts, size_t opts_len) { 487 pid_t pid; 488 int parent_ptty; 489 int child_ptty; 490 struct sigaction intact; 491 struct sigaction quitact; 492 sigset_t blockset; 493 sigset_t oldset; 494 int rc = 0; 495 496 rc = pthread_mutex_lock(&fd_mutex); 497 if (rc) { 498 ERROR("failed to lock signal_fd mutex\n"); 499 goto err_lock; 500 } 501 502 /* Use ptty instead of socketpair so that STDOUT is not buffered */ 503 parent_ptty = TEMP_FAILURE_RETRY(open("/dev/ptmx", O_RDWR)); 504 if (parent_ptty < 0) { 505 ERROR("Cannot create parent ptty\n"); 506 rc = -1; 507 goto err_open; 508 } 509 510 char child_devname[64]; 511 if (grantpt(parent_ptty) || unlockpt(parent_ptty) || 512 ptsname_r(parent_ptty, child_devname, sizeof(child_devname)) != 0) { 513 ERROR("Problem with /dev/ptmx\n"); 514 rc = -1; 515 goto err_ptty; 516 } 517 518 child_ptty = TEMP_FAILURE_RETRY(open(child_devname, O_RDWR)); 519 if (child_ptty < 0) { 520 ERROR("Cannot open child_ptty\n"); 521 rc = -1; 522 goto err_child_ptty; 523 } 524 525 sigemptyset(&blockset); 526 sigaddset(&blockset, SIGINT); 527 sigaddset(&blockset, SIGQUIT); 528 pthread_sigmask(SIG_BLOCK, &blockset, &oldset); 529 530 pid = fork(); 531 if (pid < 0) { 532 close(child_ptty); 533 ERROR("Failed to fork\n"); 534 rc = -1; 535 goto err_fork; 536 } else if (pid == 0) { 537 pthread_mutex_unlock(&fd_mutex); 538 pthread_sigmask(SIG_SETMASK, &oldset, NULL); 539 close(parent_ptty); 540 541 // redirect stdin, stdout and stderr 542 for (size_t i = 0; i < opts_len; ++i) { 543 if (opts[i].opt_type == FORK_EXECVP_OPTION_INPUT) { 544 dup2(child_ptty, 0); 545 break; 546 } 547 } 548 dup2(child_ptty, 1); 549 dup2(child_ptty, 2); 550 close(child_ptty); 551 552 child(argc, argv); 553 } else { 554 close(child_ptty); 555 if (ignore_int_quit) { 556 struct sigaction ignact; 557 558 memset(&ignact, 0, sizeof(ignact)); 559 ignact.sa_handler = SIG_IGN; 560 sigaction(SIGINT, &ignact, &intact); 561 sigaction(SIGQUIT, &ignact, &quitact); 562 } 563 564 for (size_t i = 0; i < opts_len; ++i) { 565 if (opts[i].opt_type == FORK_EXECVP_OPTION_INPUT) { 566 size_t left = opts[i].opt_input.input_len; 567 const uint8_t* input = opts[i].opt_input.input; 568 while (left > 0) { 569 ssize_t res = 570 TEMP_FAILURE_RETRY(write(parent_ptty, input, left)); 571 if (res < 0) { 572 break; 573 } 574 left -= res; 575 input += res; 576 } 577 } 578 } 579 580 rc = parent(argv[0], parent_ptty, pid, status, log_target, 581 abbreviated, file_path, opts, opts_len); 582 } 583 584 if (ignore_int_quit) { 585 sigaction(SIGINT, &intact, NULL); 586 sigaction(SIGQUIT, &quitact, NULL); 587 } 588 err_fork: 589 pthread_sigmask(SIG_SETMASK, &oldset, NULL); 590 err_child_ptty: 591 err_ptty: 592 close(parent_ptty); 593 err_open: 594 pthread_mutex_unlock(&fd_mutex); 595 err_lock: 596 return rc; 597 } 598
