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