StdioConverter.cpp revision 1663a6c12fdf4732d7ea0a0406af6085b3c408e4 
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 */
35struct BufferedData {
36    char    buf[kMaxLine+1];
37    int     count;
38};
39
40// fwd
41static void* stdioConverterThreadStart(void* arg);
42static 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 */
50bool 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        LOGW("pipe failed: %s", strerror(errno));
59        return false;
60    }
61    if (pipe(gDvm.stderrPipe) != 0) {
62        LOGW("pipe failed: %s", strerror(errno));
63        return false;
64    }
65
66    if (dup2(gDvm.stdoutPipe[1], kFilenoStdout) != kFilenoStdout) {
67        LOGW("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        LOGW("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 */
110void 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    LOGD("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 */
129static 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                LOGE("select on stdout/stderr failed");
167                break;
168            }
169            LOGD("Got EINTR, ignoring");
170        } else if (fdCount == 0) {
171            LOGD("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                LOGW("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 */
206static 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        LOGW("read %s: (%d,%d) failed (%d): %s",
217            tag, fd, want, (int)actual, strerror(errno));
218        return false;
219    } else {
220        //LOGI("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            //LOGW("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}
268