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