blob: 6dd76a8d0421123028a17a1e15b1fd9bae3429c0 [file] [log] [blame]
Joe Onorato1754d742016-11-21 17:51:35 -08001/*
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 */
Yi Jin4e843102018-02-14 15:36:18 -080016#define DEBUG false
Yi Jinb592e3b2018-02-01 15:17:04 -080017#include "Log.h"
Joe Onorato1754d742016-11-21 17:51:35 -080018
19#include "Section.h"
Yi Jin99c248f2017-08-25 18:11:58 -070020
Kweku Adamseadd1232018-02-05 16:45:13 -080021#include <dirent.h>
22#include <errno.h>
Yi Jin3c034c92017-12-22 17:36:47 -080023#include <wait.h>
24
Yi Jin3c034c92017-12-22 17:36:47 -080025#include <mutex>
Kweku Adamseadd1232018-02-05 16:45:13 -080026#include <set>
Joe Onorato1754d742016-11-21 17:51:35 -080027
Yi Jinb592e3b2018-02-01 15:17:04 -080028#include <android-base/file.h>
Kweku Adamseadd1232018-02-05 16:45:13 -080029#include <android-base/stringprintf.h>
Yi Jinc23fad22017-09-15 17:24:59 -070030#include <android/util/protobuf.h>
Joe Onorato1754d742016-11-21 17:51:35 -080031#include <binder/IServiceManager.h>
Kweku Adamseadd1232018-02-05 16:45:13 -080032#include <debuggerd/client.h>
33#include <dumputils/dump_utils.h>
Yi Jin3c034c92017-12-22 17:36:47 -080034#include <log/log_event_list.h>
Yi Jin3c034c92017-12-22 17:36:47 -080035#include <log/log_read.h>
Yi Jinb592e3b2018-02-01 15:17:04 -080036#include <log/logprint.h>
Yi Jin3c034c92017-12-22 17:36:47 -080037#include <private/android_logger.h>
38
39#include "FdBuffer.h"
Yi Jin3c034c92017-12-22 17:36:47 -080040#include "Privacy.h"
41#include "PrivacyBuffer.h"
Kweku Adamseadd1232018-02-05 16:45:13 -080042#include "frameworks/base/core/proto/android/os/backtrace.proto.h"
Yi Jin1a11fa12018-02-22 16:44:10 -080043#include "frameworks/base/core/proto/android/os/data.proto.h"
Yi Jinb592e3b2018-02-01 15:17:04 -080044#include "frameworks/base/core/proto/android/util/log.proto.h"
45#include "incidentd_util.h"
Joe Onorato1754d742016-11-21 17:51:35 -080046
Yi Jinb592e3b2018-02-01 15:17:04 -080047using namespace android::base;
Yi Jinc23fad22017-09-15 17:24:59 -070048using namespace android::util;
Joe Onorato1754d742016-11-21 17:51:35 -080049using namespace std;
50
Yi Jinc23fad22017-09-15 17:24:59 -070051// special section ids
52const int FIELD_ID_INCIDENT_HEADER = 1;
Yi Jin329130b2018-02-09 16:47:47 -080053const int FIELD_ID_INCIDENT_METADATA = 2;
Yi Jinc23fad22017-09-15 17:24:59 -070054
55// incident section parameters
Yi Jinb592e3b2018-02-01 15:17:04 -080056const int WAIT_MAX = 5;
Yi Jinb44f7d42017-07-21 12:12:59 -070057const struct timespec WAIT_INTERVAL_NS = {0, 200 * 1000 * 1000};
Yi Jin3c034c92017-12-22 17:36:47 -080058const char INCIDENT_HELPER[] = "/system/bin/incident_helper";
Yi Jin1a11fa12018-02-22 16:44:10 -080059const char GZIP[] = "/system/bin/gzip";
Yi Jinb44f7d42017-07-21 12:12:59 -070060
Yi Jin1a11fa12018-02-22 16:44:10 -080061static pid_t fork_execute_incident_helper(const int id, Fpipe* p2cPipe, Fpipe* c2pPipe) {
Yi Jinb592e3b2018-02-01 15:17:04 -080062 const char* ihArgs[]{INCIDENT_HELPER, "-s", String8::format("%d", id).string(), NULL};
Yi Jin1a11fa12018-02-22 16:44:10 -080063 return fork_execute_cmd(INCIDENT_HELPER, const_cast<char**>(ihArgs), p2cPipe, c2pPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -070064}
65
Yi Jin99c248f2017-08-25 18:11:58 -070066// ================================================================================
Yi Jin4bab3a12018-01-10 16:50:59 -080067static status_t statusCode(int status) {
68 if (WIFSIGNALED(status)) {
Yi Jinb592e3b2018-02-01 15:17:04 -080069 VLOG("return by signal: %s", strerror(WTERMSIG(status)));
70 return -WTERMSIG(status);
Yi Jin4bab3a12018-01-10 16:50:59 -080071 } else if (WIFEXITED(status) && WEXITSTATUS(status) > 0) {
Yi Jinb592e3b2018-02-01 15:17:04 -080072 VLOG("return by exit: %s", strerror(WEXITSTATUS(status)));
73 return -WEXITSTATUS(status);
Yi Jin4bab3a12018-01-10 16:50:59 -080074 }
75 return NO_ERROR;
76}
77
Yi Jinedfd5bb2017-09-06 17:09:11 -070078static status_t kill_child(pid_t pid) {
Yi Jinb44f7d42017-07-21 12:12:59 -070079 int status;
Yi Jinb592e3b2018-02-01 15:17:04 -080080 VLOG("try to kill child process %d", pid);
Yi Jinb44f7d42017-07-21 12:12:59 -070081 kill(pid, SIGKILL);
82 if (waitpid(pid, &status, 0) == -1) return -1;
Yi Jin4bab3a12018-01-10 16:50:59 -080083 return statusCode(status);
Yi Jinb44f7d42017-07-21 12:12:59 -070084}
85
Yi Jinedfd5bb2017-09-06 17:09:11 -070086static status_t wait_child(pid_t pid) {
Yi Jinb44f7d42017-07-21 12:12:59 -070087 int status;
88 bool died = false;
89 // wait for child to report status up to 1 seconds
Yi Jinb592e3b2018-02-01 15:17:04 -080090 for (int loop = 0; !died && loop < WAIT_MAX; loop++) {
Yi Jinb44f7d42017-07-21 12:12:59 -070091 if (waitpid(pid, &status, WNOHANG) == pid) died = true;
92 // sleep for 0.2 second
93 nanosleep(&WAIT_INTERVAL_NS, NULL);
94 }
Yi Jinedfd5bb2017-09-06 17:09:11 -070095 if (!died) return kill_child(pid);
Yi Jin4bab3a12018-01-10 16:50:59 -080096 return statusCode(status);
Yi Jinb44f7d42017-07-21 12:12:59 -070097}
Joe Onorato1754d742016-11-21 17:51:35 -080098// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -080099static status_t write_section_header(int fd, int sectionId, size_t size) {
Yi Jin99c248f2017-08-25 18:11:58 -0700100 uint8_t buf[20];
Yi Jinb592e3b2018-02-01 15:17:04 -0800101 uint8_t* p = write_length_delimited_tag_header(buf, sectionId, size);
102 return WriteFully(fd, buf, p - buf) ? NO_ERROR : -errno;
Yi Jin99c248f2017-08-25 18:11:58 -0700103}
104
Kweku Adamseadd1232018-02-05 16:45:13 -0800105// Reads data from FdBuffer and writes it to the requests file descriptor.
Yi Jinb592e3b2018-02-01 15:17:04 -0800106static status_t write_report_requests(const int id, const FdBuffer& buffer,
107 ReportRequestSet* requests) {
Yi Jin0f047162017-09-05 13:44:22 -0700108 status_t err = -EBADF;
Yi Jinc23fad22017-09-15 17:24:59 -0700109 EncodedBuffer::iterator data = buffer.data();
110 PrivacyBuffer privacyBuffer(get_privacy_of_section(id), data);
Yi Jin99c248f2017-08-25 18:11:58 -0700111 int writeable = 0;
Yi Jin329130b2018-02-09 16:47:47 -0800112 auto stats = requests->sectionStats(id);
113
114 stats->set_dump_size_bytes(data.size());
115 stats->set_dump_duration_ms(buffer.durationMs());
116 stats->set_timed_out(buffer.timedOut());
117 stats->set_is_truncated(buffer.truncated());
Yi Jin99c248f2017-08-25 18:11:58 -0700118
Yi Jin0f047162017-09-05 13:44:22 -0700119 // The streaming ones, group requests by spec in order to save unnecessary strip operations
120 map<PrivacySpec, vector<sp<ReportRequest>>> requestsBySpec;
Yi Jin3ec5cc72018-01-26 13:42:43 -0800121 for (auto it = requests->begin(); it != requests->end(); it++) {
Yi Jin99c248f2017-08-25 18:11:58 -0700122 sp<ReportRequest> request = *it;
Yi Jinedfd5bb2017-09-06 17:09:11 -0700123 if (!request->ok() || !request->args.containsSection(id)) {
Yi Jin0f047162017-09-05 13:44:22 -0700124 continue; // skip invalid request
Yi Jin99c248f2017-08-25 18:11:58 -0700125 }
Yi Jin3ec5cc72018-01-26 13:42:43 -0800126 PrivacySpec spec = PrivacySpec::new_spec(request->args.dest());
Yi Jin0f047162017-09-05 13:44:22 -0700127 requestsBySpec[spec].push_back(request);
128 }
129
Yi Jin3ec5cc72018-01-26 13:42:43 -0800130 for (auto mit = requestsBySpec.begin(); mit != requestsBySpec.end(); mit++) {
Yi Jin0f047162017-09-05 13:44:22 -0700131 PrivacySpec spec = mit->first;
Yi Jinc23fad22017-09-15 17:24:59 -0700132 err = privacyBuffer.strip(spec);
Yi Jinb592e3b2018-02-01 15:17:04 -0800133 if (err != NO_ERROR) return err; // it means the privacyBuffer data is corrupted.
Yi Jinc23fad22017-09-15 17:24:59 -0700134 if (privacyBuffer.size() == 0) continue;
Yi Jin0f047162017-09-05 13:44:22 -0700135
Yi Jin3ec5cc72018-01-26 13:42:43 -0800136 for (auto it = mit->second.begin(); it != mit->second.end(); it++) {
Yi Jin0f047162017-09-05 13:44:22 -0700137 sp<ReportRequest> request = *it;
Yi Jinc23fad22017-09-15 17:24:59 -0700138 err = write_section_header(request->fd, id, privacyBuffer.size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800139 if (err != NO_ERROR) {
140 request->err = err;
141 continue;
142 }
Yi Jinc23fad22017-09-15 17:24:59 -0700143 err = privacyBuffer.flush(request->fd);
Yi Jinb592e3b2018-02-01 15:17:04 -0800144 if (err != NO_ERROR) {
145 request->err = err;
146 continue;
147 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700148 writeable++;
Yi Jinb592e3b2018-02-01 15:17:04 -0800149 VLOG("Section %d flushed %zu bytes to fd %d with spec %d", id, privacyBuffer.size(),
150 request->fd, spec.dest);
Yi Jin0f047162017-09-05 13:44:22 -0700151 }
Yi Jinc23fad22017-09-15 17:24:59 -0700152 privacyBuffer.clear();
Yi Jin99c248f2017-08-25 18:11:58 -0700153 }
154
155 // The dropbox file
156 if (requests->mainFd() >= 0) {
Yi Jin329130b2018-02-09 16:47:47 -0800157 PrivacySpec spec = PrivacySpec::new_spec(requests->mainDest());
Yi Jin3ec5cc72018-01-26 13:42:43 -0800158 err = privacyBuffer.strip(spec);
Yi Jinb592e3b2018-02-01 15:17:04 -0800159 if (err != NO_ERROR) return err; // the buffer data is corrupted.
Yi Jinc23fad22017-09-15 17:24:59 -0700160 if (privacyBuffer.size() == 0) goto DONE;
Yi Jin0f047162017-09-05 13:44:22 -0700161
Yi Jinc23fad22017-09-15 17:24:59 -0700162 err = write_section_header(requests->mainFd(), id, privacyBuffer.size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800163 if (err != NO_ERROR) {
164 requests->setMainFd(-1);
165 goto DONE;
166 }
Yi Jinc23fad22017-09-15 17:24:59 -0700167 err = privacyBuffer.flush(requests->mainFd());
Yi Jinb592e3b2018-02-01 15:17:04 -0800168 if (err != NO_ERROR) {
169 requests->setMainFd(-1);
170 goto DONE;
171 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700172 writeable++;
Yi Jinb592e3b2018-02-01 15:17:04 -0800173 VLOG("Section %d flushed %zu bytes to dropbox %d with spec %d", id, privacyBuffer.size(),
174 requests->mainFd(), spec.dest);
Yi Jin329130b2018-02-09 16:47:47 -0800175 stats->set_report_size_bytes(privacyBuffer.size());
Yi Jin99c248f2017-08-25 18:11:58 -0700176 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700177
178DONE:
Yi Jin99c248f2017-08-25 18:11:58 -0700179 // only returns error if there is no fd to write to.
180 return writeable > 0 ? NO_ERROR : err;
181}
182
183// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800184Section::Section(int i, const int64_t timeoutMs) : id(i), timeoutMs(timeoutMs) {}
Joe Onorato1754d742016-11-21 17:51:35 -0800185
Yi Jinb592e3b2018-02-01 15:17:04 -0800186Section::~Section() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800187
Joe Onorato1754d742016-11-21 17:51:35 -0800188// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800189HeaderSection::HeaderSection() : Section(FIELD_ID_INCIDENT_HEADER, 0) {}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700190
Yi Jinb592e3b2018-02-01 15:17:04 -0800191HeaderSection::~HeaderSection() {}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700192
Yi Jinb592e3b2018-02-01 15:17:04 -0800193status_t HeaderSection::Execute(ReportRequestSet* requests) const {
194 for (ReportRequestSet::iterator it = requests->begin(); it != requests->end(); it++) {
Yi Jinedfd5bb2017-09-06 17:09:11 -0700195 const sp<ReportRequest> request = *it;
Yi Jinbdf58942017-11-14 17:58:19 -0800196 const vector<vector<uint8_t>>& headers = request->args.headers();
Yi Jinedfd5bb2017-09-06 17:09:11 -0700197
Yi Jinb592e3b2018-02-01 15:17:04 -0800198 for (vector<vector<uint8_t>>::const_iterator buf = headers.begin(); buf != headers.end();
199 buf++) {
Yi Jinedfd5bb2017-09-06 17:09:11 -0700200 if (buf->empty()) continue;
201
202 // So the idea is only requests with negative fd are written to dropbox file.
203 int fd = request->fd >= 0 ? request->fd : requests->mainFd();
Yi Jin329130b2018-02-09 16:47:47 -0800204 write_section_header(fd, id, buf->size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800205 WriteFully(fd, (uint8_t const*)buf->data(), buf->size());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700206 // If there was an error now, there will be an error later and we will remove
207 // it from the list then.
208 }
209 }
210 return NO_ERROR;
211}
Yi Jin329130b2018-02-09 16:47:47 -0800212// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800213MetadataSection::MetadataSection() : Section(FIELD_ID_INCIDENT_METADATA, 0) {}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700214
Yi Jinb592e3b2018-02-01 15:17:04 -0800215MetadataSection::~MetadataSection() {}
Yi Jin329130b2018-02-09 16:47:47 -0800216
Yi Jinb592e3b2018-02-01 15:17:04 -0800217status_t MetadataSection::Execute(ReportRequestSet* requests) const {
Yi Jin329130b2018-02-09 16:47:47 -0800218 std::string metadataBuf;
219 requests->metadata().SerializeToString(&metadataBuf);
Yi Jinb592e3b2018-02-01 15:17:04 -0800220 for (ReportRequestSet::iterator it = requests->begin(); it != requests->end(); it++) {
Yi Jin329130b2018-02-09 16:47:47 -0800221 const sp<ReportRequest> request = *it;
222 if (metadataBuf.empty() || request->fd < 0 || request->err != NO_ERROR) {
223 continue;
224 }
225 write_section_header(request->fd, id, metadataBuf.size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800226 if (!WriteFully(request->fd, (uint8_t const*)metadataBuf.data(), metadataBuf.size())) {
227 ALOGW("Failed to write metadata to fd %d", request->fd);
228 // we don't fail if we can't write to a single request's fd.
229 }
Yi Jin329130b2018-02-09 16:47:47 -0800230 }
231 if (requests->mainFd() >= 0 && !metadataBuf.empty()) {
232 write_section_header(requests->mainFd(), id, metadataBuf.size());
Yi Jin4e843102018-02-14 15:36:18 -0800233 if (!WriteFully(requests->mainFd(), (uint8_t const*)metadataBuf.data(),
234 metadataBuf.size())) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800235 ALOGW("Failed to write metadata to dropbox fd %d", requests->mainFd());
236 return -1;
237 }
Yi Jin329130b2018-02-09 16:47:47 -0800238 }
239 return NO_ERROR;
240}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700241// ================================================================================
Yi Jin1a11fa12018-02-22 16:44:10 -0800242static inline bool isSysfs(const char* filename) { return strncmp(filename, "/sys/", 5) == 0; }
243
Yi Jinb44f7d42017-07-21 12:12:59 -0700244FileSection::FileSection(int id, const char* filename, const int64_t timeoutMs)
Yi Jinb592e3b2018-02-01 15:17:04 -0800245 : Section(id, timeoutMs), mFilename(filename) {
Yi Jinb44f7d42017-07-21 12:12:59 -0700246 name = filename;
Yi Jin1a11fa12018-02-22 16:44:10 -0800247 mIsSysfs = isSysfs(filename);
Yi Jin0a3406f2017-06-22 19:23:11 -0700248}
249
250FileSection::~FileSection() {}
251
Yi Jinb592e3b2018-02-01 15:17:04 -0800252status_t FileSection::Execute(ReportRequestSet* requests) const {
Yi Jinb44f7d42017-07-21 12:12:59 -0700253 // read from mFilename first, make sure the file is available
254 // add O_CLOEXEC to make sure it is closed when exec incident helper
George Burgess IV6f9735b2017-08-03 16:08:29 -0700255 int fd = open(mFilename, O_RDONLY | O_CLOEXEC);
Yi Jin0a3406f2017-06-22 19:23:11 -0700256 if (fd == -1) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800257 ALOGW("FileSection '%s' failed to open file", this->name.string());
258 return -errno;
Yi Jin0a3406f2017-06-22 19:23:11 -0700259 }
260
Yi Jinb44f7d42017-07-21 12:12:59 -0700261 FdBuffer buffer;
262 Fpipe p2cPipe;
263 Fpipe c2pPipe;
264 // initiate pipes to pass data to/from incident_helper
265 if (!p2cPipe.init() || !c2pPipe.init()) {
266 ALOGW("FileSection '%s' failed to setup pipes", this->name.string());
Yi Jin0a3406f2017-06-22 19:23:11 -0700267 return -errno;
268 }
269
Yi Jin1a11fa12018-02-22 16:44:10 -0800270 pid_t pid = fork_execute_incident_helper(this->id, &p2cPipe, &c2pPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -0700271 if (pid == -1) {
272 ALOGW("FileSection '%s' failed to fork", this->name.string());
273 return -errno;
274 }
275
276 // parent process
277 status_t readStatus = buffer.readProcessedDataInStream(fd, p2cPipe.writeFd(), c2pPipe.readFd(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800278 this->timeoutMs, mIsSysfs);
Yi Jin1a11fa12018-02-22 16:44:10 -0800279 close(fd); // close the fd anyway.
280
Yi Jinb44f7d42017-07-21 12:12:59 -0700281 if (readStatus != NO_ERROR || buffer.timedOut()) {
Yi Jin4bab3a12018-01-10 16:50:59 -0800282 ALOGW("FileSection '%s' failed to read data from incident helper: %s, timedout: %s",
Yi Jinb592e3b2018-02-01 15:17:04 -0800283 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
Yi Jin4bab3a12018-01-10 16:50:59 -0800284 kill_child(pid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700285 return readStatus;
286 }
287
Yi Jinedfd5bb2017-09-06 17:09:11 -0700288 status_t ihStatus = wait_child(pid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700289 if (ihStatus != NO_ERROR) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800290 ALOGW("FileSection '%s' abnormal child process: %s", this->name.string(),
291 strerror(-ihStatus));
Yi Jinb44f7d42017-07-21 12:12:59 -0700292 return ihStatus;
293 }
294
Yi Jinb592e3b2018-02-01 15:17:04 -0800295 VLOG("FileSection '%s' wrote %zd bytes in %d ms", this->name.string(), buffer.size(),
296 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700297 status_t err = write_report_requests(this->id, buffer, requests);
Yi Jin0a3406f2017-06-22 19:23:11 -0700298 if (err != NO_ERROR) {
299 ALOGW("FileSection '%s' failed writing: %s", this->name.string(), strerror(-err));
300 return err;
301 }
302
303 return NO_ERROR;
304}
Yi Jin1a11fa12018-02-22 16:44:10 -0800305// ================================================================================
306GZipSection::GZipSection(int id, const char* filename, ...) : Section(id) {
307 name = "gzip ";
308 name += filename;
309 va_list args;
310 va_start(args, filename);
311 mFilenames = varargs(filename, args);
312 va_end(args);
313}
Yi Jin0a3406f2017-06-22 19:23:11 -0700314
Yi Jin1a11fa12018-02-22 16:44:10 -0800315GZipSection::~GZipSection() {}
316
317status_t GZipSection::Execute(ReportRequestSet* requests) const {
318 // Reads the files in order, use the first available one.
319 int index = 0;
320 int fd = -1;
321 while (mFilenames[index] != NULL) {
322 fd = open(mFilenames[index], O_RDONLY | O_CLOEXEC);
323 if (fd != -1) {
324 break;
325 }
326 ALOGW("GZipSection failed to open file %s", mFilenames[index]);
327 index++; // look at the next file.
328 }
329 VLOG("GZipSection is using file %s, fd=%d", mFilenames[index], fd);
330 if (fd == -1) return -1;
331
332 FdBuffer buffer;
333 Fpipe p2cPipe;
334 Fpipe c2pPipe;
335 // initiate pipes to pass data to/from gzip
336 if (!p2cPipe.init() || !c2pPipe.init()) {
337 ALOGW("GZipSection '%s' failed to setup pipes", this->name.string());
338 return -errno;
339 }
340
341 const char* gzipArgs[]{GZIP, NULL};
342 pid_t pid = fork_execute_cmd(GZIP, const_cast<char**>(gzipArgs), &p2cPipe, &c2pPipe);
343 if (pid == -1) {
344 ALOGW("GZipSection '%s' failed to fork", this->name.string());
345 return -errno;
346 }
347 // parent process
348
349 // construct Fdbuffer to output GZippedfileProto, the reason to do this instead of using
350 // ProtoOutputStream is to avoid allocation of another buffer inside ProtoOutputStream.
351 EncodedBuffer* internalBuffer = buffer.getInternalBuffer();
352 internalBuffer->writeHeader((uint32_t)GZippedFileProto::FILENAME, WIRE_TYPE_LENGTH_DELIMITED);
353 String8 usedFile(mFilenames[index]);
354 internalBuffer->writeRawVarint32(usedFile.size());
355 for (size_t i = 0; i < usedFile.size(); i++) {
356 internalBuffer->writeRawByte(mFilenames[index][i]);
357 }
358 internalBuffer->writeHeader((uint32_t)GZippedFileProto::GZIPPED_DATA,
359 WIRE_TYPE_LENGTH_DELIMITED);
360 size_t editPos = internalBuffer->wp()->pos();
361 internalBuffer->wp()->move(8); // reserve 8 bytes for the varint of the data size.
362 size_t dataBeginAt = internalBuffer->wp()->pos();
363 VLOG("GZipSection '%s' editPos=%zd, dataBeginAt=%zd", this->name.string(), editPos,
364 dataBeginAt);
365
366 status_t readStatus = buffer.readProcessedDataInStream(
367 fd, p2cPipe.writeFd(), c2pPipe.readFd(), this->timeoutMs, isSysfs(mFilenames[index]));
368 close(fd); // close the fd anyway.
369
370 if (readStatus != NO_ERROR || buffer.timedOut()) {
371 ALOGW("GZipSection '%s' failed to read data from gzip: %s, timedout: %s",
372 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
373 kill_child(pid);
374 return readStatus;
375 }
376
377 status_t gzipStatus = wait_child(pid);
378 if (gzipStatus != NO_ERROR) {
379 ALOGW("GZipSection '%s' abnormal child process: %s", this->name.string(),
380 strerror(-gzipStatus));
381 return gzipStatus;
382 }
383 // Revisit the actual size from gzip result and edit the internal buffer accordingly.
384 size_t dataSize = buffer.size() - dataBeginAt;
385 internalBuffer->wp()->rewind()->move(editPos);
386 internalBuffer->writeRawVarint32(dataSize);
387 internalBuffer->copy(dataBeginAt, dataSize);
388 VLOG("GZipSection '%s' wrote %zd bytes in %d ms, dataSize=%zd", this->name.string(),
389 buffer.size(), (int)buffer.durationMs(), dataSize);
390 status_t err = write_report_requests(this->id, buffer, requests);
391 if (err != NO_ERROR) {
392 ALOGW("GZipSection '%s' failed writing: %s", this->name.string(), strerror(-err));
393 return err;
394 }
395
396 return NO_ERROR;
397}
Kweku Adamseadd1232018-02-05 16:45:13 -0800398
Yi Jin0a3406f2017-06-22 19:23:11 -0700399// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800400struct WorkerThreadData : public virtual RefBase {
Joe Onorato1754d742016-11-21 17:51:35 -0800401 const WorkerThreadSection* section;
402 int fds[2];
403
404 // Lock protects these fields
405 mutex lock;
406 bool workerDone;
407 status_t workerError;
408
409 WorkerThreadData(const WorkerThreadSection* section);
410 virtual ~WorkerThreadData();
411
412 int readFd() { return fds[0]; }
413 int writeFd() { return fds[1]; }
414};
415
416WorkerThreadData::WorkerThreadData(const WorkerThreadSection* sec)
Yi Jinb592e3b2018-02-01 15:17:04 -0800417 : section(sec), workerDone(false), workerError(NO_ERROR) {
Joe Onorato1754d742016-11-21 17:51:35 -0800418 fds[0] = -1;
419 fds[1] = -1;
420}
421
Yi Jinb592e3b2018-02-01 15:17:04 -0800422WorkerThreadData::~WorkerThreadData() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800423
424// ================================================================================
Kweku Adamseadd1232018-02-05 16:45:13 -0800425WorkerThreadSection::WorkerThreadSection(int id, const int64_t timeoutMs)
426 : Section(id, timeoutMs) {}
Joe Onorato1754d742016-11-21 17:51:35 -0800427
Yi Jinb592e3b2018-02-01 15:17:04 -0800428WorkerThreadSection::~WorkerThreadSection() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800429
Yi Jinb592e3b2018-02-01 15:17:04 -0800430static void* worker_thread_func(void* cookie) {
Joe Onorato1754d742016-11-21 17:51:35 -0800431 WorkerThreadData* data = (WorkerThreadData*)cookie;
432 status_t err = data->section->BlockingCall(data->writeFd());
433
434 {
435 unique_lock<mutex> lock(data->lock);
436 data->workerDone = true;
437 data->workerError = err;
438 }
439
440 close(data->writeFd());
441 data->decStrong(data->section);
442 // data might be gone now. don't use it after this point in this thread.
443 return NULL;
444}
445
Yi Jinb592e3b2018-02-01 15:17:04 -0800446status_t WorkerThreadSection::Execute(ReportRequestSet* requests) const {
Joe Onorato1754d742016-11-21 17:51:35 -0800447 status_t err = NO_ERROR;
448 pthread_t thread;
449 pthread_attr_t attr;
450 bool timedOut = false;
451 FdBuffer buffer;
452
453 // Data shared between this thread and the worker thread.
454 sp<WorkerThreadData> data = new WorkerThreadData(this);
455
456 // Create the pipe
457 err = pipe(data->fds);
458 if (err != 0) {
459 return -errno;
460 }
461
462 // The worker thread needs a reference and we can't let the count go to zero
463 // if that thread is slow to start.
464 data->incStrong(this);
465
466 // Create the thread
467 err = pthread_attr_init(&attr);
468 if (err != 0) {
469 return -err;
470 }
471 // TODO: Do we need to tweak thread priority?
472 err = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
473 if (err != 0) {
474 pthread_attr_destroy(&attr);
475 return -err;
476 }
477 err = pthread_create(&thread, &attr, worker_thread_func, (void*)data.get());
478 if (err != 0) {
479 pthread_attr_destroy(&attr);
480 return -err;
481 }
482 pthread_attr_destroy(&attr);
483
484 // Loop reading until either the timeout or the worker side is done (i.e. eof).
Yi Jinb44f7d42017-07-21 12:12:59 -0700485 err = buffer.read(data->readFd(), this->timeoutMs);
Joe Onorato1754d742016-11-21 17:51:35 -0800486 if (err != NO_ERROR) {
487 // TODO: Log this error into the incident report.
488 ALOGW("WorkerThreadSection '%s' reader failed with error '%s'", this->name.string(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800489 strerror(-err));
Joe Onorato1754d742016-11-21 17:51:35 -0800490 }
491
492 // Done with the read fd. The worker thread closes the write one so
493 // we never race and get here first.
494 close(data->readFd());
495
496 // If the worker side is finished, then return its error (which may overwrite
497 // our possible error -- but it's more interesting anyway). If not, then we timed out.
498 {
499 unique_lock<mutex> lock(data->lock);
500 if (!data->workerDone) {
501 // We timed out
502 timedOut = true;
503 } else {
504 if (data->workerError != NO_ERROR) {
505 err = data->workerError;
506 // TODO: Log this error into the incident report.
507 ALOGW("WorkerThreadSection '%s' worker failed with error '%s'", this->name.string(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800508 strerror(-err));
Joe Onorato1754d742016-11-21 17:51:35 -0800509 }
510 }
511 }
512
513 if (timedOut || buffer.timedOut()) {
514 ALOGW("WorkerThreadSection '%s' timed out", this->name.string());
515 return NO_ERROR;
516 }
517
518 if (buffer.truncated()) {
519 // TODO: Log this into the incident report.
520 }
521
522 // TODO: There was an error with the command or buffering. Report that. For now
523 // just exit with a log messasge.
524 if (err != NO_ERROR) {
525 ALOGW("WorkerThreadSection '%s' failed with error '%s'", this->name.string(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800526 strerror(-err));
Joe Onorato1754d742016-11-21 17:51:35 -0800527 return NO_ERROR;
528 }
529
530 // Write the data that was collected
Yi Jinb592e3b2018-02-01 15:17:04 -0800531 VLOG("WorkerThreadSection '%s' wrote %zd bytes in %d ms", name.string(), buffer.size(),
532 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700533 err = write_report_requests(this->id, buffer, requests);
Joe Onorato1754d742016-11-21 17:51:35 -0800534 if (err != NO_ERROR) {
535 ALOGW("WorkerThreadSection '%s' failed writing: '%s'", this->name.string(), strerror(-err));
536 return err;
537 }
538
539 return NO_ERROR;
540}
541
542// ================================================================================
Yi Jinb44f7d42017-07-21 12:12:59 -0700543CommandSection::CommandSection(int id, const int64_t timeoutMs, const char* command, ...)
Yi Jinb592e3b2018-02-01 15:17:04 -0800544 : Section(id, timeoutMs) {
Yi Jin1a11fa12018-02-22 16:44:10 -0800545 name = command;
Joe Onorato1754d742016-11-21 17:51:35 -0800546 va_list args;
Yi Jinb44f7d42017-07-21 12:12:59 -0700547 va_start(args, command);
Yi Jin1a11fa12018-02-22 16:44:10 -0800548 mCommand = varargs(command, args);
Joe Onorato1754d742016-11-21 17:51:35 -0800549 va_end(args);
Yi Jinb44f7d42017-07-21 12:12:59 -0700550}
Joe Onorato1754d742016-11-21 17:51:35 -0800551
Yi Jinb592e3b2018-02-01 15:17:04 -0800552CommandSection::CommandSection(int id, const char* command, ...) : Section(id) {
Yi Jin1a11fa12018-02-22 16:44:10 -0800553 name = command;
Yi Jinb44f7d42017-07-21 12:12:59 -0700554 va_list args;
555 va_start(args, command);
Yi Jin1a11fa12018-02-22 16:44:10 -0800556 mCommand = varargs(command, args);
Joe Onorato1754d742016-11-21 17:51:35 -0800557 va_end(args);
558}
559
Yi Jinb592e3b2018-02-01 15:17:04 -0800560CommandSection::~CommandSection() { free(mCommand); }
Joe Onorato1754d742016-11-21 17:51:35 -0800561
Yi Jinb592e3b2018-02-01 15:17:04 -0800562status_t CommandSection::Execute(ReportRequestSet* requests) const {
Yi Jinb44f7d42017-07-21 12:12:59 -0700563 FdBuffer buffer;
564 Fpipe cmdPipe;
565 Fpipe ihPipe;
566
567 if (!cmdPipe.init() || !ihPipe.init()) {
568 ALOGW("CommandSection '%s' failed to setup pipes", this->name.string());
569 return -errno;
570 }
571
572 pid_t cmdPid = fork();
573 if (cmdPid == -1) {
574 ALOGW("CommandSection '%s' failed to fork", this->name.string());
575 return -errno;
576 }
577 // child process to execute the command as root
578 if (cmdPid == 0) {
579 // replace command's stdout with ihPipe's write Fd
580 if (dup2(cmdPipe.writeFd(), STDOUT_FILENO) != 1 || !ihPipe.close() || !cmdPipe.close()) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800581 ALOGW("CommandSection '%s' failed to set up stdout: %s", this->name.string(),
582 strerror(errno));
Yi Jinb44f7d42017-07-21 12:12:59 -0700583 _exit(EXIT_FAILURE);
584 }
Yi Jinb592e3b2018-02-01 15:17:04 -0800585 execvp(this->mCommand[0], (char* const*)this->mCommand);
586 int err = errno; // record command error code
587 ALOGW("CommandSection '%s' failed in executing command: %s", this->name.string(),
588 strerror(errno));
589 _exit(err); // exit with command error code
Yi Jinb44f7d42017-07-21 12:12:59 -0700590 }
Yi Jin1a11fa12018-02-22 16:44:10 -0800591 pid_t ihPid = fork_execute_incident_helper(this->id, &cmdPipe, &ihPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -0700592 if (ihPid == -1) {
593 ALOGW("CommandSection '%s' failed to fork", this->name.string());
594 return -errno;
595 }
596
597 close(cmdPipe.writeFd());
598 status_t readStatus = buffer.read(ihPipe.readFd(), this->timeoutMs);
599 if (readStatus != NO_ERROR || buffer.timedOut()) {
Yi Jin4bab3a12018-01-10 16:50:59 -0800600 ALOGW("CommandSection '%s' failed to read data from incident helper: %s, timedout: %s",
Yi Jinb592e3b2018-02-01 15:17:04 -0800601 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
Yi Jin4bab3a12018-01-10 16:50:59 -0800602 kill_child(cmdPid);
603 kill_child(ihPid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700604 return readStatus;
605 }
606
Kweku Adamseadd1232018-02-05 16:45:13 -0800607 // Waiting for command here has one trade-off: the failed status of command won't be detected
Yi Jin1a11fa12018-02-22 16:44:10 -0800608 // until buffer timeout, but it has advatage on starting the data stream earlier.
Yi Jinedfd5bb2017-09-06 17:09:11 -0700609 status_t cmdStatus = wait_child(cmdPid);
Yi Jinb592e3b2018-02-01 15:17:04 -0800610 status_t ihStatus = wait_child(ihPid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700611 if (cmdStatus != NO_ERROR || ihStatus != NO_ERROR) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800612 ALOGW("CommandSection '%s' abnormal child processes, return status: command: %s, incident "
613 "helper: %s",
614 this->name.string(), strerror(-cmdStatus), strerror(-ihStatus));
Yi Jinb44f7d42017-07-21 12:12:59 -0700615 return cmdStatus != NO_ERROR ? cmdStatus : ihStatus;
616 }
617
Yi Jinb592e3b2018-02-01 15:17:04 -0800618 VLOG("CommandSection '%s' wrote %zd bytes in %d ms", this->name.string(), buffer.size(),
619 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700620 status_t err = write_report_requests(this->id, buffer, requests);
Yi Jinb44f7d42017-07-21 12:12:59 -0700621 if (err != NO_ERROR) {
622 ALOGW("CommandSection '%s' failed writing: %s", this->name.string(), strerror(-err));
623 return err;
624 }
Joe Onorato1754d742016-11-21 17:51:35 -0800625 return NO_ERROR;
626}
627
628// ================================================================================
629DumpsysSection::DumpsysSection(int id, const char* service, ...)
Yi Jinb592e3b2018-02-01 15:17:04 -0800630 : WorkerThreadSection(id), mService(service) {
Joe Onorato1754d742016-11-21 17:51:35 -0800631 name = "dumpsys ";
632 name += service;
633
634 va_list args;
635 va_start(args, service);
636 while (true) {
Yi Jin0a3406f2017-06-22 19:23:11 -0700637 const char* arg = va_arg(args, const char*);
Joe Onorato1754d742016-11-21 17:51:35 -0800638 if (arg == NULL) {
639 break;
640 }
641 mArgs.add(String16(arg));
642 name += " ";
643 name += arg;
644 }
645 va_end(args);
646}
647
Yi Jinb592e3b2018-02-01 15:17:04 -0800648DumpsysSection::~DumpsysSection() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800649
Yi Jinb592e3b2018-02-01 15:17:04 -0800650status_t DumpsysSection::BlockingCall(int pipeWriteFd) const {
Joe Onorato1754d742016-11-21 17:51:35 -0800651 // checkService won't wait for the service to show up like getService will.
652 sp<IBinder> service = defaultServiceManager()->checkService(mService);
Yi Jin0a3406f2017-06-22 19:23:11 -0700653
Joe Onorato1754d742016-11-21 17:51:35 -0800654 if (service == NULL) {
655 // Returning an error interrupts the entire incident report, so just
656 // log the failure.
657 // TODO: have a meta record inside the report that would log this
658 // failure inside the report, because the fact that we can't find
659 // the service is good data in and of itself. This is running in
660 // another thread so lock that carefully...
661 ALOGW("DumpsysSection: Can't lookup service: %s", String8(mService).string());
662 return NO_ERROR;
663 }
664
665 service->dump(pipeWriteFd, mArgs);
666
667 return NO_ERROR;
668}
Yi Jin3c034c92017-12-22 17:36:47 -0800669
670// ================================================================================
671// initialization only once in Section.cpp.
672map<log_id_t, log_time> LogSection::gLastLogsRetrieved;
673
Yi Jinb592e3b2018-02-01 15:17:04 -0800674LogSection::LogSection(int id, log_id_t logID) : WorkerThreadSection(id), mLogID(logID) {
Yi Jin3c034c92017-12-22 17:36:47 -0800675 name += "logcat ";
676 name += android_log_id_to_name(logID);
677 switch (logID) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800678 case LOG_ID_EVENTS:
679 case LOG_ID_STATS:
680 case LOG_ID_SECURITY:
681 mBinary = true;
682 break;
683 default:
684 mBinary = false;
Yi Jin3c034c92017-12-22 17:36:47 -0800685 }
686}
687
Yi Jinb592e3b2018-02-01 15:17:04 -0800688LogSection::~LogSection() {}
Yi Jin3c034c92017-12-22 17:36:47 -0800689
Yi Jinb592e3b2018-02-01 15:17:04 -0800690static size_t trimTail(char const* buf, size_t len) {
Yi Jin3c034c92017-12-22 17:36:47 -0800691 while (len > 0) {
692 char c = buf[len - 1];
693 if (c == '\0' || c == ' ' || c == '\n' || c == '\r' || c == ':') {
694 len--;
695 } else {
696 break;
697 }
698 }
699 return len;
700}
701
702static inline int32_t get4LE(uint8_t const* src) {
703 return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
704}
705
Yi Jinb592e3b2018-02-01 15:17:04 -0800706status_t LogSection::BlockingCall(int pipeWriteFd) const {
Yi Jin3c034c92017-12-22 17:36:47 -0800707 // Open log buffer and getting logs since last retrieved time if any.
708 unique_ptr<logger_list, void (*)(logger_list*)> loggers(
Yi Jinb592e3b2018-02-01 15:17:04 -0800709 gLastLogsRetrieved.find(mLogID) == gLastLogsRetrieved.end()
710 ? android_logger_list_alloc(ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 0, 0)
711 : android_logger_list_alloc_time(ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
712 gLastLogsRetrieved[mLogID], 0),
713 android_logger_list_free);
Yi Jin3c034c92017-12-22 17:36:47 -0800714
715 if (android_logger_open(loggers.get(), mLogID) == NULL) {
716 ALOGW("LogSection %s: Can't get logger.", this->name.string());
Kweku Adamseadd1232018-02-05 16:45:13 -0800717 return NO_ERROR;
Yi Jin3c034c92017-12-22 17:36:47 -0800718 }
719
720 log_msg msg;
721 log_time lastTimestamp(0);
722
Kweku Adamseadd1232018-02-05 16:45:13 -0800723 status_t err = NO_ERROR;
Yi Jin3c034c92017-12-22 17:36:47 -0800724 ProtoOutputStream proto;
Yi Jinb592e3b2018-02-01 15:17:04 -0800725 while (true) { // keeps reading until logd buffer is fully read.
Kweku Adamseadd1232018-02-05 16:45:13 -0800726 err = android_logger_list_read(loggers.get(), &msg);
Yi Jin3c034c92017-12-22 17:36:47 -0800727 // err = 0 - no content, unexpected connection drop or EOF.
728 // err = +ive number - size of retrieved data from logger
729 // err = -ive number, OS supplied error _except_ for -EAGAIN
730 // err = -EAGAIN, graceful indication for ANDRODI_LOG_NONBLOCK that this is the end of data.
731 if (err <= 0) {
732 if (err != -EAGAIN) {
733 ALOGE("LogSection %s: fails to read a log_msg.\n", this->name.string());
734 }
735 break;
736 }
737 if (mBinary) {
738 // remove the first uint32 which is tag's index in event log tags
739 android_log_context context = create_android_log_parser(msg.msg() + sizeof(uint32_t),
Yi Jinb592e3b2018-02-01 15:17:04 -0800740 msg.len() - sizeof(uint32_t));
741 ;
Yi Jin3c034c92017-12-22 17:36:47 -0800742 android_log_list_element elem;
743
744 lastTimestamp.tv_sec = msg.entry_v1.sec;
745 lastTimestamp.tv_nsec = msg.entry_v1.nsec;
746
747 // format a BinaryLogEntry
Yi Jin5ee07872018-03-05 18:18:27 -0800748 uint64_t token = proto.start(LogProto::BINARY_LOGS);
Yi Jin3c034c92017-12-22 17:36:47 -0800749 proto.write(BinaryLogEntry::SEC, msg.entry_v1.sec);
750 proto.write(BinaryLogEntry::NANOSEC, msg.entry_v1.nsec);
Yi Jinb592e3b2018-02-01 15:17:04 -0800751 proto.write(BinaryLogEntry::UID, (int)msg.entry_v4.uid);
Yi Jin3c034c92017-12-22 17:36:47 -0800752 proto.write(BinaryLogEntry::PID, msg.entry_v1.pid);
753 proto.write(BinaryLogEntry::TID, msg.entry_v1.tid);
Yi Jinb592e3b2018-02-01 15:17:04 -0800754 proto.write(BinaryLogEntry::TAG_INDEX,
755 get4LE(reinterpret_cast<uint8_t const*>(msg.msg())));
Yi Jin3c034c92017-12-22 17:36:47 -0800756 do {
757 elem = android_log_read_next(context);
Yi Jin5ee07872018-03-05 18:18:27 -0800758 uint64_t elemToken = proto.start(BinaryLogEntry::ELEMS);
Yi Jin3c034c92017-12-22 17:36:47 -0800759 switch (elem.type) {
760 case EVENT_TYPE_INT:
Yi Jinb592e3b2018-02-01 15:17:04 -0800761 proto.write(BinaryLogEntry::Elem::TYPE,
762 BinaryLogEntry::Elem::EVENT_TYPE_INT);
763 proto.write(BinaryLogEntry::Elem::VAL_INT32, (int)elem.data.int32);
Yi Jin3c034c92017-12-22 17:36:47 -0800764 break;
765 case EVENT_TYPE_LONG:
Yi Jinb592e3b2018-02-01 15:17:04 -0800766 proto.write(BinaryLogEntry::Elem::TYPE,
767 BinaryLogEntry::Elem::EVENT_TYPE_LONG);
768 proto.write(BinaryLogEntry::Elem::VAL_INT64, (long long)elem.data.int64);
Yi Jin3c034c92017-12-22 17:36:47 -0800769 break;
770 case EVENT_TYPE_STRING:
Yi Jinb592e3b2018-02-01 15:17:04 -0800771 proto.write(BinaryLogEntry::Elem::TYPE,
772 BinaryLogEntry::Elem::EVENT_TYPE_STRING);
Yi Jin3c034c92017-12-22 17:36:47 -0800773 proto.write(BinaryLogEntry::Elem::VAL_STRING, elem.data.string, elem.len);
774 break;
775 case EVENT_TYPE_FLOAT:
Yi Jinb592e3b2018-02-01 15:17:04 -0800776 proto.write(BinaryLogEntry::Elem::TYPE,
777 BinaryLogEntry::Elem::EVENT_TYPE_FLOAT);
Yi Jin3c034c92017-12-22 17:36:47 -0800778 proto.write(BinaryLogEntry::Elem::VAL_FLOAT, elem.data.float32);
779 break;
780 case EVENT_TYPE_LIST:
Yi Jinb592e3b2018-02-01 15:17:04 -0800781 proto.write(BinaryLogEntry::Elem::TYPE,
782 BinaryLogEntry::Elem::EVENT_TYPE_LIST);
Yi Jin3c034c92017-12-22 17:36:47 -0800783 break;
784 case EVENT_TYPE_LIST_STOP:
Yi Jinb592e3b2018-02-01 15:17:04 -0800785 proto.write(BinaryLogEntry::Elem::TYPE,
786 BinaryLogEntry::Elem::EVENT_TYPE_LIST_STOP);
Yi Jin3c034c92017-12-22 17:36:47 -0800787 break;
788 case EVENT_TYPE_UNKNOWN:
Yi Jinb592e3b2018-02-01 15:17:04 -0800789 proto.write(BinaryLogEntry::Elem::TYPE,
790 BinaryLogEntry::Elem::EVENT_TYPE_UNKNOWN);
Yi Jin3c034c92017-12-22 17:36:47 -0800791 break;
792 }
793 proto.end(elemToken);
794 } while ((elem.type != EVENT_TYPE_UNKNOWN) && !elem.complete);
795 proto.end(token);
796 if (context) {
797 android_log_destroy(&context);
798 }
799 } else {
800 AndroidLogEntry entry;
801 err = android_log_processLogBuffer(&msg.entry_v1, &entry);
802 if (err != NO_ERROR) {
803 ALOGE("LogSection %s: fails to process to an entry.\n", this->name.string());
804 break;
805 }
806 lastTimestamp.tv_sec = entry.tv_sec;
807 lastTimestamp.tv_nsec = entry.tv_nsec;
808
809 // format a TextLogEntry
Yi Jin5ee07872018-03-05 18:18:27 -0800810 uint64_t token = proto.start(LogProto::TEXT_LOGS);
Yi Jin3c034c92017-12-22 17:36:47 -0800811 proto.write(TextLogEntry::SEC, (long long)entry.tv_sec);
812 proto.write(TextLogEntry::NANOSEC, (long long)entry.tv_nsec);
813 proto.write(TextLogEntry::PRIORITY, (int)entry.priority);
814 proto.write(TextLogEntry::UID, entry.uid);
815 proto.write(TextLogEntry::PID, entry.pid);
816 proto.write(TextLogEntry::TID, entry.tid);
817 proto.write(TextLogEntry::TAG, entry.tag, trimTail(entry.tag, entry.tagLen));
Yi Jinb592e3b2018-02-01 15:17:04 -0800818 proto.write(TextLogEntry::LOG, entry.message,
819 trimTail(entry.message, entry.messageLen));
Yi Jin3c034c92017-12-22 17:36:47 -0800820 proto.end(token);
821 }
822 }
823 gLastLogsRetrieved[mLogID] = lastTimestamp;
824 proto.flush(pipeWriteFd);
825 return err;
826}
Kweku Adamseadd1232018-02-05 16:45:13 -0800827
828// ================================================================================
829
830TombstoneSection::TombstoneSection(int id, const char* type, const int64_t timeoutMs)
831 : WorkerThreadSection(id, timeoutMs), mType(type) {
832 name += "tombstone ";
833 name += type;
834}
835
836TombstoneSection::~TombstoneSection() {}
837
838status_t TombstoneSection::BlockingCall(int pipeWriteFd) const {
839 std::unique_ptr<DIR, decltype(&closedir)> proc(opendir("/proc"), closedir);
840 if (proc.get() == nullptr) {
841 ALOGE("opendir /proc failed: %s\n", strerror(errno));
842 return -errno;
843 }
844
845 const std::set<int> hal_pids = get_interesting_hal_pids();
846
847 ProtoOutputStream proto;
848 struct dirent* d;
849 status_t err = NO_ERROR;
850 while ((d = readdir(proc.get()))) {
851 int pid = atoi(d->d_name);
852 if (pid <= 0) {
853 continue;
854 }
855
856 const std::string link_name = android::base::StringPrintf("/proc/%d/exe", pid);
857 std::string exe;
858 if (!android::base::Readlink(link_name, &exe)) {
859 ALOGE("Can't read '%s': %s\n", link_name.c_str(), strerror(errno));
860 continue;
861 }
862
863 bool is_java_process;
864 if (exe == "/system/bin/app_process32" || exe == "/system/bin/app_process64") {
865 if (mType != "java") continue;
866 // Don't bother dumping backtraces for the zygote.
867 if (IsZygote(pid)) {
868 VLOG("Skipping Zygote");
869 continue;
870 }
871
872 is_java_process = true;
873 } else if (should_dump_native_traces(exe.c_str())) {
874 if (mType != "native") continue;
875 is_java_process = false;
876 } else if (hal_pids.find(pid) != hal_pids.end()) {
877 if (mType != "hal") continue;
878 is_java_process = false;
879 } else {
880 // Probably a native process we don't care about, continue.
881 VLOG("Skipping %d", pid);
882 continue;
883 }
884
885 Fpipe dumpPipe;
886 if (!dumpPipe.init()) {
887 ALOGW("TombstoneSection '%s' failed to setup dump pipe", this->name.string());
888 err = -errno;
889 break;
890 }
891
892 const uint64_t start = Nanotime();
893 pid_t child = fork();
894 if (child < 0) {
895 ALOGE("Failed to fork child process");
896 break;
897 } else if (child == 0) {
898 // This is the child process.
899 close(dumpPipe.readFd());
900 const int ret = dump_backtrace_to_file_timeout(
901 pid, is_java_process ? kDebuggerdJavaBacktrace : kDebuggerdNativeBacktrace,
902 is_java_process ? 5 : 20, dumpPipe.writeFd());
903 if (ret == -1) {
904 if (errno == 0) {
905 ALOGW("Dumping failed for pid '%d', likely due to a timeout\n", pid);
906 } else {
907 ALOGE("Dumping failed for pid '%d': %s\n", pid, strerror(errno));
908 }
909 }
910 if (close(dumpPipe.writeFd()) != 0) {
911 ALOGW("TombstoneSection '%s' failed to close dump pipe writeFd: %d",
912 this->name.string(), errno);
913 _exit(EXIT_FAILURE);
914 }
915
916 _exit(EXIT_SUCCESS);
917 }
918 close(dumpPipe.writeFd());
919 // Parent process.
920 // Read from the pipe concurrently to avoid blocking the child.
921 FdBuffer buffer;
922 err = buffer.readFully(dumpPipe.readFd());
923 if (err != NO_ERROR) {
924 ALOGW("TombstoneSection '%s' failed to read stack dump: %d", this->name.string(), err);
925 if (close(dumpPipe.readFd()) != 0) {
926 ALOGW("TombstoneSection '%s' failed to close dump pipe readFd: %s",
927 this->name.string(), strerror(errno));
928 }
929 break;
930 }
931
932 auto dump = std::make_unique<char[]>(buffer.size());
933 auto iterator = buffer.data();
934 int i = 0;
935 while (iterator.hasNext()) {
936 dump[i] = iterator.next();
937 i++;
938 }
939 long long token = proto.start(android::os::BackTraceProto::TRACES);
940 proto.write(android::os::BackTraceProto::Stack::PID, pid);
941 proto.write(android::os::BackTraceProto::Stack::DUMP, dump.get(), i);
942 proto.write(android::os::BackTraceProto::Stack::DUMP_DURATION_NS,
943 static_cast<long long>(Nanotime() - start));
944 proto.end(token);
945
946 if (close(dumpPipe.readFd()) != 0) {
947 ALOGW("TombstoneSection '%s' failed to close dump pipe readFd: %d", this->name.string(),
948 errno);
949 err = -errno;
950 break;
951 }
952 }
953
954 proto.flush(pipeWriteFd);
955 return err;
956}