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