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 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 122 static 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 */ 161 static 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 */ 176 static 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 */ 191 static 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 220 static 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 238 static 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 243 static 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 253 static 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 297 static 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 456 err_waitpid: 457 err_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 467 static 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 479 int 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 } 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
