vm/StdioConverter.cpp

   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  * Thread that reads from stdout/stderr and converts them to log messages.
  18  * (Sort of a hack.)
  19  */
  20 #include "Dalvik.h"
  21
  22 #include <stdlib.h>
  23 #include <unistd.h>
  24 #include <fcntl.h>
  25 #include <errno.h>
  26
  27 #define kFilenoStdout   1
  28 #define kFilenoStderr   2
  29
  30 #define kMaxLine    512
  31
  32 /*
  33  * Hold some data.
  34  */
  35 struct BufferedData {
  36     char    buf[kMaxLine+1];
  37     int     count;
  38 };
  39
  40 // fwd
  41 static void* stdioConverterThreadStart(void* arg);
  42 static bool readAndLog(int fd, BufferedData* data, const char* tag);
  43
  44
  45 /*
  46  * Crank up the stdout/stderr converter thread.
  47  *
  48  * Returns immediately.
  49  */
  50 bool dvmStdioConverterStartup()
  51 {
  52     gDvm.haltStdioConverter = false;
  53
  54     dvmInitMutex(&gDvm.stdioConverterLock);
  55     pthread_cond_init(&gDvm.stdioConverterCond, NULL);
  56
  57     if (pipe(gDvm.stdoutPipe) != 0) {
  58         ALOGW("pipe failed: %s", strerror(errno));
  59         return false;
  60     }
  61     if (pipe(gDvm.stderrPipe) != 0) {
  62         ALOGW("pipe failed: %s", strerror(errno));
  63         return false;
  64     }
  65
  66     if (dup2(gDvm.stdoutPipe[1], kFilenoStdout) != kFilenoStdout) {
  67         ALOGW("dup2(1) failed: %s", strerror(errno));
  68         return false;
  69     }
  70     close(gDvm.stdoutPipe[1]);
  71     gDvm.stdoutPipe[1] = -1;
  72 #ifdef HAVE_ANDROID_OS
  73     /* don't redirect stderr on sim -- logs get written there! */
  74     /* (don't need this on the sim anyway) */
  75     if (dup2(gDvm.stderrPipe[1], kFilenoStderr) != kFilenoStderr) {
  76         ALOGW("dup2(2) failed: %d %s", errno, strerror(errno));
  77         return false;
  78     }
  79     close(gDvm.stderrPipe[1]);
  80     gDvm.stderrPipe[1] = -1;
  81 #endif
  82
  83
  84     /*
  85      * Create the thread.
  86      */
  87     dvmLockMutex(&gDvm.stdioConverterLock);
  88
  89     if (!dvmCreateInternalThread(&gDvm.stdioConverterHandle,
  90                                  "Stdio Converter",
  91                                  stdioConverterThreadStart,
  92                                  NULL)) {
  93         return false;
  94     }
  95
  96     while (!gDvm.stdioConverterReady) {
  97         dvmWaitCond(&gDvm.stdioConverterCond, &gDvm.stdioConverterLock);
  98     }
  99     dvmUnlockMutex(&gDvm.stdioConverterLock);
 100
 101     return true;
 102 }
 103
 104 /*
 105  * Shut down the stdio converter thread if it was started.
 106  *
 107  * Since we know the thread is just sitting around waiting for something
 108  * to arrive on stdout, print something.
 109  */
 110 void dvmStdioConverterShutdown()
 111 {
 112     gDvm.haltStdioConverter = true;
 113     if (gDvm.stdioConverterHandle == 0)    // not started, or still starting
 114         return;
 115
 116     /* print something to wake it up */
 117     printf("Shutting down\n");
 118     fflush(stdout);
 119
 120     ALOGD("Joining stdio converter...");
 121     pthread_join(gDvm.stdioConverterHandle, NULL);
 122 }
 123
 124 /*
 125  * Select on stdout/stderr pipes, waiting for activity.
 126  *
 127  * DO NOT use printf from here.
 128  */
 129 static void* stdioConverterThreadStart(void* arg)
 130 {
 131     int cc;
 132
 133     /* tell the main thread that we're ready */
 134     dvmLockMutex(&gDvm.stdioConverterLock);
 135     gDvm.stdioConverterReady = true;
 136     cc = pthread_cond_signal(&gDvm.stdioConverterCond);
 137     assert(cc == 0);
 138     dvmUnlockMutex(&gDvm.stdioConverterLock);
 139
 140     /* we never do anything that affects the rest of the VM */
 141     dvmChangeStatus(NULL, THREAD_VMWAIT);
 142
 143     /*
 144      * Allocate read buffers.
 145      */
 146     BufferedData* stdoutData = new BufferedData;
 147     BufferedData* stderrData = new BufferedData;
 148     stdoutData->count = stderrData->count = 0;
 149
 150     /*
 151      * Read until shutdown time.
 152      */
 153     while (!gDvm.haltStdioConverter) {
 154         fd_set readfds;
 155         int maxFd, fdCount;
 156
 157         FD_ZERO(&readfds);
 158         FD_SET(gDvm.stdoutPipe[0], &readfds);
 159         FD_SET(gDvm.stderrPipe[0], &readfds);
 160         maxFd = MAX(gDvm.stdoutPipe[0], gDvm.stderrPipe[0]);
 161
 162         fdCount = select(maxFd+1, &readfds, NULL, NULL, NULL);
 163
 164         if (fdCount < 0) {
 165             if (errno != EINTR) {
 166                 ALOGE("select on stdout/stderr failed");
 167                 break;
 168             }
 169             ALOGD("Got EINTR, ignoring");
 170         } else if (fdCount == 0) {
 171             ALOGD("WEIRD: select returned zero");
 172         } else {
 173             bool err = false;
 174             if (FD_ISSET(gDvm.stdoutPipe[0], &readfds)) {
 175                 err |= !readAndLog(gDvm.stdoutPipe[0], stdoutData,
 176                     "stdout");
 177             }
 178             if (FD_ISSET(gDvm.stderrPipe[0], &readfds)) {
 179                 err |= !readAndLog(gDvm.stderrPipe[0], stderrData,
 180                     "stderr");
 181             }
 182
 183             /* probably EOF; give up */
 184             if (err) {
 185                 ALOGW("stdio converter got read error; shutting it down");
 186                 break;
 187             }
 188         }
 189     }
 190
 191     close(gDvm.stdoutPipe[0]);
 192     close(gDvm.stderrPipe[0]);
 193
 194     delete stdoutData;
 195     delete stderrData;
 196
 197     /* change back for shutdown sequence */
 198     dvmChangeStatus(NULL, THREAD_RUNNING);
 199     return NULL;
 200 }
 201
 202 /*
 203  * Data is pending on "fd".  Read as much as will fit in "data", then
 204  * write out any full lines and compact "data".
 205  */
 206 static bool readAndLog(int fd, BufferedData* data, const char* tag)
 207 {
 208     ssize_t actual;
 209     size_t want;
 210
 211     assert(data->count < kMaxLine);
 212
 213     want = kMaxLine - data->count;
 214     actual = read(fd, data->buf + data->count, want);
 215     if (actual <= 0) {
 216         ALOGW("read %s: (%d,%d) failed (%d): %s",
 217             tag, fd, want, (int)actual, strerror(errno));
 218         return false;
 219     } else {
 220         //ALOGI("read %s: %d at %d", tag, actual, data->count);
 221     }
 222     data->count += actual;
 223
 224     /*
 225      * Got more data, look for an EOL.  We expect LF or CRLF, but will
 226      * try to handle a standalone CR.
 227      */
 228     char* cp = data->buf;
 229     const char* start = data->buf;
 230     int i = data->count;
 231     for (i = data->count; i > 0; i--, cp++) {
 232         if (*cp == '\n' || (*cp == '\r' && i != 0 && *(cp+1) != '\n')) {
 233             *cp = '\0';
 234             //ALOGW("GOT %d at %d '%s'", cp - start, start - data->buf, start);
 235             ALOG(LOG_INFO, tag, "%s", start);
 236             start = cp+1;
 237         }
 238     }
 239
 240     /*
 241      * See if we overflowed.  If so, cut it off.
 242      */
 243     if (start == data->buf && data->count == kMaxLine) {
 244         data->buf[kMaxLine] = '\0';
 245         ALOG(LOG_INFO, tag, "%s!", start);
 246         start = cp + kMaxLine;
 247     }
 248
 249     /*
 250      * Update "data" if we consumed some output.  If there's anything left
 251      * in the buffer, it's because we didn't see an EOL and need to keep
 252      * reading until we see one.
 253      */
 254     if (start != data->buf) {
 255         if (start >= data->buf + data->count) {
 256             /* consumed all available */
 257             data->count = 0;
 258         } else {
 259             /* some left over */
 260             int remaining = data->count - (start - data->buf);
 261             memmove(data->buf, start, remaining);
 262             data->count = remaining;
 263         }
 264     }
 265
 266     return true;
 267 }