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