blob: bb5221c7404cec6746c78ab02f133e37d5bbc8e5 [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
Yi Jin3c034c92017-12-22 17:36:47 -080024#include <mutex>
Kweku Adamseadd1232018-02-05 16:45:13 -080025#include <set>
Joe Onorato1754d742016-11-21 17:51:35 -080026
Yi Jinb592e3b2018-02-01 15:17:04 -080027#include <android-base/file.h>
Kweku Adamseadd1232018-02-05 16:45:13 -080028#include <android-base/stringprintf.h>
Yi Jinc23fad22017-09-15 17:24:59 -070029#include <android/util/protobuf.h>
Joe Onorato1754d742016-11-21 17:51:35 -080030#include <binder/IServiceManager.h>
Kweku Adamseadd1232018-02-05 16:45:13 -080031#include <debuggerd/client.h>
32#include <dumputils/dump_utils.h>
Yi Jin3c034c92017-12-22 17:36:47 -080033#include <log/log_event_list.h>
Yi Jin3c034c92017-12-22 17:36:47 -080034#include <log/log_read.h>
Yi Jinb592e3b2018-02-01 15:17:04 -080035#include <log/logprint.h>
Yi Jin3c034c92017-12-22 17:36:47 -080036#include <private/android_logger.h>
37
38#include "FdBuffer.h"
Yi Jin3c034c92017-12-22 17:36:47 -080039#include "Privacy.h"
40#include "PrivacyBuffer.h"
Kweku Adamseadd1232018-02-05 16:45:13 -080041#include "frameworks/base/core/proto/android/os/backtrace.proto.h"
Yi Jin1a11fa12018-02-22 16:44:10 -080042#include "frameworks/base/core/proto/android/os/data.proto.h"
Yi Jinb592e3b2018-02-01 15:17:04 -080043#include "frameworks/base/core/proto/android/util/log.proto.h"
44#include "incidentd_util.h"
Joe Onorato1754d742016-11-21 17:51:35 -080045
Yi Jin6cacbcb2018-03-30 14:04:52 -070046namespace android {
47namespace os {
48namespace incidentd {
49
Yi Jinb592e3b2018-02-01 15:17:04 -080050using namespace android::base;
Yi Jinc23fad22017-09-15 17:24:59 -070051using namespace android::util;
Joe Onorato1754d742016-11-21 17:51:35 -080052
Yi Jinc23fad22017-09-15 17:24:59 -070053// special section ids
54const int FIELD_ID_INCIDENT_HEADER = 1;
Yi Jin329130b2018-02-09 16:47:47 -080055const int FIELD_ID_INCIDENT_METADATA = 2;
Yi Jinc23fad22017-09-15 17:24:59 -070056
57// incident section parameters
Yi Jin3c034c92017-12-22 17:36:47 -080058const char INCIDENT_HELPER[] = "/system/bin/incident_helper";
Yi Jinc36e91d2018-03-08 11:25:58 -080059const char* GZIP[] = {"/system/bin/gzip", NULL};
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 Jinc36e91d2018-03-08 11:25:58 -080063 return fork_execute_cmd(const_cast<char**>(ihArgs), p2cPipe, c2pPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -070064}
65
Yi Jin99c248f2017-08-25 18:11:58 -070066// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -080067static status_t write_section_header(int fd, int sectionId, size_t size) {
Yi Jin99c248f2017-08-25 18:11:58 -070068 uint8_t buf[20];
Yi Jinb592e3b2018-02-01 15:17:04 -080069 uint8_t* p = write_length_delimited_tag_header(buf, sectionId, size);
70 return WriteFully(fd, buf, p - buf) ? NO_ERROR : -errno;
Yi Jin99c248f2017-08-25 18:11:58 -070071}
72
Yi Jin98ce8102018-04-12 11:15:39 -070073static void write_section_stats(IncidentMetadata::SectionStats* stats, const FdBuffer& buffer) {
74 stats->set_dump_size_bytes(buffer.data().size());
75 stats->set_dump_duration_ms(buffer.durationMs());
76 stats->set_timed_out(buffer.timedOut());
77 stats->set_is_truncated(buffer.truncated());
78}
79
Kweku Adamseadd1232018-02-05 16:45:13 -080080// Reads data from FdBuffer and writes it to the requests file descriptor.
Yi Jinb592e3b2018-02-01 15:17:04 -080081static status_t write_report_requests(const int id, const FdBuffer& buffer,
82 ReportRequestSet* requests) {
Yi Jin0f047162017-09-05 13:44:22 -070083 status_t err = -EBADF;
Yi Jinc23fad22017-09-15 17:24:59 -070084 EncodedBuffer::iterator data = buffer.data();
85 PrivacyBuffer privacyBuffer(get_privacy_of_section(id), data);
Yi Jin99c248f2017-08-25 18:11:58 -070086 int writeable = 0;
87
Yi Jin0f047162017-09-05 13:44:22 -070088 // The streaming ones, group requests by spec in order to save unnecessary strip operations
89 map<PrivacySpec, vector<sp<ReportRequest>>> requestsBySpec;
Yi Jin3ec5cc72018-01-26 13:42:43 -080090 for (auto it = requests->begin(); it != requests->end(); it++) {
Yi Jin99c248f2017-08-25 18:11:58 -070091 sp<ReportRequest> request = *it;
Yi Jinedfd5bb2017-09-06 17:09:11 -070092 if (!request->ok() || !request->args.containsSection(id)) {
Yi Jin0f047162017-09-05 13:44:22 -070093 continue; // skip invalid request
Yi Jin99c248f2017-08-25 18:11:58 -070094 }
Yi Jin3ec5cc72018-01-26 13:42:43 -080095 PrivacySpec spec = PrivacySpec::new_spec(request->args.dest());
Yi Jin0f047162017-09-05 13:44:22 -070096 requestsBySpec[spec].push_back(request);
97 }
98
Yi Jin3ec5cc72018-01-26 13:42:43 -080099 for (auto mit = requestsBySpec.begin(); mit != requestsBySpec.end(); mit++) {
Yi Jin0f047162017-09-05 13:44:22 -0700100 PrivacySpec spec = mit->first;
Yi Jinc23fad22017-09-15 17:24:59 -0700101 err = privacyBuffer.strip(spec);
Yi Jinb592e3b2018-02-01 15:17:04 -0800102 if (err != NO_ERROR) return err; // it means the privacyBuffer data is corrupted.
Yi Jinc23fad22017-09-15 17:24:59 -0700103 if (privacyBuffer.size() == 0) continue;
Yi Jin0f047162017-09-05 13:44:22 -0700104
Yi Jin3ec5cc72018-01-26 13:42:43 -0800105 for (auto it = mit->second.begin(); it != mit->second.end(); it++) {
Yi Jin0f047162017-09-05 13:44:22 -0700106 sp<ReportRequest> request = *it;
Yi Jinc23fad22017-09-15 17:24:59 -0700107 err = write_section_header(request->fd, id, privacyBuffer.size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800108 if (err != NO_ERROR) {
109 request->err = err;
110 continue;
111 }
Yi Jinc23fad22017-09-15 17:24:59 -0700112 err = privacyBuffer.flush(request->fd);
Yi Jinb592e3b2018-02-01 15:17:04 -0800113 if (err != NO_ERROR) {
114 request->err = err;
115 continue;
116 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700117 writeable++;
Yi Jinb592e3b2018-02-01 15:17:04 -0800118 VLOG("Section %d flushed %zu bytes to fd %d with spec %d", id, privacyBuffer.size(),
119 request->fd, spec.dest);
Yi Jin0f047162017-09-05 13:44:22 -0700120 }
Yi Jinc23fad22017-09-15 17:24:59 -0700121 privacyBuffer.clear();
Yi Jin99c248f2017-08-25 18:11:58 -0700122 }
123
124 // The dropbox file
125 if (requests->mainFd() >= 0) {
Yi Jin329130b2018-02-09 16:47:47 -0800126 PrivacySpec spec = PrivacySpec::new_spec(requests->mainDest());
Yi Jin3ec5cc72018-01-26 13:42:43 -0800127 err = privacyBuffer.strip(spec);
Yi Jinb592e3b2018-02-01 15:17:04 -0800128 if (err != NO_ERROR) return err; // the buffer data is corrupted.
Yi Jinc23fad22017-09-15 17:24:59 -0700129 if (privacyBuffer.size() == 0) goto DONE;
Yi Jin0f047162017-09-05 13:44:22 -0700130
Yi Jinc23fad22017-09-15 17:24:59 -0700131 err = write_section_header(requests->mainFd(), id, privacyBuffer.size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800132 if (err != NO_ERROR) {
133 requests->setMainFd(-1);
134 goto DONE;
135 }
Yi Jinc23fad22017-09-15 17:24:59 -0700136 err = privacyBuffer.flush(requests->mainFd());
Yi Jinb592e3b2018-02-01 15:17:04 -0800137 if (err != NO_ERROR) {
138 requests->setMainFd(-1);
139 goto DONE;
140 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700141 writeable++;
Yi Jinb592e3b2018-02-01 15:17:04 -0800142 VLOG("Section %d flushed %zu bytes to dropbox %d with spec %d", id, privacyBuffer.size(),
143 requests->mainFd(), spec.dest);
Yi Jin98ce8102018-04-12 11:15:39 -0700144 // Reports bytes of the section uploaded via dropbox after filtering.
145 requests->sectionStats(id)->set_report_size_bytes(privacyBuffer.size());
Yi Jin99c248f2017-08-25 18:11:58 -0700146 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700147
148DONE:
Yi Jin99c248f2017-08-25 18:11:58 -0700149 // only returns error if there is no fd to write to.
150 return writeable > 0 ? NO_ERROR : err;
151}
152
153// ================================================================================
Kweku Adams71a95312018-04-16 16:54:24 -0700154Section::Section(int i, int64_t timeoutMs, bool userdebugAndEngOnly, bool deviceSpecific)
155 : id(i),
156 timeoutMs(timeoutMs),
157 userdebugAndEngOnly(userdebugAndEngOnly),
158 deviceSpecific(deviceSpecific) {}
Joe Onorato1754d742016-11-21 17:51:35 -0800159
Yi Jinb592e3b2018-02-01 15:17:04 -0800160Section::~Section() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800161
Joe Onorato1754d742016-11-21 17:51:35 -0800162// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800163HeaderSection::HeaderSection() : Section(FIELD_ID_INCIDENT_HEADER, 0) {}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700164
Yi Jinb592e3b2018-02-01 15:17:04 -0800165HeaderSection::~HeaderSection() {}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700166
Yi Jinb592e3b2018-02-01 15:17:04 -0800167status_t HeaderSection::Execute(ReportRequestSet* requests) const {
168 for (ReportRequestSet::iterator it = requests->begin(); it != requests->end(); it++) {
Yi Jinedfd5bb2017-09-06 17:09:11 -0700169 const sp<ReportRequest> request = *it;
Yi Jinbdf58942017-11-14 17:58:19 -0800170 const vector<vector<uint8_t>>& headers = request->args.headers();
Yi Jinedfd5bb2017-09-06 17:09:11 -0700171
Yi Jinb592e3b2018-02-01 15:17:04 -0800172 for (vector<vector<uint8_t>>::const_iterator buf = headers.begin(); buf != headers.end();
173 buf++) {
Yi Jinedfd5bb2017-09-06 17:09:11 -0700174 if (buf->empty()) continue;
175
176 // So the idea is only requests with negative fd are written to dropbox file.
177 int fd = request->fd >= 0 ? request->fd : requests->mainFd();
Yi Jin329130b2018-02-09 16:47:47 -0800178 write_section_header(fd, id, buf->size());
Yi Jinb592e3b2018-02-01 15:17:04 -0800179 WriteFully(fd, (uint8_t const*)buf->data(), buf->size());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700180 // If there was an error now, there will be an error later and we will remove
181 // it from the list then.
182 }
183 }
184 return NO_ERROR;
185}
Yi Jin329130b2018-02-09 16:47:47 -0800186// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800187MetadataSection::MetadataSection() : Section(FIELD_ID_INCIDENT_METADATA, 0) {}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700188
Yi Jinb592e3b2018-02-01 15:17:04 -0800189MetadataSection::~MetadataSection() {}
Yi Jin329130b2018-02-09 16:47:47 -0800190
Yi Jinb592e3b2018-02-01 15:17:04 -0800191status_t MetadataSection::Execute(ReportRequestSet* requests) const {
Yi Jin86dce412018-03-07 11:36:57 -0800192 ProtoOutputStream proto;
193 IncidentMetadata metadata = requests->metadata();
194 proto.write(FIELD_TYPE_ENUM | IncidentMetadata::kDestFieldNumber, metadata.dest());
195 proto.write(FIELD_TYPE_INT32 | IncidentMetadata::kRequestSizeFieldNumber,
196 metadata.request_size());
197 proto.write(FIELD_TYPE_BOOL | IncidentMetadata::kUseDropboxFieldNumber, metadata.use_dropbox());
198 for (auto iter = requests->allSectionStats().begin(); iter != requests->allSectionStats().end();
199 iter++) {
200 IncidentMetadata::SectionStats stats = iter->second;
201 uint64_t token = proto.start(FIELD_TYPE_MESSAGE | IncidentMetadata::kSectionsFieldNumber);
202 proto.write(FIELD_TYPE_INT32 | IncidentMetadata::SectionStats::kIdFieldNumber, stats.id());
203 proto.write(FIELD_TYPE_BOOL | IncidentMetadata::SectionStats::kSuccessFieldNumber,
204 stats.success());
205 proto.write(FIELD_TYPE_INT32 | IncidentMetadata::SectionStats::kReportSizeBytesFieldNumber,
206 stats.report_size_bytes());
207 proto.write(FIELD_TYPE_INT64 | IncidentMetadata::SectionStats::kExecDurationMsFieldNumber,
208 stats.exec_duration_ms());
209 proto.write(FIELD_TYPE_INT32 | IncidentMetadata::SectionStats::kDumpSizeBytesFieldNumber,
210 stats.dump_size_bytes());
211 proto.write(FIELD_TYPE_INT64 | IncidentMetadata::SectionStats::kDumpDurationMsFieldNumber,
212 stats.dump_duration_ms());
213 proto.write(FIELD_TYPE_BOOL | IncidentMetadata::SectionStats::kTimedOutFieldNumber,
214 stats.timed_out());
215 proto.write(FIELD_TYPE_BOOL | IncidentMetadata::SectionStats::kIsTruncatedFieldNumber,
216 stats.is_truncated());
217 proto.end(token);
218 }
219
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;
Yi Jin86dce412018-03-07 11:36:57 -0800222 if (request->fd < 0 || request->err != NO_ERROR) {
Yi Jin329130b2018-02-09 16:47:47 -0800223 continue;
224 }
Yi Jin86dce412018-03-07 11:36:57 -0800225 write_section_header(request->fd, id, proto.size());
226 if (!proto.flush(request->fd)) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800227 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 }
Yi Jin86dce412018-03-07 11:36:57 -0800231 if (requests->mainFd() >= 0) {
232 write_section_header(requests->mainFd(), id, proto.size());
233 if (!proto.flush(requests->mainFd())) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800234 ALOGW("Failed to write metadata to dropbox fd %d", requests->mainFd());
235 return -1;
236 }
Yi Jin329130b2018-02-09 16:47:47 -0800237 }
238 return NO_ERROR;
239}
Yi Jinedfd5bb2017-09-06 17:09:11 -0700240// ================================================================================
Yi Jin1a11fa12018-02-22 16:44:10 -0800241static inline bool isSysfs(const char* filename) { return strncmp(filename, "/sys/", 5) == 0; }
242
Yi Jin7fe3dee2018-04-16 16:13:04 -0700243FileSection::FileSection(int id, const char* filename, const bool deviceSpecific,
244 const int64_t timeoutMs)
Kweku Adams71a95312018-04-16 16:54:24 -0700245 : Section(id, timeoutMs, false, deviceSpecific), 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
Yi Jin6355d2f2018-03-14 15:18:02 -0700255 unique_fd fd(open(mFilename, O_RDONLY | O_CLOEXEC));
256 if (fd.get() == -1) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800257 ALOGW("FileSection '%s' failed to open file", this->name.string());
Yi Jin7fe3dee2018-04-16 16:13:04 -0700258 return this->deviceSpecific ? NO_ERROR : -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
Yi Jine3dab2d2018-03-22 16:56:39 -0700277 status_t readStatus = buffer.readProcessedDataInStream(fd.get(), std::move(p2cPipe.writeFd()),
278 std::move(c2pPipe.readFd()),
279 this->timeoutMs, mIsSysfs);
Yi Jin98ce8102018-04-12 11:15:39 -0700280 write_section_stats(requests->sectionStats(this->id), buffer);
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) {
Yi Jin1a11fa12018-02-22 16:44:10 -0800307 va_list args;
308 va_start(args, filename);
309 mFilenames = varargs(filename, args);
310 va_end(args);
Yi Jinc36e91d2018-03-08 11:25:58 -0800311 name = "gzip";
312 for (int i = 0; mFilenames[i] != NULL; i++) {
313 name += " ";
314 name += mFilenames[i];
315 }
Yi Jin1a11fa12018-02-22 16:44:10 -0800316}
Yi Jin0a3406f2017-06-22 19:23:11 -0700317
Yi Jin480de782018-04-06 15:37:36 -0700318GZipSection::~GZipSection() { free(mFilenames); }
Yi Jin1a11fa12018-02-22 16:44:10 -0800319
320status_t GZipSection::Execute(ReportRequestSet* requests) const {
321 // Reads the files in order, use the first available one.
322 int index = 0;
Yi Jin6355d2f2018-03-14 15:18:02 -0700323 unique_fd fd;
Yi Jin1a11fa12018-02-22 16:44:10 -0800324 while (mFilenames[index] != NULL) {
Yi Jin6355d2f2018-03-14 15:18:02 -0700325 fd.reset(open(mFilenames[index], O_RDONLY | O_CLOEXEC));
326 if (fd.get() != -1) {
Yi Jin1a11fa12018-02-22 16:44:10 -0800327 break;
328 }
329 ALOGW("GZipSection failed to open file %s", mFilenames[index]);
330 index++; // look at the next file.
331 }
Yi Jin6355d2f2018-03-14 15:18:02 -0700332 VLOG("GZipSection is using file %s, fd=%d", mFilenames[index], fd.get());
Yi Jinc858e272018-03-28 15:32:50 -0700333 if (fd.get() == -1) {
Yi Jin6cacbcb2018-03-30 14:04:52 -0700334 ALOGW("GZipSection %s can't open all the files", this->name.string());
335 return NO_ERROR; // e.g. LAST_KMSG will reach here in user build.
Yi Jinc858e272018-03-28 15:32:50 -0700336 }
Yi Jin1a11fa12018-02-22 16:44:10 -0800337 FdBuffer buffer;
338 Fpipe p2cPipe;
339 Fpipe c2pPipe;
340 // initiate pipes to pass data to/from gzip
341 if (!p2cPipe.init() || !c2pPipe.init()) {
342 ALOGW("GZipSection '%s' failed to setup pipes", this->name.string());
343 return -errno;
344 }
345
Yi Jinc36e91d2018-03-08 11:25:58 -0800346 pid_t pid = fork_execute_cmd((char* const*)GZIP, &p2cPipe, &c2pPipe);
Yi Jin1a11fa12018-02-22 16:44:10 -0800347 if (pid == -1) {
348 ALOGW("GZipSection '%s' failed to fork", this->name.string());
349 return -errno;
350 }
351 // parent process
352
353 // construct Fdbuffer to output GZippedfileProto, the reason to do this instead of using
354 // ProtoOutputStream is to avoid allocation of another buffer inside ProtoOutputStream.
355 EncodedBuffer* internalBuffer = buffer.getInternalBuffer();
356 internalBuffer->writeHeader((uint32_t)GZippedFileProto::FILENAME, WIRE_TYPE_LENGTH_DELIMITED);
Yi Jina9635e42018-03-23 12:05:32 -0700357 size_t fileLen = strlen(mFilenames[index]);
358 internalBuffer->writeRawVarint32(fileLen);
359 for (size_t i = 0; i < fileLen; i++) {
Yi Jin1a11fa12018-02-22 16:44:10 -0800360 internalBuffer->writeRawByte(mFilenames[index][i]);
361 }
362 internalBuffer->writeHeader((uint32_t)GZippedFileProto::GZIPPED_DATA,
363 WIRE_TYPE_LENGTH_DELIMITED);
364 size_t editPos = internalBuffer->wp()->pos();
365 internalBuffer->wp()->move(8); // reserve 8 bytes for the varint of the data size.
366 size_t dataBeginAt = internalBuffer->wp()->pos();
367 VLOG("GZipSection '%s' editPos=%zd, dataBeginAt=%zd", this->name.string(), editPos,
368 dataBeginAt);
369
Yi Jine3dab2d2018-03-22 16:56:39 -0700370 status_t readStatus = buffer.readProcessedDataInStream(
371 fd.get(), std::move(p2cPipe.writeFd()), std::move(c2pPipe.readFd()), this->timeoutMs,
372 isSysfs(mFilenames[index]));
Yi Jin98ce8102018-04-12 11:15:39 -0700373 write_section_stats(requests->sectionStats(this->id), buffer);
Yi Jin1a11fa12018-02-22 16:44:10 -0800374 if (readStatus != NO_ERROR || buffer.timedOut()) {
375 ALOGW("GZipSection '%s' failed to read data from gzip: %s, timedout: %s",
376 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
377 kill_child(pid);
378 return readStatus;
379 }
380
381 status_t gzipStatus = wait_child(pid);
382 if (gzipStatus != NO_ERROR) {
383 ALOGW("GZipSection '%s' abnormal child process: %s", this->name.string(),
384 strerror(-gzipStatus));
385 return gzipStatus;
386 }
387 // Revisit the actual size from gzip result and edit the internal buffer accordingly.
388 size_t dataSize = buffer.size() - dataBeginAt;
389 internalBuffer->wp()->rewind()->move(editPos);
390 internalBuffer->writeRawVarint32(dataSize);
391 internalBuffer->copy(dataBeginAt, dataSize);
392 VLOG("GZipSection '%s' wrote %zd bytes in %d ms, dataSize=%zd", this->name.string(),
393 buffer.size(), (int)buffer.durationMs(), dataSize);
394 status_t err = write_report_requests(this->id, buffer, requests);
395 if (err != NO_ERROR) {
396 ALOGW("GZipSection '%s' failed writing: %s", this->name.string(), strerror(-err));
397 return err;
398 }
399
400 return NO_ERROR;
401}
Kweku Adamseadd1232018-02-05 16:45:13 -0800402
Yi Jin0a3406f2017-06-22 19:23:11 -0700403// ================================================================================
Yi Jinb592e3b2018-02-01 15:17:04 -0800404struct WorkerThreadData : public virtual RefBase {
Joe Onorato1754d742016-11-21 17:51:35 -0800405 const WorkerThreadSection* section;
Yi Jin6355d2f2018-03-14 15:18:02 -0700406 Fpipe pipe;
Joe Onorato1754d742016-11-21 17:51:35 -0800407
408 // Lock protects these fields
409 mutex lock;
410 bool workerDone;
411 status_t workerError;
412
Chih-Hung Hsieh7a88a932018-12-20 13:45:04 -0800413 explicit WorkerThreadData(const WorkerThreadSection* section);
Joe Onorato1754d742016-11-21 17:51:35 -0800414 virtual ~WorkerThreadData();
Joe Onorato1754d742016-11-21 17:51:35 -0800415};
416
417WorkerThreadData::WorkerThreadData(const WorkerThreadSection* sec)
Yi Jin6355d2f2018-03-14 15:18:02 -0700418 : section(sec), workerDone(false), workerError(NO_ERROR) {}
Joe Onorato1754d742016-11-21 17:51:35 -0800419
Yi Jinb592e3b2018-02-01 15:17:04 -0800420WorkerThreadData::~WorkerThreadData() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800421
422// ================================================================================
Kweku Adams71a95312018-04-16 16:54:24 -0700423WorkerThreadSection::WorkerThreadSection(int id, const int64_t timeoutMs, bool userdebugAndEngOnly)
424 : Section(id, timeoutMs, userdebugAndEngOnly) {}
Joe Onorato1754d742016-11-21 17:51:35 -0800425
Yi Jinb592e3b2018-02-01 15:17:04 -0800426WorkerThreadSection::~WorkerThreadSection() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800427
Kweku Adams4d4a2332018-09-13 15:44:58 -0700428void sigpipe_handler(int signum) {
429 if (signum == SIGPIPE) {
430 ALOGE("Wrote to a broken pipe\n");
431 } else {
432 ALOGE("Received unexpected signal: %d\n", signum);
433 }
434}
435
Yi Jinb592e3b2018-02-01 15:17:04 -0800436static void* worker_thread_func(void* cookie) {
Kweku Adams4d4a2332018-09-13 15:44:58 -0700437 // Don't crash the service if we write to a closed pipe (which can happen if
438 // dumping times out).
439 signal(SIGPIPE, sigpipe_handler);
440
Joe Onorato1754d742016-11-21 17:51:35 -0800441 WorkerThreadData* data = (WorkerThreadData*)cookie;
Yi Jin6355d2f2018-03-14 15:18:02 -0700442 status_t err = data->section->BlockingCall(data->pipe.writeFd().get());
Joe Onorato1754d742016-11-21 17:51:35 -0800443
444 {
445 unique_lock<mutex> lock(data->lock);
446 data->workerDone = true;
447 data->workerError = err;
448 }
449
Yi Jin6355d2f2018-03-14 15:18:02 -0700450 data->pipe.writeFd().reset();
Joe Onorato1754d742016-11-21 17:51:35 -0800451 data->decStrong(data->section);
452 // data might be gone now. don't use it after this point in this thread.
453 return NULL;
454}
455
Yi Jinb592e3b2018-02-01 15:17:04 -0800456status_t WorkerThreadSection::Execute(ReportRequestSet* requests) const {
Joe Onorato1754d742016-11-21 17:51:35 -0800457 status_t err = NO_ERROR;
458 pthread_t thread;
459 pthread_attr_t attr;
460 bool timedOut = false;
461 FdBuffer buffer;
462
463 // Data shared between this thread and the worker thread.
464 sp<WorkerThreadData> data = new WorkerThreadData(this);
465
466 // Create the pipe
Yi Jin6355d2f2018-03-14 15:18:02 -0700467 if (!data->pipe.init()) {
Joe Onorato1754d742016-11-21 17:51:35 -0800468 return -errno;
469 }
470
471 // The worker thread needs a reference and we can't let the count go to zero
472 // if that thread is slow to start.
473 data->incStrong(this);
474
475 // Create the thread
476 err = pthread_attr_init(&attr);
477 if (err != 0) {
478 return -err;
479 }
480 // TODO: Do we need to tweak thread priority?
481 err = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
482 if (err != 0) {
483 pthread_attr_destroy(&attr);
484 return -err;
485 }
486 err = pthread_create(&thread, &attr, worker_thread_func, (void*)data.get());
487 if (err != 0) {
488 pthread_attr_destroy(&attr);
489 return -err;
490 }
491 pthread_attr_destroy(&attr);
492
493 // Loop reading until either the timeout or the worker side is done (i.e. eof).
Yi Jine3dab2d2018-03-22 16:56:39 -0700494 err = buffer.read(data->pipe.readFd().get(), this->timeoutMs);
Joe Onorato1754d742016-11-21 17:51:35 -0800495 if (err != NO_ERROR) {
496 // TODO: Log this error into the incident report.
497 ALOGW("WorkerThreadSection '%s' reader failed with error '%s'", this->name.string(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800498 strerror(-err));
Joe Onorato1754d742016-11-21 17:51:35 -0800499 }
500
501 // Done with the read fd. The worker thread closes the write one so
502 // we never race and get here first.
Yi Jin6355d2f2018-03-14 15:18:02 -0700503 data->pipe.readFd().reset();
Joe Onorato1754d742016-11-21 17:51:35 -0800504
505 // If the worker side is finished, then return its error (which may overwrite
506 // our possible error -- but it's more interesting anyway). If not, then we timed out.
507 {
508 unique_lock<mutex> lock(data->lock);
509 if (!data->workerDone) {
510 // We timed out
511 timedOut = true;
512 } else {
513 if (data->workerError != NO_ERROR) {
514 err = data->workerError;
515 // TODO: Log this error into the incident report.
516 ALOGW("WorkerThreadSection '%s' worker failed with error '%s'", this->name.string(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800517 strerror(-err));
Joe Onorato1754d742016-11-21 17:51:35 -0800518 }
519 }
520 }
Kweku Adams4d4a2332018-09-13 15:44:58 -0700521
Yi Jin98ce8102018-04-12 11:15:39 -0700522 write_section_stats(requests->sectionStats(this->id), buffer);
Joe Onorato1754d742016-11-21 17:51:35 -0800523 if (timedOut || buffer.timedOut()) {
524 ALOGW("WorkerThreadSection '%s' timed out", this->name.string());
525 return NO_ERROR;
526 }
527
528 if (buffer.truncated()) {
529 // TODO: Log this into the incident report.
530 }
531
532 // TODO: There was an error with the command or buffering. Report that. For now
533 // just exit with a log messasge.
534 if (err != NO_ERROR) {
535 ALOGW("WorkerThreadSection '%s' failed with error '%s'", this->name.string(),
Yi Jinb592e3b2018-02-01 15:17:04 -0800536 strerror(-err));
Joe Onorato1754d742016-11-21 17:51:35 -0800537 return NO_ERROR;
538 }
539
540 // Write the data that was collected
Yi Jinb592e3b2018-02-01 15:17:04 -0800541 VLOG("WorkerThreadSection '%s' wrote %zd bytes in %d ms", name.string(), buffer.size(),
542 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700543 err = write_report_requests(this->id, buffer, requests);
Joe Onorato1754d742016-11-21 17:51:35 -0800544 if (err != NO_ERROR) {
545 ALOGW("WorkerThreadSection '%s' failed writing: '%s'", this->name.string(), strerror(-err));
546 return err;
547 }
548
549 return NO_ERROR;
550}
551
552// ================================================================================
Yi Jinb44f7d42017-07-21 12:12:59 -0700553CommandSection::CommandSection(int id, const int64_t timeoutMs, const char* command, ...)
Yi Jinb592e3b2018-02-01 15:17:04 -0800554 : Section(id, timeoutMs) {
Joe Onorato1754d742016-11-21 17:51:35 -0800555 va_list args;
Yi Jinb44f7d42017-07-21 12:12:59 -0700556 va_start(args, command);
Yi Jin1a11fa12018-02-22 16:44:10 -0800557 mCommand = varargs(command, args);
Joe Onorato1754d742016-11-21 17:51:35 -0800558 va_end(args);
Yi Jinc36e91d2018-03-08 11:25:58 -0800559 name = "cmd";
560 for (int i = 0; mCommand[i] != NULL; i++) {
561 name += " ";
562 name += mCommand[i];
563 }
Yi Jinb44f7d42017-07-21 12:12:59 -0700564}
Joe Onorato1754d742016-11-21 17:51:35 -0800565
Yi Jinb592e3b2018-02-01 15:17:04 -0800566CommandSection::CommandSection(int id, const char* command, ...) : Section(id) {
Yi Jinb44f7d42017-07-21 12:12:59 -0700567 va_list args;
568 va_start(args, command);
Yi Jin1a11fa12018-02-22 16:44:10 -0800569 mCommand = varargs(command, args);
Joe Onorato1754d742016-11-21 17:51:35 -0800570 va_end(args);
Yi Jinc36e91d2018-03-08 11:25:58 -0800571 name = "cmd";
572 for (int i = 0; mCommand[i] != NULL; i++) {
573 name += " ";
574 name += mCommand[i];
575 }
Joe Onorato1754d742016-11-21 17:51:35 -0800576}
577
Yi Jinb592e3b2018-02-01 15:17:04 -0800578CommandSection::~CommandSection() { free(mCommand); }
Joe Onorato1754d742016-11-21 17:51:35 -0800579
Yi Jinb592e3b2018-02-01 15:17:04 -0800580status_t CommandSection::Execute(ReportRequestSet* requests) const {
Yi Jinb44f7d42017-07-21 12:12:59 -0700581 FdBuffer buffer;
582 Fpipe cmdPipe;
583 Fpipe ihPipe;
584
585 if (!cmdPipe.init() || !ihPipe.init()) {
586 ALOGW("CommandSection '%s' failed to setup pipes", this->name.string());
587 return -errno;
588 }
589
Yi Jinc36e91d2018-03-08 11:25:58 -0800590 pid_t cmdPid = fork_execute_cmd((char* const*)mCommand, NULL, &cmdPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -0700591 if (cmdPid == -1) {
592 ALOGW("CommandSection '%s' failed to fork", this->name.string());
593 return -errno;
594 }
Yi Jin1a11fa12018-02-22 16:44:10 -0800595 pid_t ihPid = fork_execute_incident_helper(this->id, &cmdPipe, &ihPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -0700596 if (ihPid == -1) {
597 ALOGW("CommandSection '%s' failed to fork", this->name.string());
598 return -errno;
599 }
600
Yi Jin6355d2f2018-03-14 15:18:02 -0700601 cmdPipe.writeFd().reset();
Yi Jine3dab2d2018-03-22 16:56:39 -0700602 status_t readStatus = buffer.read(ihPipe.readFd().get(), this->timeoutMs);
Yi Jin98ce8102018-04-12 11:15:39 -0700603 write_section_stats(requests->sectionStats(this->id), buffer);
Yi Jinb44f7d42017-07-21 12:12:59 -0700604 if (readStatus != NO_ERROR || buffer.timedOut()) {
Yi Jin4bab3a12018-01-10 16:50:59 -0800605 ALOGW("CommandSection '%s' failed to read data from incident helper: %s, timedout: %s",
Yi Jinb592e3b2018-02-01 15:17:04 -0800606 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
Yi Jin4bab3a12018-01-10 16:50:59 -0800607 kill_child(cmdPid);
608 kill_child(ihPid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700609 return readStatus;
610 }
611
Kweku Adamseadd1232018-02-05 16:45:13 -0800612 // Waiting for command here has one trade-off: the failed status of command won't be detected
Yi Jin1a11fa12018-02-22 16:44:10 -0800613 // until buffer timeout, but it has advatage on starting the data stream earlier.
Yi Jinedfd5bb2017-09-06 17:09:11 -0700614 status_t cmdStatus = wait_child(cmdPid);
Yi Jinb592e3b2018-02-01 15:17:04 -0800615 status_t ihStatus = wait_child(ihPid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700616 if (cmdStatus != NO_ERROR || ihStatus != NO_ERROR) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800617 ALOGW("CommandSection '%s' abnormal child processes, return status: command: %s, incident "
618 "helper: %s",
619 this->name.string(), strerror(-cmdStatus), strerror(-ihStatus));
Yi Jinb44f7d42017-07-21 12:12:59 -0700620 return cmdStatus != NO_ERROR ? cmdStatus : ihStatus;
621 }
622
Yi Jinb592e3b2018-02-01 15:17:04 -0800623 VLOG("CommandSection '%s' wrote %zd bytes in %d ms", this->name.string(), buffer.size(),
624 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700625 status_t err = write_report_requests(this->id, buffer, requests);
Yi Jinb44f7d42017-07-21 12:12:59 -0700626 if (err != NO_ERROR) {
627 ALOGW("CommandSection '%s' failed writing: %s", this->name.string(), strerror(-err));
628 return err;
629 }
Joe Onorato1754d742016-11-21 17:51:35 -0800630 return NO_ERROR;
631}
632
633// ================================================================================
Kweku Adams71a95312018-04-16 16:54:24 -0700634DumpsysSection::DumpsysSection(int id, bool userdebugAndEngOnly, const char* service, ...)
635 : WorkerThreadSection(id, REMOTE_CALL_TIMEOUT_MS, userdebugAndEngOnly), mService(service) {
Joe Onorato1754d742016-11-21 17:51:35 -0800636 name = "dumpsys ";
637 name += service;
638
639 va_list args;
640 va_start(args, service);
641 while (true) {
Yi Jin0a3406f2017-06-22 19:23:11 -0700642 const char* arg = va_arg(args, const char*);
Joe Onorato1754d742016-11-21 17:51:35 -0800643 if (arg == NULL) {
644 break;
645 }
646 mArgs.add(String16(arg));
647 name += " ";
648 name += arg;
649 }
650 va_end(args);
651}
652
Yi Jinb592e3b2018-02-01 15:17:04 -0800653DumpsysSection::~DumpsysSection() {}
Joe Onorato1754d742016-11-21 17:51:35 -0800654
Yi Jinb592e3b2018-02-01 15:17:04 -0800655status_t DumpsysSection::BlockingCall(int pipeWriteFd) const {
Joe Onorato1754d742016-11-21 17:51:35 -0800656 // checkService won't wait for the service to show up like getService will.
657 sp<IBinder> service = defaultServiceManager()->checkService(mService);
Yi Jin0a3406f2017-06-22 19:23:11 -0700658
Joe Onorato1754d742016-11-21 17:51:35 -0800659 if (service == NULL) {
660 // Returning an error interrupts the entire incident report, so just
661 // log the failure.
662 // TODO: have a meta record inside the report that would log this
663 // failure inside the report, because the fact that we can't find
664 // the service is good data in and of itself. This is running in
665 // another thread so lock that carefully...
666 ALOGW("DumpsysSection: Can't lookup service: %s", String8(mService).string());
667 return NO_ERROR;
668 }
669
670 service->dump(pipeWriteFd, mArgs);
671
672 return NO_ERROR;
673}
Yi Jin3c034c92017-12-22 17:36:47 -0800674
675// ================================================================================
676// initialization only once in Section.cpp.
677map<log_id_t, log_time> LogSection::gLastLogsRetrieved;
678
Yi Jinb592e3b2018-02-01 15:17:04 -0800679LogSection::LogSection(int id, log_id_t logID) : WorkerThreadSection(id), mLogID(logID) {
Yi Jin3c034c92017-12-22 17:36:47 -0800680 name += "logcat ";
681 name += android_log_id_to_name(logID);
682 switch (logID) {
Yi Jinb592e3b2018-02-01 15:17:04 -0800683 case LOG_ID_EVENTS:
684 case LOG_ID_STATS:
685 case LOG_ID_SECURITY:
686 mBinary = true;
687 break;
688 default:
689 mBinary = false;
Yi Jin3c034c92017-12-22 17:36:47 -0800690 }
691}
692
Yi Jinb592e3b2018-02-01 15:17:04 -0800693LogSection::~LogSection() {}
Yi Jin3c034c92017-12-22 17:36:47 -0800694
Yi Jinb592e3b2018-02-01 15:17:04 -0800695static size_t trimTail(char const* buf, size_t len) {
Yi Jin3c034c92017-12-22 17:36:47 -0800696 while (len > 0) {
697 char c = buf[len - 1];
698 if (c == '\0' || c == ' ' || c == '\n' || c == '\r' || c == ':') {
699 len--;
700 } else {
701 break;
702 }
703 }
704 return len;
705}
706
707static inline int32_t get4LE(uint8_t const* src) {
708 return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
709}
710
Yi Jinb592e3b2018-02-01 15:17:04 -0800711status_t LogSection::BlockingCall(int pipeWriteFd) const {
Yi Jin3c034c92017-12-22 17:36:47 -0800712 // Open log buffer and getting logs since last retrieved time if any.
713 unique_ptr<logger_list, void (*)(logger_list*)> loggers(
Yi Jinb592e3b2018-02-01 15:17:04 -0800714 gLastLogsRetrieved.find(mLogID) == gLastLogsRetrieved.end()
715 ? android_logger_list_alloc(ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 0, 0)
716 : android_logger_list_alloc_time(ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
717 gLastLogsRetrieved[mLogID], 0),
718 android_logger_list_free);
Yi Jin3c034c92017-12-22 17:36:47 -0800719
720 if (android_logger_open(loggers.get(), mLogID) == NULL) {
Yi Jin83fb1d52018-03-16 12:03:53 -0700721 ALOGE("LogSection %s: Can't get logger.", this->name.string());
722 return -1;
Yi Jin3c034c92017-12-22 17:36:47 -0800723 }
724
725 log_msg msg;
726 log_time lastTimestamp(0);
727
728 ProtoOutputStream proto;
Yi Jinb592e3b2018-02-01 15:17:04 -0800729 while (true) { // keeps reading until logd buffer is fully read.
Yi Jin83fb1d52018-03-16 12:03:53 -0700730 status_t err = android_logger_list_read(loggers.get(), &msg);
Yi Jin3c034c92017-12-22 17:36:47 -0800731 // err = 0 - no content, unexpected connection drop or EOF.
732 // err = +ive number - size of retrieved data from logger
733 // err = -ive number, OS supplied error _except_ for -EAGAIN
734 // err = -EAGAIN, graceful indication for ANDRODI_LOG_NONBLOCK that this is the end of data.
735 if (err <= 0) {
736 if (err != -EAGAIN) {
Yi Jin83fb1d52018-03-16 12:03:53 -0700737 ALOGW("LogSection %s: fails to read a log_msg.\n", this->name.string());
Yi Jin3c034c92017-12-22 17:36:47 -0800738 }
Yi Jin83fb1d52018-03-16 12:03:53 -0700739 // dump previous logs and don't consider this error a failure.
Yi Jin3c034c92017-12-22 17:36:47 -0800740 break;
741 }
742 if (mBinary) {
743 // remove the first uint32 which is tag's index in event log tags
744 android_log_context context = create_android_log_parser(msg.msg() + sizeof(uint32_t),
Yi Jinb592e3b2018-02-01 15:17:04 -0800745 msg.len() - sizeof(uint32_t));
746 ;
Yi Jin3c034c92017-12-22 17:36:47 -0800747 android_log_list_element elem;
748
749 lastTimestamp.tv_sec = msg.entry_v1.sec;
750 lastTimestamp.tv_nsec = msg.entry_v1.nsec;
751
752 // format a BinaryLogEntry
Yi Jin5ee07872018-03-05 18:18:27 -0800753 uint64_t token = proto.start(LogProto::BINARY_LOGS);
Yi Jin3c034c92017-12-22 17:36:47 -0800754 proto.write(BinaryLogEntry::SEC, msg.entry_v1.sec);
755 proto.write(BinaryLogEntry::NANOSEC, msg.entry_v1.nsec);
Yi Jinb592e3b2018-02-01 15:17:04 -0800756 proto.write(BinaryLogEntry::UID, (int)msg.entry_v4.uid);
Yi Jin3c034c92017-12-22 17:36:47 -0800757 proto.write(BinaryLogEntry::PID, msg.entry_v1.pid);
758 proto.write(BinaryLogEntry::TID, msg.entry_v1.tid);
Yi Jinb592e3b2018-02-01 15:17:04 -0800759 proto.write(BinaryLogEntry::TAG_INDEX,
760 get4LE(reinterpret_cast<uint8_t const*>(msg.msg())));
Yi Jin3c034c92017-12-22 17:36:47 -0800761 do {
762 elem = android_log_read_next(context);
Yi Jin5ee07872018-03-05 18:18:27 -0800763 uint64_t elemToken = proto.start(BinaryLogEntry::ELEMS);
Yi Jin3c034c92017-12-22 17:36:47 -0800764 switch (elem.type) {
765 case EVENT_TYPE_INT:
Yi Jinb592e3b2018-02-01 15:17:04 -0800766 proto.write(BinaryLogEntry::Elem::TYPE,
767 BinaryLogEntry::Elem::EVENT_TYPE_INT);
768 proto.write(BinaryLogEntry::Elem::VAL_INT32, (int)elem.data.int32);
Yi Jin3c034c92017-12-22 17:36:47 -0800769 break;
770 case EVENT_TYPE_LONG:
Yi Jinb592e3b2018-02-01 15:17:04 -0800771 proto.write(BinaryLogEntry::Elem::TYPE,
772 BinaryLogEntry::Elem::EVENT_TYPE_LONG);
773 proto.write(BinaryLogEntry::Elem::VAL_INT64, (long long)elem.data.int64);
Yi Jin3c034c92017-12-22 17:36:47 -0800774 break;
775 case EVENT_TYPE_STRING:
Yi Jinb592e3b2018-02-01 15:17:04 -0800776 proto.write(BinaryLogEntry::Elem::TYPE,
777 BinaryLogEntry::Elem::EVENT_TYPE_STRING);
Yi Jin3c034c92017-12-22 17:36:47 -0800778 proto.write(BinaryLogEntry::Elem::VAL_STRING, elem.data.string, elem.len);
779 break;
780 case EVENT_TYPE_FLOAT:
Yi Jinb592e3b2018-02-01 15:17:04 -0800781 proto.write(BinaryLogEntry::Elem::TYPE,
782 BinaryLogEntry::Elem::EVENT_TYPE_FLOAT);
Yi Jin3c034c92017-12-22 17:36:47 -0800783 proto.write(BinaryLogEntry::Elem::VAL_FLOAT, elem.data.float32);
784 break;
785 case EVENT_TYPE_LIST:
Yi Jinb592e3b2018-02-01 15:17:04 -0800786 proto.write(BinaryLogEntry::Elem::TYPE,
787 BinaryLogEntry::Elem::EVENT_TYPE_LIST);
Yi Jin3c034c92017-12-22 17:36:47 -0800788 break;
789 case EVENT_TYPE_LIST_STOP:
Yi Jinb592e3b2018-02-01 15:17:04 -0800790 proto.write(BinaryLogEntry::Elem::TYPE,
791 BinaryLogEntry::Elem::EVENT_TYPE_LIST_STOP);
Yi Jin3c034c92017-12-22 17:36:47 -0800792 break;
793 case EVENT_TYPE_UNKNOWN:
Yi Jinb592e3b2018-02-01 15:17:04 -0800794 proto.write(BinaryLogEntry::Elem::TYPE,
795 BinaryLogEntry::Elem::EVENT_TYPE_UNKNOWN);
Yi Jin3c034c92017-12-22 17:36:47 -0800796 break;
797 }
798 proto.end(elemToken);
799 } while ((elem.type != EVENT_TYPE_UNKNOWN) && !elem.complete);
800 proto.end(token);
801 if (context) {
802 android_log_destroy(&context);
803 }
804 } else {
805 AndroidLogEntry entry;
806 err = android_log_processLogBuffer(&msg.entry_v1, &entry);
807 if (err != NO_ERROR) {
Yi Jin83fb1d52018-03-16 12:03:53 -0700808 ALOGW("LogSection %s: fails to process to an entry.\n", this->name.string());
Yi Jin3c034c92017-12-22 17:36:47 -0800809 break;
810 }
811 lastTimestamp.tv_sec = entry.tv_sec;
812 lastTimestamp.tv_nsec = entry.tv_nsec;
813
814 // format a TextLogEntry
Yi Jin5ee07872018-03-05 18:18:27 -0800815 uint64_t token = proto.start(LogProto::TEXT_LOGS);
Yi Jin3c034c92017-12-22 17:36:47 -0800816 proto.write(TextLogEntry::SEC, (long long)entry.tv_sec);
817 proto.write(TextLogEntry::NANOSEC, (long long)entry.tv_nsec);
818 proto.write(TextLogEntry::PRIORITY, (int)entry.priority);
819 proto.write(TextLogEntry::UID, entry.uid);
820 proto.write(TextLogEntry::PID, entry.pid);
821 proto.write(TextLogEntry::TID, entry.tid);
822 proto.write(TextLogEntry::TAG, entry.tag, trimTail(entry.tag, entry.tagLen));
Yi Jinb592e3b2018-02-01 15:17:04 -0800823 proto.write(TextLogEntry::LOG, entry.message,
824 trimTail(entry.message, entry.messageLen));
Yi Jin3c034c92017-12-22 17:36:47 -0800825 proto.end(token);
826 }
827 }
828 gLastLogsRetrieved[mLogID] = lastTimestamp;
Kweku Adams4d4a2332018-09-13 15:44:58 -0700829 if (!proto.flush(pipeWriteFd) && errno == EPIPE) {
830 ALOGE("[%s] wrote to a broken pipe\n", this->name.string());
831 return EPIPE;
832 }
Yi Jin83fb1d52018-03-16 12:03:53 -0700833 return NO_ERROR;
Yi Jin3c034c92017-12-22 17:36:47 -0800834}
Kweku Adamseadd1232018-02-05 16:45:13 -0800835
836// ================================================================================
837
838TombstoneSection::TombstoneSection(int id, const char* type, const int64_t timeoutMs)
839 : WorkerThreadSection(id, timeoutMs), mType(type) {
840 name += "tombstone ";
841 name += type;
842}
843
844TombstoneSection::~TombstoneSection() {}
845
846status_t TombstoneSection::BlockingCall(int pipeWriteFd) const {
847 std::unique_ptr<DIR, decltype(&closedir)> proc(opendir("/proc"), closedir);
848 if (proc.get() == nullptr) {
849 ALOGE("opendir /proc failed: %s\n", strerror(errno));
850 return -errno;
851 }
852
853 const std::set<int> hal_pids = get_interesting_hal_pids();
854
855 ProtoOutputStream proto;
856 struct dirent* d;
857 status_t err = NO_ERROR;
858 while ((d = readdir(proc.get()))) {
859 int pid = atoi(d->d_name);
860 if (pid <= 0) {
861 continue;
862 }
863
864 const std::string link_name = android::base::StringPrintf("/proc/%d/exe", pid);
865 std::string exe;
866 if (!android::base::Readlink(link_name, &exe)) {
867 ALOGE("Can't read '%s': %s\n", link_name.c_str(), strerror(errno));
868 continue;
869 }
870
871 bool is_java_process;
872 if (exe == "/system/bin/app_process32" || exe == "/system/bin/app_process64") {
873 if (mType != "java") continue;
874 // Don't bother dumping backtraces for the zygote.
875 if (IsZygote(pid)) {
876 VLOG("Skipping Zygote");
877 continue;
878 }
879
880 is_java_process = true;
881 } else if (should_dump_native_traces(exe.c_str())) {
882 if (mType != "native") continue;
883 is_java_process = false;
884 } else if (hal_pids.find(pid) != hal_pids.end()) {
885 if (mType != "hal") continue;
886 is_java_process = false;
887 } else {
888 // Probably a native process we don't care about, continue.
889 VLOG("Skipping %d", pid);
890 continue;
891 }
892
893 Fpipe dumpPipe;
894 if (!dumpPipe.init()) {
895 ALOGW("TombstoneSection '%s' failed to setup dump pipe", this->name.string());
896 err = -errno;
897 break;
898 }
899
900 const uint64_t start = Nanotime();
901 pid_t child = fork();
902 if (child < 0) {
903 ALOGE("Failed to fork child process");
904 break;
905 } else if (child == 0) {
906 // This is the child process.
Yi Jin6355d2f2018-03-14 15:18:02 -0700907 dumpPipe.readFd().reset();
Kweku Adamseadd1232018-02-05 16:45:13 -0800908 const int ret = dump_backtrace_to_file_timeout(
909 pid, is_java_process ? kDebuggerdJavaBacktrace : kDebuggerdNativeBacktrace,
Yi Jin6355d2f2018-03-14 15:18:02 -0700910 is_java_process ? 5 : 20, dumpPipe.writeFd().get());
Kweku Adamseadd1232018-02-05 16:45:13 -0800911 if (ret == -1) {
912 if (errno == 0) {
913 ALOGW("Dumping failed for pid '%d', likely due to a timeout\n", pid);
914 } else {
915 ALOGE("Dumping failed for pid '%d': %s\n", pid, strerror(errno));
916 }
917 }
Yi Jin6355d2f2018-03-14 15:18:02 -0700918 dumpPipe.writeFd().reset();
Kweku Adamseadd1232018-02-05 16:45:13 -0800919 _exit(EXIT_SUCCESS);
920 }
Yi Jin6355d2f2018-03-14 15:18:02 -0700921 dumpPipe.writeFd().reset();
Kweku Adamseadd1232018-02-05 16:45:13 -0800922 // Parent process.
923 // Read from the pipe concurrently to avoid blocking the child.
924 FdBuffer buffer;
Yi Jine3dab2d2018-03-22 16:56:39 -0700925 err = buffer.readFully(dumpPipe.readFd().get());
Kweku Adamsa8a56c82018-04-23 06:15:31 -0700926 // Wait on the child to avoid it becoming a zombie process.
927 status_t cStatus = wait_child(child);
Kweku Adamseadd1232018-02-05 16:45:13 -0800928 if (err != NO_ERROR) {
929 ALOGW("TombstoneSection '%s' failed to read stack dump: %d", this->name.string(), err);
Yi Jin6355d2f2018-03-14 15:18:02 -0700930 dumpPipe.readFd().reset();
Kweku Adamseadd1232018-02-05 16:45:13 -0800931 break;
932 }
Kweku Adamsa8a56c82018-04-23 06:15:31 -0700933 if (cStatus != NO_ERROR) {
Kweku Adams4d4a2332018-09-13 15:44:58 -0700934 ALOGE("[%s] child had an issue: %s\n", this->name.string(), strerror(-cStatus));
Kweku Adamsa8a56c82018-04-23 06:15:31 -0700935 }
Kweku Adamseadd1232018-02-05 16:45:13 -0800936
937 auto dump = std::make_unique<char[]>(buffer.size());
938 auto iterator = buffer.data();
939 int i = 0;
940 while (iterator.hasNext()) {
941 dump[i] = iterator.next();
942 i++;
943 }
Yi Jin6cacbcb2018-03-30 14:04:52 -0700944 uint64_t token = proto.start(android::os::BackTraceProto::TRACES);
Kweku Adamseadd1232018-02-05 16:45:13 -0800945 proto.write(android::os::BackTraceProto::Stack::PID, pid);
946 proto.write(android::os::BackTraceProto::Stack::DUMP, dump.get(), i);
947 proto.write(android::os::BackTraceProto::Stack::DUMP_DURATION_NS,
948 static_cast<long long>(Nanotime() - start));
949 proto.end(token);
Yi Jin6355d2f2018-03-14 15:18:02 -0700950 dumpPipe.readFd().reset();
Kweku Adamseadd1232018-02-05 16:45:13 -0800951 }
952
Kweku Adams4d4a2332018-09-13 15:44:58 -0700953 if (!proto.flush(pipeWriteFd) && errno == EPIPE) {
954 ALOGE("[%s] wrote to a broken pipe\n", this->name.string());
955 if (err != NO_ERROR) {
956 return EPIPE;
957 }
958 }
959
Kweku Adamseadd1232018-02-05 16:45:13 -0800960 return err;
961}
Yi Jin6cacbcb2018-03-30 14:04:52 -0700962
963} // namespace incidentd
964} // namespace os
Yi Jin98ce8102018-04-12 11:15:39 -0700965} // namespace android