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