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
39static pthread_mutex_t fd_mutex = PTHREAD_MUTEX_INITIALIZER;
40
41#define ERROR(fmt, args...)                                                   \
42do {                                                                          \
43    fprintf(stderr, fmt, ## args);                                            \
44    ALOG(LOG_ERROR, "logwrapper", fmt, ## args);                              \
45} while(0)
46
47#define FATAL_CHILD(fmt, args...)                                             \
48do {                                                                          \
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
59struct 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
72struct 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 */
84struct 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. */
91struct 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 */
101static 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 */
104static 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
120static 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 */
158static 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 */
173static 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 */
188static 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
216static 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
234static 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
239static 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
249static 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
293static 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 = read(parent_read, &buffer[b], sizeof(buffer) - 1 - b);
359
360            sz += b;
361            // Log one line at a time
362            for (b = 0; b < sz; b++) {
363                if (buffer[b] == '\r') {
364                    if (abbreviated) {
365                        /* The abbreviated logging code uses newline as
366                         * the line separator.  Lucikly, the pty layer
367                         * helpfully cooks the output of the command
368                         * being run and inserts a CR before NL.  So
369                         * I just change it to NL here when doing
370                         * abbreviated logging.
371                         */
372                        buffer[b] = '\n';
373                    } else {
374                        buffer[b] = '\0';
375                    }
376                } else if (buffer[b] == '\n') {
377                    buffer[b] = '\0';
378                    log_line(&log_info, &buffer[a], b - a);
379                    a = b + 1;
380                }
381            }
382
383            if (a == 0 && b == sizeof(buffer) - 1) {
384                // buffer is full, flush
385                buffer[b] = '\0';
386                log_line(&log_info, &buffer[a], b - a);
387                b = 0;
388            } else if (a != b) {
389                // Keep left-overs
390                b -= a;
391                memmove(buffer, &buffer[a], b);
392                a = 0;
393            } else {
394                a = 0;
395                b = 0;
396            }
397        }
398
399        if (poll_fds[0].revents & POLLHUP) {
400            int ret;
401
402            ret = waitpid(pid, &status, WNOHANG);
403            if (ret < 0) {
404                rc = errno;
405                ALOG(LOG_ERROR, "logwrap", "waitpid failed with %s\n", strerror(errno));
406                goto err_waitpid;
407            }
408            if (ret > 0) {
409                found_child = true;
410            }
411        }
412    }
413
414    if (chld_sts != NULL) {
415        *chld_sts = status;
416    } else {
417      if (WIFEXITED(status))
418        rc = WEXITSTATUS(status);
419      else
420        rc = -ECHILD;
421    }
422
423    // Flush remaining data
424    if (a != b) {
425      buffer[b] = '\0';
426      log_line(&log_info, &buffer[a], b - a);
427    }
428
429    /* All the output has been processed, time to dump the abbreviated output */
430    if (abbreviated) {
431        print_abbr_buf(&log_info);
432    }
433
434    if (WIFEXITED(status)) {
435      if (WEXITSTATUS(status)) {
436        snprintf(tmpbuf, sizeof(tmpbuf),
437                 "%s terminated by exit(%d)\n", log_info.btag, WEXITSTATUS(status));
438        do_log_line(&log_info, tmpbuf);
439      }
440    } else {
441      if (WIFSIGNALED(status)) {
442        snprintf(tmpbuf, sizeof(tmpbuf),
443                       "%s terminated by signal %d\n", log_info.btag, WTERMSIG(status));
444        do_log_line(&log_info, tmpbuf);
445      } else if (WIFSTOPPED(status)) {
446        snprintf(tmpbuf, sizeof(tmpbuf),
447                       "%s stopped by signal %d\n", log_info.btag, WSTOPSIG(status));
448        do_log_line(&log_info, tmpbuf);
449      }
450    }
451
452err_waitpid:
453err_poll:
454    if (log_target & LOG_FILE) {
455        fclose(log_info.fp); /* Also closes underlying fd */
456    }
457    if (abbreviated) {
458        free_abbr_buf(&log_info.a_buf);
459    }
460    return rc;
461}
462
463static void child(int argc, char* argv[]) {
464    // create null terminated argv_child array
465    char* argv_child[argc + 1];
466    memcpy(argv_child, argv, argc * sizeof(char *));
467    argv_child[argc] = NULL;
468
469    if (execvp(argv_child[0], argv_child)) {
470        FATAL_CHILD("executing %s failed: %s\n", argv_child[0],
471                strerror(errno));
472    }
473}
474
475int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit,
476        int log_target, bool abbreviated, char *file_path) {
477    pid_t pid;
478    int parent_ptty;
479    int child_ptty;
480    struct sigaction intact;
481    struct sigaction quitact;
482    sigset_t blockset;
483    sigset_t oldset;
484    int rc = 0;
485
486    rc = pthread_mutex_lock(&fd_mutex);
487    if (rc) {
488        ERROR("failed to lock signal_fd mutex\n");
489        goto err_lock;
490    }
491
492    /* Use ptty instead of socketpair so that STDOUT is not buffered */
493    parent_ptty = open("/dev/ptmx", O_RDWR);
494    if (parent_ptty < 0) {
495        ERROR("Cannot create parent ptty\n");
496        rc = -1;
497        goto err_open;
498    }
499
500    char child_devname[64];
501    if (grantpt(parent_ptty) || unlockpt(parent_ptty) ||
502            ptsname_r(parent_ptty, child_devname, sizeof(child_devname)) != 0) {
503        ERROR("Problem with /dev/ptmx\n");
504        rc = -1;
505        goto err_ptty;
506    }
507
508    child_ptty = open(child_devname, O_RDWR);
509    if (child_ptty < 0) {
510        ERROR("Cannot open child_ptty\n");
511        rc = -1;
512        goto err_child_ptty;
513    }
514
515    sigemptyset(&blockset);
516    sigaddset(&blockset, SIGINT);
517    sigaddset(&blockset, SIGQUIT);
518    pthread_sigmask(SIG_BLOCK, &blockset, &oldset);
519
520    pid = fork();
521    if (pid < 0) {
522        close(child_ptty);
523        ERROR("Failed to fork\n");
524        rc = -1;
525        goto err_fork;
526    } else if (pid == 0) {
527        pthread_mutex_unlock(&fd_mutex);
528        pthread_sigmask(SIG_SETMASK, &oldset, NULL);
529        close(parent_ptty);
530
531        // redirect stdout and stderr
532        dup2(child_ptty, 1);
533        dup2(child_ptty, 2);
534        close(child_ptty);
535
536        child(argc, argv);
537    } else {
538        close(child_ptty);
539        if (ignore_int_quit) {
540            struct sigaction ignact;
541
542            memset(&ignact, 0, sizeof(ignact));
543            ignact.sa_handler = SIG_IGN;
544            sigaction(SIGINT, &ignact, &intact);
545            sigaction(SIGQUIT, &ignact, &quitact);
546        }
547
548        rc = parent(argv[0], parent_ptty, pid, status, log_target,
549                    abbreviated, file_path);
550    }
551
552    if (ignore_int_quit) {
553        sigaction(SIGINT, &intact, NULL);
554        sigaction(SIGQUIT, &quitact, NULL);
555    }
556err_fork:
557    pthread_sigmask(SIG_SETMASK, &oldset, NULL);
558err_child_ptty:
559err_ptty:
560    close(parent_ptty);
561err_open:
562    pthread_mutex_unlock(&fd_mutex);
563err_lock:
564    return rc;
565}
566