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 */ 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 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 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 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
