• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 
35 #define ARRAY_SIZE(x)   (sizeof(x) / sizeof(*(x)))
36 #define MIN(a,b) (((a)<(b))?(a):(b))
37 
38 static pthread_mutex_t fd_mutex = PTHREAD_MUTEX_INITIALIZER;
39 
40 #define ERROR(fmt, args...)                                                   \
41 do {                                                                          \
42     fprintf(stderr, fmt, ## args);                                            \
43     ALOG(LOG_ERROR, "logwrapper", fmt, ## args);                              \
44 } while(0)
45 
46 #define FATAL_CHILD(fmt, args...)                                             \
47 do {                                                                          \
48     ERROR(fmt, ## args);                                                      \
49     _exit(-1);                                                                \
50 } while(0)
51 
52 #define MAX_KLOG_TAG 16
53 
54 /* This is a simple buffer that holds up to the first beginning_buf->buf_size
55  * bytes of output from a command.
56  */
57 #define BEGINNING_BUF_SIZE 0x1000
58 struct beginning_buf {
59     char *buf;
60     size_t alloc_len;
61     /* buf_size is the usable space, which is one less than the allocated size */
62     size_t buf_size;
63     size_t used_len;
64 };
65 
66 /* This is a circular buf that holds up to the last ending_buf->buf_size bytes
67  * of output from a command after the first beginning_buf->buf_size bytes
68  * (which are held in beginning_buf above).
69  */
70 #define ENDING_BUF_SIZE 0x1000
71 struct ending_buf {
72     char *buf;
73     ssize_t alloc_len;
74     /* buf_size is the usable space, which is one less than the allocated size */
75     ssize_t buf_size;
76     ssize_t used_len;
77     /* read and write offsets into the circular buffer */
78     int read;
79     int write;
80 };
81 
82  /* A structure to hold all the abbreviated buf data */
83 struct abbr_buf {
84     struct beginning_buf b_buf;
85     struct ending_buf e_buf;
86     int beginning_buf_full;
87 };
88 
89 /* Collect all the various bits of info needed for logging in one place. */
90 struct log_info {
91     int log_target;
92     char klog_fmt[MAX_KLOG_TAG * 2];
93     char *btag;
94     bool abbreviated;
95     FILE *fp;
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 */
add_line_to_linear_buf(struct beginning_buf * b_buf,char * line,ssize_t line_len)103 static int add_line_to_linear_buf(struct beginning_buf *b_buf,
104                                    char *line, ssize_t line_len)
105 {
106     int full = 0;
107 
108     if ((line_len + b_buf->used_len) > b_buf->buf_size) {
109         full = 1;
110     } else {
111         /* Add to the end of the buf */
112         memcpy(b_buf->buf + b_buf->used_len, line, line_len);
113         b_buf->used_len += line_len;
114     }
115 
116     return full;
117 }
118 
add_line_to_circular_buf(struct ending_buf * e_buf,char * line,ssize_t line_len)119 static void add_line_to_circular_buf(struct ending_buf *e_buf,
120                                      char *line, ssize_t line_len)
121 {
122     ssize_t free_len;
123     ssize_t needed_space;
124     int cnt;
125 
126     if (e_buf->buf == NULL) {
127         return;
128     }
129 
130    if (line_len > e_buf->buf_size) {
131        return;
132    }
133 
134     free_len = e_buf->buf_size - e_buf->used_len;
135 
136     if (line_len > free_len) {
137         /* remove oldest entries at read, and move read to make
138          * room for the new string */
139         needed_space = line_len - free_len;
140         e_buf->read = (e_buf->read + needed_space) % e_buf->buf_size;
141         e_buf->used_len -= needed_space;
142     }
143 
144     /* Copy the line into the circular buffer, dealing with possible
145      * wraparound.
146      */
147     cnt = MIN(line_len, e_buf->buf_size - e_buf->write);
148     memcpy(e_buf->buf + e_buf->write, line, cnt);
149     if (cnt < line_len) {
150         memcpy(e_buf->buf, line + cnt, line_len - cnt);
151     }
152     e_buf->used_len += line_len;
153     e_buf->write = (e_buf->write + line_len) % e_buf->buf_size;
154 }
155 
156 /* Log directly to the specified log */
do_log_line(struct log_info * log_info,char * line)157 static void do_log_line(struct log_info *log_info, char *line) {
158     if (log_info->log_target & LOG_KLOG) {
159         klog_write(6, log_info->klog_fmt, line);
160     }
161     if (log_info->log_target & LOG_ALOG) {
162         ALOG(LOG_INFO, log_info->btag, "%s", line);
163     }
164     if (log_info->log_target & LOG_FILE) {
165         fprintf(log_info->fp, "%s\n", line);
166     }
167 }
168 
169 /* Log to either the abbreviated buf, or directly to the specified log
170  * via do_log_line() above.
171  */
log_line(struct log_info * log_info,char * line,int len)172 static void log_line(struct log_info *log_info, char *line, int len) {
173     if (log_info->abbreviated) {
174         add_line_to_abbr_buf(&log_info->a_buf, line, len);
175     } else {
176         do_log_line(log_info, line);
177     }
178 }
179 
180 /*
181  * The kernel will take a maximum of 1024 bytes in any single write to
182  * the kernel logging device file, so find and print each line one at
183  * a time.  The allocated size for buf should be at least 1 byte larger
184  * than buf_size (the usable size of the buffer) to make sure there is
185  * room to temporarily stuff a null byte to terminate a line for logging.
186  */
print_buf_lines(struct log_info * log_info,char * buf,int buf_size)187 static void print_buf_lines(struct log_info *log_info, char *buf, int buf_size)
188 {
189     char *line_start;
190     char c;
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 
init_abbr_buf(struct abbr_buf * a_buf)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 
free_abbr_buf(struct abbr_buf * a_buf)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 
add_line_to_abbr_buf(struct abbr_buf * a_buf,char * linebuf,int linelen)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 
print_abbr_buf(struct log_info * log_info)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 
parent(const char * tag,int parent_read,pid_t pid,int * chld_sts,int log_target,bool abbreviated,char * file_path)292 static int parent(const char *tag, int parent_read, pid_t pid,
293         int *chld_sts, int log_target, bool abbreviated, char *file_path) {
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     int fd;
304 
305     struct log_info log_info;
306 
307     int a = 0;  // start index of unprocessed data
308     int b = 0;  // end index of unprocessed data
309     int sz;
310     bool found_child = false;
311     char tmpbuf[256];
312 
313     log_info.btag = basename(tag);
314     if (!log_info.btag) {
315         log_info.btag = (char*) tag;
316     }
317 
318     if (abbreviated && (log_target == LOG_NONE)) {
319         abbreviated = 0;
320     }
321     if (abbreviated) {
322         init_abbr_buf(&log_info.a_buf);
323     }
324 
325     if (log_target & LOG_KLOG) {
326         snprintf(log_info.klog_fmt, sizeof(log_info.klog_fmt),
327                  "<6>%.*s: %%s\n", MAX_KLOG_TAG, log_info.btag);
328     }
329 
330     if ((log_target & LOG_FILE) && !file_path) {
331         /* No file_path specified, clear the LOG_FILE bit */
332         log_target &= ~LOG_FILE;
333     }
334 
335     if (log_target & LOG_FILE) {
336         fd = open(file_path, O_WRONLY | O_CREAT, 0664);
337         if (fd < 0) {
338             ERROR("Cannot log to file %s\n", file_path);
339             log_target &= ~LOG_FILE;
340         } else {
341             lseek(fd, 0, SEEK_END);
342             log_info.fp = fdopen(fd, "a");
343         }
344     }
345 
346     log_info.log_target = log_target;
347     log_info.abbreviated = abbreviated;
348 
349     while (!found_child) {
350         if (TEMP_FAILURE_RETRY(poll(poll_fds, ARRAY_SIZE(poll_fds), -1)) < 0) {
351             ERROR("poll failed\n");
352             rc = -1;
353             goto err_poll;
354         }
355 
356         if (poll_fds[0].revents & POLLIN) {
357             sz = TEMP_FAILURE_RETRY(
358                 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 = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0));
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 
452 err_waitpid:
453 err_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 
child(int argc,char * argv[])463 static 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 
android_fork_execvp_ext(int argc,char * argv[],int * status,bool ignore_int_quit,int log_target,bool abbreviated,char * file_path,void * unused_opts,int unused_opts_len)475 int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit,
476         int log_target, bool abbreviated, char *file_path,
477         void *unused_opts, int unused_opts_len) {
478     pid_t pid;
479     int parent_ptty;
480     int child_ptty;
481     struct sigaction intact;
482     struct sigaction quitact;
483     sigset_t blockset;
484     sigset_t oldset;
485     int rc = 0;
486 
487     LOG_ALWAYS_FATAL_IF(unused_opts != NULL);
488     LOG_ALWAYS_FATAL_IF(unused_opts_len != 0);
489 
490     rc = pthread_mutex_lock(&fd_mutex);
491     if (rc) {
492         ERROR("failed to lock signal_fd mutex\n");
493         goto err_lock;
494     }
495 
496     /* Use ptty instead of socketpair so that STDOUT is not buffered */
497     parent_ptty = TEMP_FAILURE_RETRY(open("/dev/ptmx", O_RDWR));
498     if (parent_ptty < 0) {
499         ERROR("Cannot create parent ptty\n");
500         rc = -1;
501         goto err_open;
502     }
503 
504     char child_devname[64];
505     if (grantpt(parent_ptty) || unlockpt(parent_ptty) ||
506             ptsname_r(parent_ptty, child_devname, sizeof(child_devname)) != 0) {
507         ERROR("Problem with /dev/ptmx\n");
508         rc = -1;
509         goto err_ptty;
510     }
511 
512     child_ptty = TEMP_FAILURE_RETRY(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         dup2(child_ptty, 1);
536         dup2(child_ptty, 2);
537         close(child_ptty);
538 
539         child(argc, argv);
540     } else {
541         close(child_ptty);
542         if (ignore_int_quit) {
543             struct sigaction ignact;
544 
545             memset(&ignact, 0, sizeof(ignact));
546             ignact.sa_handler = SIG_IGN;
547             sigaction(SIGINT, &ignact, &intact);
548             sigaction(SIGQUIT, &ignact, &quitact);
549         }
550 
551         rc = parent(argv[0], parent_ptty, pid, status, log_target,
552                     abbreviated, file_path);
553     }
554 
555     if (ignore_int_quit) {
556         sigaction(SIGINT, &intact, NULL);
557         sigaction(SIGQUIT, &quitact, NULL);
558     }
559 err_fork:
560     pthread_sigmask(SIG_SETMASK, &oldset, NULL);
561 err_child_ptty:
562 err_ptty:
563     close(parent_ptty);
564 err_open:
565     pthread_mutex_unlock(&fd_mutex);
566 err_lock:
567     return rc;
568 }
569