• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2016 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 #define DEBUG false
17 #include "Log.h"
18 
19 #include "Section.h"
20 
21 #include <dirent.h>
22 #include <errno.h>
23 #include <mutex>
24 #include <set>
25 #include <thread>
26 
27 #include <android-base/file.h>
28 #include <android-base/properties.h>
29 #include <android-base/stringprintf.h>
30 #include <android/util/protobuf.h>
31 #include <android/util/ProtoOutputStream.h>
32 #include <binder/IServiceManager.h>
33 #include <debuggerd/client.h>
34 #include <dumputils/dump_utils.h>
35 #include <log/log_event_list.h>
36 #include <log/logprint.h>
37 #include <private/android_logger.h>
38 #include <sys/mman.h>
39 
40 #include "FdBuffer.h"
41 #include "Privacy.h"
42 #include "frameworks/base/core/proto/android/os/backtrace.proto.h"
43 #include "frameworks/base/core/proto/android/os/data.proto.h"
44 #include "frameworks/base/core/proto/android/util/log.proto.h"
45 #include "frameworks/base/core/proto/android/util/textdump.proto.h"
46 #include "incidentd_util.h"
47 
48 namespace android {
49 namespace os {
50 namespace incidentd {
51 
52 using namespace android::base;
53 using namespace android::util;
54 
55 // special section ids
56 const int FIELD_ID_INCIDENT_METADATA = 2;
57 
58 // incident section parameters
59 const char INCIDENT_HELPER[] = "/system/bin/incident_helper";
60 const char* GZIP[] = {"/system/bin/gzip", NULL};
61 
fork_execute_incident_helper(const int id,Fpipe * p2cPipe,Fpipe * c2pPipe)62 static pid_t fork_execute_incident_helper(const int id, Fpipe* p2cPipe, Fpipe* c2pPipe) {
63     const char* ihArgs[]{INCIDENT_HELPER, "-s", String8::format("%d", id).string(), NULL};
64     return fork_execute_cmd(const_cast<char**>(ihArgs), p2cPipe, c2pPipe);
65 }
66 
section_requires_specific_mention(int sectionId)67 bool section_requires_specific_mention(int sectionId) {
68     switch (sectionId) {
69         case 3025: // restricted_images
70             return true;
71         case 3026: // system_trace
72             return true;
73         default:
74             return false;
75     }
76 }
77 
78 // ================================================================================
Section(int i,int64_t timeoutMs)79 Section::Section(int i, int64_t timeoutMs)
80     : id(i),
81       timeoutMs(timeoutMs) {
82 }
83 
~Section()84 Section::~Section() {}
85 
86 // ================================================================================
isSysfs(const char * filename)87 static inline bool isSysfs(const char* filename) { return strncmp(filename, "/sys/", 5) == 0; }
88 
FileSection(int id,const char * filename,const int64_t timeoutMs)89 FileSection::FileSection(int id, const char* filename, const int64_t timeoutMs)
90     : Section(id, timeoutMs), mFilename(filename) {
91     name = "file ";
92     name += filename;
93     mIsSysfs = isSysfs(filename);
94 }
95 
~FileSection()96 FileSection::~FileSection() {}
97 
Execute(ReportWriter * writer) const98 status_t FileSection::Execute(ReportWriter* writer) const {
99     // read from mFilename first, make sure the file is available
100     // add O_CLOEXEC to make sure it is closed when exec incident helper
101     unique_fd fd(open(mFilename, O_RDONLY | O_CLOEXEC));
102     if (fd.get() == -1) {
103         ALOGW("[%s] failed to open file", this->name.string());
104         // There may be some devices/architectures that won't have the file.
105         // Just return here without an error.
106         return NO_ERROR;
107     }
108 
109     Fpipe p2cPipe;
110     Fpipe c2pPipe;
111     // initiate pipes to pass data to/from incident_helper
112     if (!p2cPipe.init() || !c2pPipe.init()) {
113         ALOGW("[%s] failed to setup pipes", this->name.string());
114         return -errno;
115     }
116 
117     pid_t pid = fork_execute_incident_helper(this->id, &p2cPipe, &c2pPipe);
118     if (pid == -1) {
119         ALOGW("[%s] failed to fork", this->name.string());
120         return -errno;
121     }
122 
123     // parent process
124     FdBuffer buffer;
125     status_t readStatus = buffer.readProcessedDataInStream(fd.get(), std::move(p2cPipe.writeFd()),
126                                                            std::move(c2pPipe.readFd()),
127                                                            this->timeoutMs, mIsSysfs);
128     writer->setSectionStats(buffer);
129     if (readStatus != NO_ERROR || buffer.timedOut()) {
130         ALOGW("[%s] failed to read data from incident helper: %s, timedout: %s",
131               this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
132         kill_child(pid);
133         return readStatus;
134     }
135 
136     status_t ihStatus = wait_child(pid);
137     if (ihStatus != NO_ERROR) {
138         ALOGW("[%s] abnormal child process: %s", this->name.string(), strerror(-ihStatus));
139         return OK; // Not a fatal error.
140     }
141 
142     return writer->writeSection(buffer);
143 }
144 // ================================================================================
GZipSection(int id,const char * filename,...)145 GZipSection::GZipSection(int id, const char* filename, ...) : Section(id) {
146     va_list args;
147     va_start(args, filename);
148     mFilenames = varargs(filename, args);
149     va_end(args);
150     name = "gzip";
151     for (int i = 0; mFilenames[i] != NULL; i++) {
152         name += " ";
153         name += mFilenames[i];
154     }
155 }
156 
~GZipSection()157 GZipSection::~GZipSection() { free(mFilenames); }
158 
Execute(ReportWriter * writer) const159 status_t GZipSection::Execute(ReportWriter* writer) const {
160     // Reads the files in order, use the first available one.
161     int index = 0;
162     unique_fd fd;
163     while (mFilenames[index] != NULL) {
164         fd.reset(open(mFilenames[index], O_RDONLY | O_CLOEXEC));
165         if (fd.get() != -1) {
166             break;
167         }
168         ALOGW("GZipSection failed to open file %s", mFilenames[index]);
169         index++;  // look at the next file.
170     }
171     if (fd.get() == -1) {
172         ALOGW("[%s] can't open all the files", this->name.string());
173         return NO_ERROR;  // e.g. LAST_KMSG will reach here in user build.
174     }
175     FdBuffer buffer;
176     Fpipe p2cPipe;
177     Fpipe c2pPipe;
178     // initiate pipes to pass data to/from gzip
179     if (!p2cPipe.init() || !c2pPipe.init()) {
180         ALOGW("[%s] failed to setup pipes", this->name.string());
181         return -errno;
182     }
183 
184     pid_t pid = fork_execute_cmd((char* const*)GZIP, &p2cPipe, &c2pPipe);
185     if (pid == -1) {
186         ALOGW("[%s] failed to fork", this->name.string());
187         return -errno;
188     }
189     // parent process
190 
191     // construct Fdbuffer to output GZippedfileProto, the reason to do this instead of using
192     // ProtoOutputStream is to avoid allocation of another buffer inside ProtoOutputStream.
193     sp<EncodedBuffer> internalBuffer = buffer.data();
194     internalBuffer->writeHeader((uint32_t)GZippedFileProto::FILENAME, WIRE_TYPE_LENGTH_DELIMITED);
195     size_t fileLen = strlen(mFilenames[index]);
196     internalBuffer->writeRawVarint32(fileLen);
197     for (size_t i = 0; i < fileLen; i++) {
198         internalBuffer->writeRawByte(mFilenames[index][i]);
199     }
200     internalBuffer->writeHeader((uint32_t)GZippedFileProto::GZIPPED_DATA,
201                                 WIRE_TYPE_LENGTH_DELIMITED);
202     size_t editPos = internalBuffer->wp()->pos();
203     internalBuffer->wp()->move(8);  // reserve 8 bytes for the varint of the data size.
204     size_t dataBeginAt = internalBuffer->wp()->pos();
205     VLOG("[%s] editPos=%zu, dataBeginAt=%zu", this->name.string(), editPos, dataBeginAt);
206 
207     status_t readStatus = buffer.readProcessedDataInStream(
208             fd.get(), std::move(p2cPipe.writeFd()), std::move(c2pPipe.readFd()), this->timeoutMs,
209             isSysfs(mFilenames[index]));
210     writer->setSectionStats(buffer);
211     if (readStatus != NO_ERROR || buffer.timedOut()) {
212         ALOGW("[%s] failed to read data from gzip: %s, timedout: %s", this->name.string(),
213               strerror(-readStatus), buffer.timedOut() ? "true" : "false");
214         kill_child(pid);
215         return readStatus;
216     }
217 
218     status_t gzipStatus = wait_child(pid);
219     if (gzipStatus != NO_ERROR) {
220         ALOGW("[%s] abnormal child process: %s", this->name.string(), strerror(-gzipStatus));
221         return gzipStatus;
222     }
223     // Revisit the actual size from gzip result and edit the internal buffer accordingly.
224     size_t dataSize = buffer.size() - dataBeginAt;
225     internalBuffer->wp()->rewind()->move(editPos);
226     internalBuffer->writeRawVarint32(dataSize);
227     internalBuffer->copy(dataBeginAt, dataSize);
228 
229     return writer->writeSection(buffer);
230 }
231 
232 // ================================================================================
233 struct WorkerThreadData : public virtual RefBase {
234     const WorkerThreadSection* section;
235     Fpipe pipe;
236 
237     // Lock protects these fields
238     std::mutex lock;
239     bool workerDone;
240     status_t workerError;
241 
242     explicit WorkerThreadData(const WorkerThreadSection* section);
243     virtual ~WorkerThreadData();
244 };
245 
WorkerThreadData(const WorkerThreadSection * sec)246 WorkerThreadData::WorkerThreadData(const WorkerThreadSection* sec)
247     : section(sec), workerDone(false), workerError(NO_ERROR) {}
248 
~WorkerThreadData()249 WorkerThreadData::~WorkerThreadData() {}
250 
251 // ================================================================================
WorkerThreadSection(int id,const int64_t timeoutMs)252 WorkerThreadSection::WorkerThreadSection(int id, const int64_t timeoutMs)
253     : Section(id, timeoutMs) {}
254 
~WorkerThreadSection()255 WorkerThreadSection::~WorkerThreadSection() {}
256 
sigpipe_handler(int signum)257 void sigpipe_handler(int signum) {
258     if (signum == SIGPIPE) {
259         ALOGE("Wrote to a broken pipe\n");
260     } else {
261         ALOGE("Received unexpected signal: %d\n", signum);
262     }
263 }
264 
Execute(ReportWriter * writer) const265 status_t WorkerThreadSection::Execute(ReportWriter* writer) const {
266     // Create shared data and pipe. Don't put data on the stack since this thread may exit early.
267     sp<WorkerThreadData> data = new WorkerThreadData(this);
268     if (!data->pipe.init()) {
269         return -errno;
270     }
271     data->incStrong(this);
272     std::thread([data, this]() {
273         // Don't crash the service if writing to a closed pipe (may happen if dumping times out)
274         signal(SIGPIPE, sigpipe_handler);
275         status_t err = data->section->BlockingCall(data->pipe.writeFd());
276         {
277             std::scoped_lock<std::mutex> lock(data->lock);
278             data->workerDone = true;
279             data->workerError = err;
280             // unique_fd is not thread safe. If we don't lock it, reset() may pause half way while
281             // the other thread executes to the end, calling ~Fpipe, which is a race condition.
282             data->pipe.writeFd().reset();
283         }
284         data->decStrong(this);
285     }).detach();
286 
287     // Loop reading until either the timeout or the worker side is done (i.e. eof).
288     status_t err = NO_ERROR;
289     bool workerDone = false;
290     FdBuffer buffer;
291     err = buffer.read(data->pipe.readFd().get(), this->timeoutMs);
292     if (err != NO_ERROR) {
293         ALOGE("[%s] reader failed with error '%s'", this->name.string(), strerror(-err));
294     }
295 
296     // If the worker side is finished, then return its error (which may overwrite
297     // our possible error -- but it's more interesting anyway). If not, then we timed out.
298     {
299         std::scoped_lock<std::mutex> lock(data->lock);
300         data->pipe.close();
301         if (data->workerError != NO_ERROR) {
302             err = data->workerError;
303             ALOGE("[%s] worker failed with error '%s'", this->name.string(), strerror(-err));
304         }
305         workerDone = data->workerDone;
306     }
307 
308     writer->setSectionStats(buffer);
309     if (err != NO_ERROR) {
310         char errMsg[128];
311         snprintf(errMsg, 128, "[%s] failed with error '%s'",
312             this->name.string(), strerror(-err));
313         writer->error(this, err, "WorkerThreadSection failed.");
314         return NO_ERROR;
315     }
316     if (buffer.truncated()) {
317         ALOGW("[%s] too large, truncating", this->name.string());
318         // Do not write a truncated section. It won't pass through the PrivacyFilter.
319         return NO_ERROR;
320     }
321     if (!workerDone || buffer.timedOut()) {
322         ALOGW("[%s] timed out", this->name.string());
323         return NO_ERROR;
324     }
325 
326     // Write the data that was collected
327     return writer->writeSection(buffer);
328 }
329 
330 // ================================================================================
CommandSection(int id,const int64_t timeoutMs,const char * command,...)331 CommandSection::CommandSection(int id, const int64_t timeoutMs, const char* command, ...)
332     : Section(id, timeoutMs) {
333     va_list args;
334     va_start(args, command);
335     mCommand = varargs(command, args);
336     va_end(args);
337     name = "cmd";
338     for (int i = 0; mCommand[i] != NULL; i++) {
339         name += " ";
340         name += mCommand[i];
341     }
342 }
343 
CommandSection(int id,const char * command,...)344 CommandSection::CommandSection(int id, const char* command, ...) : Section(id) {
345     va_list args;
346     va_start(args, command);
347     mCommand = varargs(command, args);
348     va_end(args);
349     name = "cmd";
350     for (int i = 0; mCommand[i] != NULL; i++) {
351         name += " ";
352         name += mCommand[i];
353     }
354 }
355 
~CommandSection()356 CommandSection::~CommandSection() { free(mCommand); }
357 
Execute(ReportWriter * writer) const358 status_t CommandSection::Execute(ReportWriter* writer) const {
359     Fpipe cmdPipe;
360     Fpipe ihPipe;
361 
362     if (!cmdPipe.init() || !ihPipe.init()) {
363         ALOGW("[%s] failed to setup pipes", this->name.string());
364         return -errno;
365     }
366 
367     pid_t cmdPid = fork_execute_cmd((char* const*)mCommand, NULL, &cmdPipe);
368     if (cmdPid == -1) {
369         ALOGW("[%s] failed to fork", this->name.string());
370         return -errno;
371     }
372     pid_t ihPid = fork_execute_incident_helper(this->id, &cmdPipe, &ihPipe);
373     if (ihPid == -1) {
374         ALOGW("[%s] failed to fork", this->name.string());
375         return -errno;
376     }
377 
378     cmdPipe.writeFd().reset();
379     FdBuffer buffer;
380     status_t readStatus = buffer.read(ihPipe.readFd().get(), this->timeoutMs);
381     writer->setSectionStats(buffer);
382     if (readStatus != NO_ERROR || buffer.timedOut()) {
383         ALOGW("[%s] failed to read data from incident helper: %s, timedout: %s",
384               this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
385         kill_child(cmdPid);
386         kill_child(ihPid);
387         return readStatus;
388     }
389 
390     // Waiting for command here has one trade-off: the failed status of command won't be detected
391     // until buffer timeout, but it has advatage on starting the data stream earlier.
392     status_t cmdStatus = wait_child(cmdPid);
393     status_t ihStatus = wait_child(ihPid);
394     if (cmdStatus != NO_ERROR || ihStatus != NO_ERROR) {
395         ALOGW("[%s] abnormal child processes, return status: command: %s, incident helper: %s",
396               this->name.string(), strerror(-cmdStatus), strerror(-ihStatus));
397         // Not a fatal error.
398         return NO_ERROR;
399     }
400 
401     return writer->writeSection(buffer);
402 }
403 
404 // ================================================================================
DumpsysSection(int id,const char * service,...)405 DumpsysSection::DumpsysSection(int id, const char* service, ...)
406     : WorkerThreadSection(id, REMOTE_CALL_TIMEOUT_MS), mService(service) {
407     name = "dumpsys ";
408     name += service;
409 
410     va_list args;
411     va_start(args, service);
412     while (true) {
413         const char* arg = va_arg(args, const char*);
414         if (arg == NULL) {
415             break;
416         }
417         mArgs.add(String16(arg));
418         name += " ";
419         name += arg;
420     }
421     va_end(args);
422 }
423 
~DumpsysSection()424 DumpsysSection::~DumpsysSection() {}
425 
BlockingCall(unique_fd & pipeWriteFd) const426 status_t DumpsysSection::BlockingCall(unique_fd& pipeWriteFd) const {
427     // checkService won't wait for the service to show up like getService will.
428     sp<IBinder> service = defaultServiceManager()->checkService(mService);
429 
430     if (service == NULL) {
431         ALOGW("DumpsysSection: Can't lookup service: %s", String8(mService).string());
432         return NAME_NOT_FOUND;
433     }
434 
435     service->dump(pipeWriteFd.get(), mArgs);
436 
437     return NO_ERROR;
438 }
439 
440 // ================================================================================
TextDumpsysSection(int id,const char * service,...)441 TextDumpsysSection::TextDumpsysSection(int id, const char* service, ...)
442         :Section(id), mService(service) {
443     name = "dumpsys ";
444     name += service;
445 
446     va_list args;
447     va_start(args, service);
448     while (true) {
449         const char* arg = va_arg(args, const char*);
450         if (arg == NULL) {
451             break;
452         }
453         mArgs.add(String16(arg));
454         name += " ";
455         name += arg;
456     }
457     va_end(args);
458 }
459 
~TextDumpsysSection()460 TextDumpsysSection::~TextDumpsysSection() {}
461 
Execute(ReportWriter * writer) const462 status_t TextDumpsysSection::Execute(ReportWriter* writer) const {
463     // checkService won't wait for the service to show up like getService will.
464     sp<IBinder> service = defaultServiceManager()->checkService(mService);
465     if (service == NULL) {
466         ALOGW("TextDumpsysSection: Can't lookup service: %s", String8(mService).string());
467         return NAME_NOT_FOUND;
468     }
469 
470     // Create pipe
471     Fpipe dumpPipe;
472     if (!dumpPipe.init()) {
473         ALOGW("[%s] failed to setup pipe", this->name.string());
474         return -errno;
475     }
476 
477     // Run dumping thread
478     const uint64_t start = Nanotime();
479     std::thread worker([write_fd = std::move(dumpPipe.writeFd()), service = std::move(service),
480                         this]() mutable {
481         // Don't crash the service if writing to a closed pipe (may happen if dumping times out)
482         signal(SIGPIPE, sigpipe_handler);
483         status_t err = service->dump(write_fd.get(), this->mArgs);
484         if (err != OK) {
485             ALOGW("[%s] dump thread failed. Error: %s", this->name.string(), strerror(-err));
486         }
487         write_fd.reset();
488     });
489 
490     // Collect dump content
491     FdBuffer buffer;
492     ProtoOutputStream proto;
493     proto.write(TextDumpProto::COMMAND, std::string(name.string()));
494     proto.write(TextDumpProto::DUMP_DURATION_NS, int64_t(Nanotime() - start));
495     buffer.write(proto.data());
496 
497     sp<EncodedBuffer> internalBuffer = buffer.data();
498     internalBuffer->writeHeader((uint32_t)TextDumpProto::CONTENT, WIRE_TYPE_LENGTH_DELIMITED);
499     size_t editPos = internalBuffer->wp()->pos();
500     internalBuffer->wp()->move(8); // reserve 8 bytes for the varint of the data size
501     size_t dataBeginPos = internalBuffer->wp()->pos();
502 
503     status_t readStatus = buffer.read(dumpPipe.readFd(), this->timeoutMs);
504     dumpPipe.readFd().reset();
505     writer->setSectionStats(buffer);
506     if (readStatus != OK || buffer.timedOut()) {
507         ALOGW("[%s] failed to read from dumpsys: %s, timedout: %s", this->name.string(),
508               strerror(-readStatus), buffer.timedOut() ? "true" : "false");
509         worker.detach();
510         return readStatus;
511     }
512     worker.join(); // wait for worker to finish
513 
514     // Revisit the actual size from dumpsys and edit the internal buffer accordingly.
515     size_t dumpSize = buffer.size() - dataBeginPos;
516     internalBuffer->wp()->rewind()->move(editPos);
517     internalBuffer->writeRawVarint32(dumpSize);
518     internalBuffer->copy(dataBeginPos, dumpSize);
519 
520     return writer->writeSection(buffer);
521 }
522 
523 // ================================================================================
524 // initialization only once in Section.cpp.
525 map<log_id_t, log_time> LogSection::gLastLogsRetrieved;
526 
LogSection(int id,const char * logID,...)527 LogSection::LogSection(int id, const char* logID, ...) : WorkerThreadSection(id), mLogMode(logModeBase) {
528     name = "logcat -b ";
529     name += logID;
530 
531     va_list args;
532     va_start(args, logID);
533     mLogID = android_name_to_log_id(logID);
534     while(true) {
535         const char* arg = va_arg(args, const char*);
536         if (arg == NULL) {
537             break;
538         }
539         if (!strcmp(arg, "-L")) {
540           // Read from last logcat buffer
541           mLogMode = mLogMode | ANDROID_LOG_PSTORE;
542         }
543         name += " ";
544         name += arg;
545     }
546     va_end(args);
547 
548     switch (mLogID) {
549         case LOG_ID_EVENTS:
550         case LOG_ID_STATS:
551         case LOG_ID_SECURITY:
552             mBinary = true;
553             break;
554         default:
555             mBinary = false;
556     }
557 }
558 
~LogSection()559 LogSection::~LogSection() {}
560 
trimTail(char const * buf,size_t len)561 static size_t trimTail(char const* buf, size_t len) {
562     while (len > 0) {
563         char c = buf[len - 1];
564         if (c == '\0' || c == ' ' || c == '\n' || c == '\r' || c == ':') {
565             len--;
566         } else {
567             break;
568         }
569     }
570     return len;
571 }
572 
get4LE(uint8_t const * src)573 static inline int32_t get4LE(uint8_t const* src) {
574     return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
575 }
576 
BlockingCall(unique_fd & pipeWriteFd) const577 status_t LogSection::BlockingCall(unique_fd& pipeWriteFd) const {
578     // heap profile shows that liblog malloc & free significant amount of memory in this process.
579     // Hence forking a new process to prevent memory fragmentation.
580     pid_t pid = fork();
581     if (pid < 0) {
582         ALOGW("[%s] failed to fork", this->name.string());
583         return errno;
584     }
585     if (pid > 0) {
586         return wait_child(pid, this->timeoutMs);
587     }
588     // Open log buffer and getting logs since last retrieved time if any.
589     unique_ptr<logger_list, void (*)(logger_list*)> loggers(
590             gLastLogsRetrieved.find(mLogID) == gLastLogsRetrieved.end()
591                     ? android_logger_list_alloc(mLogMode, 0, 0)
592                     : android_logger_list_alloc_time(mLogMode, gLastLogsRetrieved[mLogID], 0),
593             android_logger_list_free);
594 
595     if (android_logger_open(loggers.get(), mLogID) == NULL) {
596         ALOGE("[%s] Can't get logger.", this->name.string());
597         _exit(EXIT_FAILURE);
598     }
599 
600     log_msg msg;
601     log_time lastTimestamp(0);
602 
603     ProtoOutputStream proto;
604     status_t err = OK;
605     while (true) {  // keeps reading until logd buffer is fully read.
606         status_t status = android_logger_list_read(loggers.get(), &msg);
607         // status = 0 - no content, unexpected connection drop or EOF.
608         // status = +ive number - size of retrieved data from logger
609         // status = -ive number, OS supplied error _except_ for -EAGAIN
610         // status = -EAGAIN, graceful indication for ANDRODI_LOG_NONBLOCK that this is the end.
611         if (status <= 0) {
612             if (status != -EAGAIN) {
613                 ALOGW("[%s] fails to read a log_msg.\n", this->name.string());
614                 err = -status;
615             }
616             break;
617         }
618         if (mBinary) {
619             // remove the first uint32 which is tag's index in event log tags
620             android_log_context context = create_android_log_parser(msg.msg() + sizeof(uint32_t),
621                                                                     msg.len() - sizeof(uint32_t));
622             android_log_list_element elem;
623 
624             lastTimestamp.tv_sec = msg.entry.sec;
625             lastTimestamp.tv_nsec = msg.entry.nsec;
626 
627             // format a BinaryLogEntry
628             uint64_t token = proto.start(LogProto::BINARY_LOGS);
629             proto.write(BinaryLogEntry::SEC, (int32_t)msg.entry.sec);
630             proto.write(BinaryLogEntry::NANOSEC, (int32_t)msg.entry.nsec);
631             proto.write(BinaryLogEntry::UID, (int)msg.entry.uid);
632             proto.write(BinaryLogEntry::PID, msg.entry.pid);
633             proto.write(BinaryLogEntry::TID, (int32_t)msg.entry.tid);
634             proto.write(BinaryLogEntry::TAG_INDEX,
635                         get4LE(reinterpret_cast<uint8_t const*>(msg.msg())));
636             do {
637                 elem = android_log_read_next(context);
638                 uint64_t elemToken = proto.start(BinaryLogEntry::ELEMS);
639                 switch (elem.type) {
640                     case EVENT_TYPE_INT:
641                         proto.write(BinaryLogEntry::Elem::TYPE,
642                                     BinaryLogEntry::Elem::EVENT_TYPE_INT);
643                         proto.write(BinaryLogEntry::Elem::VAL_INT32, (int)elem.data.int32);
644                         break;
645                     case EVENT_TYPE_LONG:
646                         proto.write(BinaryLogEntry::Elem::TYPE,
647                                     BinaryLogEntry::Elem::EVENT_TYPE_LONG);
648                         proto.write(BinaryLogEntry::Elem::VAL_INT64, (long long)elem.data.int64);
649                         break;
650                     case EVENT_TYPE_STRING:
651                         proto.write(BinaryLogEntry::Elem::TYPE,
652                                     BinaryLogEntry::Elem::EVENT_TYPE_STRING);
653                         proto.write(BinaryLogEntry::Elem::VAL_STRING, elem.data.string, elem.len);
654                         break;
655                     case EVENT_TYPE_FLOAT:
656                         proto.write(BinaryLogEntry::Elem::TYPE,
657                                     BinaryLogEntry::Elem::EVENT_TYPE_FLOAT);
658                         proto.write(BinaryLogEntry::Elem::VAL_FLOAT, elem.data.float32);
659                         break;
660                     case EVENT_TYPE_LIST:
661                         proto.write(BinaryLogEntry::Elem::TYPE,
662                                     BinaryLogEntry::Elem::EVENT_TYPE_LIST);
663                         break;
664                     case EVENT_TYPE_LIST_STOP:
665                         proto.write(BinaryLogEntry::Elem::TYPE,
666                                     BinaryLogEntry::Elem::EVENT_TYPE_LIST_STOP);
667                         break;
668                     case EVENT_TYPE_UNKNOWN:
669                         proto.write(BinaryLogEntry::Elem::TYPE,
670                                     BinaryLogEntry::Elem::EVENT_TYPE_UNKNOWN);
671                         break;
672                 }
673                 proto.end(elemToken);
674             } while ((elem.type != EVENT_TYPE_UNKNOWN) && !elem.complete);
675             proto.end(token);
676             if (context) {
677                 android_log_destroy(&context);
678             }
679         } else {
680             AndroidLogEntry entry;
681             status = android_log_processLogBuffer(&msg.entry, &entry);
682             if (status != OK) {
683                 ALOGW("[%s] fails to process to an entry.\n", this->name.string());
684                 err = status;
685                 break;
686             }
687             lastTimestamp.tv_sec = entry.tv_sec;
688             lastTimestamp.tv_nsec = entry.tv_nsec;
689 
690             // format a TextLogEntry
691             uint64_t token = proto.start(LogProto::TEXT_LOGS);
692             proto.write(TextLogEntry::SEC, (long long)entry.tv_sec);
693             proto.write(TextLogEntry::NANOSEC, (long long)entry.tv_nsec);
694             proto.write(TextLogEntry::PRIORITY, (int)entry.priority);
695             proto.write(TextLogEntry::UID, entry.uid);
696             proto.write(TextLogEntry::PID, entry.pid);
697             proto.write(TextLogEntry::TID, entry.tid);
698             proto.write(TextLogEntry::TAG, entry.tag, trimTail(entry.tag, entry.tagLen));
699             proto.write(TextLogEntry::LOG, entry.message,
700                         trimTail(entry.message, entry.messageLen));
701             proto.end(token);
702         }
703         if (!proto.flush(pipeWriteFd.get())) {
704             if (errno == EPIPE) {
705                 ALOGW("[%s] wrote to a broken pipe\n", this->name.string());
706             }
707             err = errno;
708             break;
709         }
710         proto.clear();
711     }
712     gLastLogsRetrieved[mLogID] = lastTimestamp;
713     _exit(err);
714 }
715 
716 // ================================================================================
717 
718 const int LINK_NAME_LEN = 64;
719 const int EXE_NAME_LEN = 1024;
720 
TombstoneSection(int id,const char * type,const int64_t timeoutMs)721 TombstoneSection::TombstoneSection(int id, const char* type, const int64_t timeoutMs)
722     : WorkerThreadSection(id, timeoutMs), mType(type) {
723     name = "tombstone ";
724     name += type;
725 }
726 
~TombstoneSection()727 TombstoneSection::~TombstoneSection() {}
728 
BlockingCall(unique_fd & pipeWriteFd) const729 status_t TombstoneSection::BlockingCall(unique_fd& pipeWriteFd) const {
730     std::unique_ptr<DIR, decltype(&closedir)> proc(opendir("/proc"), closedir);
731     if (proc.get() == nullptr) {
732         ALOGE("opendir /proc failed: %s\n", strerror(errno));
733         return -errno;
734     }
735 
736     const std::set<int> hal_pids = get_interesting_hal_pids();
737 
738     auto pooledBuffer = get_buffer_from_pool();
739     ProtoOutputStream proto(pooledBuffer);
740     // dumpBufferSize should be a multiple of page size (4 KB) to reduce memory fragmentation
741     size_t dumpBufferSize = 64 * 1024; // 64 KB is enough for most tombstone dump
742     char* dumpBuffer = (char*)mmap(NULL, dumpBufferSize, PROT_READ | PROT_WRITE,
743                 MAP_ANONYMOUS | MAP_PRIVATE, -1, 0);
744     struct dirent* d;
745     char link_name[LINK_NAME_LEN];
746     char exe_name[EXE_NAME_LEN];
747     status_t err = NO_ERROR;
748     while ((d = readdir(proc.get()))) {
749         int pid = atoi(d->d_name);
750         if (pid <= 0) {
751             continue;
752         }
753         snprintf(link_name, LINK_NAME_LEN, "/proc/%d/exe", pid);
754         struct stat fileStat;
755         if (stat(link_name, &fileStat) != OK) {
756             continue;
757         }
758         ssize_t exe_name_len = readlink(link_name, exe_name, EXE_NAME_LEN);
759         if (exe_name_len < 0 || exe_name_len >= EXE_NAME_LEN) {
760             ALOGE("[%s] Can't read '%s': %s", name.string(), link_name, strerror(errno));
761             continue;
762         }
763         // readlink(2) does not put a null terminator at the end
764         exe_name[exe_name_len] = '\0';
765 
766         bool is_java_process;
767         if (strncmp(exe_name, "/system/bin/app_process32", LINK_NAME_LEN) == 0 ||
768                 strncmp(exe_name, "/system/bin/app_process64", LINK_NAME_LEN) == 0) {
769             if (mType != "java") continue;
770             // Don't bother dumping backtraces for the zygote.
771             if (IsZygote(pid)) {
772                 VLOG("Skipping Zygote");
773                 continue;
774             }
775 
776             is_java_process = true;
777         } else if (should_dump_native_traces(exe_name)) {
778             if (mType != "native") continue;
779             is_java_process = false;
780         } else if (hal_pids.find(pid) != hal_pids.end()) {
781             if (mType != "hal") continue;
782             is_java_process = false;
783         } else {
784             // Probably a native process we don't care about, continue.
785             VLOG("Skipping %d", pid);
786             continue;
787         }
788 
789         Fpipe dumpPipe;
790         if (!dumpPipe.init()) {
791             ALOGW("[%s] failed to setup dump pipe", this->name.string());
792             err = -errno;
793             break;
794         }
795 
796         const uint64_t start = Nanotime();
797         pid_t child = fork();
798         if (child < 0) {
799             ALOGE("Failed to fork child process");
800             break;
801         } else if (child == 0) {
802             // This is the child process.
803             dumpPipe.readFd().reset();
804             const int ret = dump_backtrace_to_file_timeout(
805                     pid, is_java_process ? kDebuggerdJavaBacktrace : kDebuggerdNativeBacktrace,
806                     is_java_process ? 5 : 20, dumpPipe.writeFd().get());
807             if (ret == -1) {
808                 if (errno == 0) {
809                     ALOGW("Dumping failed for pid '%d', likely due to a timeout\n", pid);
810                 } else {
811                     ALOGE("Dumping failed for pid '%d': %s\n", pid, strerror(errno));
812                 }
813             }
814             dumpPipe.writeFd().reset();
815             _exit(EXIT_SUCCESS);
816         }
817         dumpPipe.writeFd().reset();
818         // Parent process.
819         // Read from the pipe concurrently to avoid blocking the child.
820         FdBuffer buffer;
821         err = buffer.readFully(dumpPipe.readFd().get());
822         // Wait on the child to avoid it becoming a zombie process.
823         status_t cStatus = wait_child(child);
824         if (err != NO_ERROR) {
825             ALOGW("[%s] failed to read stack dump: %d", this->name.string(), err);
826             dumpPipe.readFd().reset();
827             break;
828         }
829         if (cStatus != NO_ERROR) {
830             ALOGE("[%s] child had an issue: %s\n", this->name.string(), strerror(-cStatus));
831         }
832 
833         // Resize dump buffer
834         if (dumpBufferSize < buffer.size()) {
835             munmap(dumpBuffer, dumpBufferSize);
836             while(dumpBufferSize < buffer.size()) dumpBufferSize = dumpBufferSize << 1;
837             dumpBuffer = (char*)mmap(NULL, dumpBufferSize, PROT_READ | PROT_WRITE,
838                     MAP_ANONYMOUS | MAP_PRIVATE, -1, 0);
839         }
840         sp<ProtoReader> reader = buffer.data()->read();
841         int i = 0;
842         while (reader->hasNext()) {
843             dumpBuffer[i] = reader->next();
844             i++;
845         }
846         uint64_t token = proto.start(android::os::BackTraceProto::TRACES);
847         proto.write(android::os::BackTraceProto::Stack::PID, pid);
848         proto.write(android::os::BackTraceProto::Stack::DUMP, dumpBuffer, i);
849         proto.write(android::os::BackTraceProto::Stack::DUMP_DURATION_NS,
850                     static_cast<long long>(Nanotime() - start));
851         proto.end(token);
852         dumpPipe.readFd().reset();
853         if (!proto.flush(pipeWriteFd.get())) {
854             if (errno == EPIPE) {
855                 ALOGE("[%s] wrote to a broken pipe\n", this->name.string());
856             }
857             err = errno;
858             break;
859         }
860         proto.clear();
861     }
862     munmap(dumpBuffer, dumpBufferSize);
863     return_buffer_to_pool(pooledBuffer);
864     return err;
865 }
866 
867 // ================================================================================
BringYourOwnSection(int id,const char * customName,const uid_t callingUid,const sp<IIncidentDumpCallback> & callback)868 BringYourOwnSection::BringYourOwnSection(int id, const char* customName, const uid_t callingUid,
869         const sp<IIncidentDumpCallback>& callback)
870     : WorkerThreadSection(id, REMOTE_CALL_TIMEOUT_MS), uid(callingUid), mCallback(callback) {
871     name = "registered ";
872     name += customName;
873 }
874 
~BringYourOwnSection()875 BringYourOwnSection::~BringYourOwnSection() {}
876 
BlockingCall(unique_fd & pipeWriteFd) const877 status_t BringYourOwnSection::BlockingCall(unique_fd& pipeWriteFd) const {
878     android::os::ParcelFileDescriptor pfd(std::move(pipeWriteFd));
879     if(mCallback != nullptr) {
880         mCallback->onDumpSection(pfd);
881     }
882     return NO_ERROR;
883 }
884 
885 }  // namespace incidentd
886 }  // namespace os
887 }  // namespace android
888