blob: 0827785811b66fe9ae11650bcdaf38b06176bd7a [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 */
16
17#define LOG_TAG "incidentd"
18
19#include "Section.h"
Yi Jin99c248f2017-08-25 18:11:58 -070020
Yi Jin3c034c92017-12-22 17:36:47 -080021#include <errno.h>
Yi Jin4bab3a12018-01-10 16:50:59 -080022#include <sys/prctl.h>
Yi Jin3c034c92017-12-22 17:36:47 -080023#include <unistd.h>
24#include <wait.h>
25
26#include <memory>
27#include <mutex>
Joe Onorato1754d742016-11-21 17:51:35 -080028
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>
Yi Jin3c034c92017-12-22 17:36:47 -080031#include <log/log_event_list.h>
32#include <log/logprint.h>
33#include <log/log_read.h>
Yi Jin3c034c92017-12-22 17:36:47 -080034#include <private/android_logger.h>
35
36#include "FdBuffer.h"
37#include "frameworks/base/core/proto/android/util/log.proto.h"
38#include "io_util.h"
39#include "Privacy.h"
40#include "PrivacyBuffer.h"
41#include "section_list.h"
Joe Onorato1754d742016-11-21 17:51:35 -080042
Yi Jinc23fad22017-09-15 17:24:59 -070043using namespace android::util;
Joe Onorato1754d742016-11-21 17:51:35 -080044using namespace std;
45
Yi Jinc23fad22017-09-15 17:24:59 -070046// special section ids
47const int FIELD_ID_INCIDENT_HEADER = 1;
48
49// incident section parameters
Yi Jinb44f7d42017-07-21 12:12:59 -070050const int WAIT_MAX = 5;
51const struct timespec WAIT_INTERVAL_NS = {0, 200 * 1000 * 1000};
Yi Jin3c034c92017-12-22 17:36:47 -080052const char INCIDENT_HELPER[] = "/system/bin/incident_helper";
Yi Jinb44f7d42017-07-21 12:12:59 -070053
54static pid_t
Yi Jinedfd5bb2017-09-06 17:09:11 -070055fork_execute_incident_helper(const int id, const char* name, Fpipe& p2cPipe, Fpipe& c2pPipe)
Yi Jinb44f7d42017-07-21 12:12:59 -070056{
Yi Jin0ed9b682017-08-18 14:51:20 -070057 const char* ihArgs[] { INCIDENT_HELPER, "-s", String8::format("%d", id).string(), NULL };
Yi Jinb44f7d42017-07-21 12:12:59 -070058 // fork used in multithreaded environment, avoid adding unnecessary code in child process
59 pid_t pid = fork();
60 if (pid == 0) {
Yi Jin4bab3a12018-01-10 16:50:59 -080061 if (TEMP_FAILURE_RETRY(dup2(p2cPipe.readFd(), STDIN_FILENO)) != 0
62 || !p2cPipe.close()
63 || TEMP_FAILURE_RETRY(dup2(c2pPipe.writeFd(), STDOUT_FILENO)) != 1
64 || !c2pPipe.close()) {
Yi Jinb44f7d42017-07-21 12:12:59 -070065 ALOGW("%s can't setup stdin and stdout for incident helper", name);
66 _exit(EXIT_FAILURE);
67 }
68
Yi Jin4bab3a12018-01-10 16:50:59 -080069 /* make sure the child dies when incidentd dies */
70 prctl(PR_SET_PDEATHSIG, SIGKILL);
71
Yi Jinb44f7d42017-07-21 12:12:59 -070072 execv(INCIDENT_HELPER, const_cast<char**>(ihArgs));
73
74 ALOGW("%s failed in incident helper process: %s", name, strerror(errno));
75 _exit(EXIT_FAILURE); // always exits with failure if any
76 }
77 // close the fds used in incident helper
78 close(p2cPipe.readFd());
79 close(c2pPipe.writeFd());
80 return pid;
81}
82
Yi Jin99c248f2017-08-25 18:11:58 -070083// ================================================================================
Yi Jin4bab3a12018-01-10 16:50:59 -080084static status_t statusCode(int status) {
85 if (WIFSIGNALED(status)) {
86 ALOGD("return by signal: %s", strerror(WTERMSIG(status)));
87 return -WTERMSIG(status);
88 } else if (WIFEXITED(status) && WEXITSTATUS(status) > 0) {
89 ALOGD("return by exit: %s", strerror(WEXITSTATUS(status)));
90 return -WEXITSTATUS(status);
91 }
92 return NO_ERROR;
93}
94
Yi Jinedfd5bb2017-09-06 17:09:11 -070095static status_t kill_child(pid_t pid) {
Yi Jinb44f7d42017-07-21 12:12:59 -070096 int status;
Yi Jin4bab3a12018-01-10 16:50:59 -080097 ALOGD("try to kill child process %d", pid);
Yi Jinb44f7d42017-07-21 12:12:59 -070098 kill(pid, SIGKILL);
99 if (waitpid(pid, &status, 0) == -1) return -1;
Yi Jin4bab3a12018-01-10 16:50:59 -0800100 return statusCode(status);
Yi Jinb44f7d42017-07-21 12:12:59 -0700101}
102
Yi Jinedfd5bb2017-09-06 17:09:11 -0700103static status_t wait_child(pid_t pid) {
Yi Jinb44f7d42017-07-21 12:12:59 -0700104 int status;
105 bool died = false;
106 // wait for child to report status up to 1 seconds
107 for(int loop = 0; !died && loop < WAIT_MAX; loop++) {
108 if (waitpid(pid, &status, WNOHANG) == pid) died = true;
109 // sleep for 0.2 second
110 nanosleep(&WAIT_INTERVAL_NS, NULL);
111 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700112 if (!died) return kill_child(pid);
Yi Jin4bab3a12018-01-10 16:50:59 -0800113 return statusCode(status);
Yi Jinb44f7d42017-07-21 12:12:59 -0700114}
Joe Onorato1754d742016-11-21 17:51:35 -0800115// ================================================================================
Yi Jin99c248f2017-08-25 18:11:58 -0700116static const Privacy*
Yi Jinedfd5bb2017-09-06 17:09:11 -0700117get_privacy_of_section(int id)
Yi Jin99c248f2017-08-25 18:11:58 -0700118{
Yi Jin7e0b4e52017-09-12 20:00:25 -0700119 int l = 0;
120 int r = PRIVACY_POLICY_COUNT - 1;
121 while (l <= r) {
122 int mid = (l + r) >> 1;
123 const Privacy* p = PRIVACY_POLICY_LIST[mid];
124
125 if (p->field_id < (uint32_t)id) {
126 l = mid + 1;
127 } else if (p->field_id > (uint32_t)id) {
128 r = mid - 1;
129 } else {
130 return p;
131 }
Yi Jin99c248f2017-08-25 18:11:58 -0700132 }
133 return NULL;
134}
135
Yi Jinedfd5bb2017-09-06 17:09:11 -0700136// ================================================================================
Yi Jin99c248f2017-08-25 18:11:58 -0700137static status_t
Yi Jinedfd5bb2017-09-06 17:09:11 -0700138write_section_header(int fd, int sectionId, size_t size)
Yi Jin99c248f2017-08-25 18:11:58 -0700139{
Yi Jin99c248f2017-08-25 18:11:58 -0700140 uint8_t buf[20];
Yi Jinedfd5bb2017-09-06 17:09:11 -0700141 uint8_t *p = write_length_delimited_tag_header(buf, sectionId, size);
142 return write_all(fd, buf, p-buf);
Yi Jin99c248f2017-08-25 18:11:58 -0700143}
144
145static status_t
Yi Jinedfd5bb2017-09-06 17:09:11 -0700146write_report_requests(const int id, const FdBuffer& buffer, ReportRequestSet* requests)
Yi Jin99c248f2017-08-25 18:11:58 -0700147{
Yi Jin0f047162017-09-05 13:44:22 -0700148 status_t err = -EBADF;
Yi Jinc23fad22017-09-15 17:24:59 -0700149 EncodedBuffer::iterator data = buffer.data();
150 PrivacyBuffer privacyBuffer(get_privacy_of_section(id), data);
Yi Jin99c248f2017-08-25 18:11:58 -0700151 int writeable = 0;
152
Yi Jin0f047162017-09-05 13:44:22 -0700153 // The streaming ones, group requests by spec in order to save unnecessary strip operations
154 map<PrivacySpec, vector<sp<ReportRequest>>> requestsBySpec;
Yi Jin99c248f2017-08-25 18:11:58 -0700155 for (ReportRequestSet::iterator it = requests->begin(); it != requests->end(); it++) {
156 sp<ReportRequest> request = *it;
Yi Jinedfd5bb2017-09-06 17:09:11 -0700157 if (!request->ok() || !request->args.containsSection(id)) {
Yi Jin0f047162017-09-05 13:44:22 -0700158 continue; // skip invalid request
Yi Jin99c248f2017-08-25 18:11:58 -0700159 }
Yi Jin0f047162017-09-05 13:44:22 -0700160 PrivacySpec spec = new_spec_from_args(request->args.dest());
161 requestsBySpec[spec].push_back(request);
162 }
163
164 for (map<PrivacySpec, vector<sp<ReportRequest>>>::iterator mit = requestsBySpec.begin(); mit != requestsBySpec.end(); mit++) {
165 PrivacySpec spec = mit->first;
Yi Jinc23fad22017-09-15 17:24:59 -0700166 err = privacyBuffer.strip(spec);
167 if (err != NO_ERROR) return err; // it means the privacyBuffer data is corrupted.
168 if (privacyBuffer.size() == 0) continue;
Yi Jin0f047162017-09-05 13:44:22 -0700169
170 for (vector<sp<ReportRequest>>::iterator it = mit->second.begin(); it != mit->second.end(); it++) {
171 sp<ReportRequest> request = *it;
Yi Jinc23fad22017-09-15 17:24:59 -0700172 err = write_section_header(request->fd, id, privacyBuffer.size());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700173 if (err != NO_ERROR) { request->err = err; continue; }
Yi Jinc23fad22017-09-15 17:24:59 -0700174 err = privacyBuffer.flush(request->fd);
Yi Jinedfd5bb2017-09-06 17:09:11 -0700175 if (err != NO_ERROR) { request->err = err; continue; }
176 writeable++;
Yi Jinc23fad22017-09-15 17:24:59 -0700177 ALOGD("Section %d flushed %zu bytes to fd %d with spec %d", id, privacyBuffer.size(), request->fd, spec.dest);
Yi Jin0f047162017-09-05 13:44:22 -0700178 }
Yi Jinc23fad22017-09-15 17:24:59 -0700179 privacyBuffer.clear();
Yi Jin99c248f2017-08-25 18:11:58 -0700180 }
181
182 // The dropbox file
183 if (requests->mainFd() >= 0) {
Yi Jinc23fad22017-09-15 17:24:59 -0700184 err = privacyBuffer.strip(get_default_dropbox_spec());
Yi Jin0f047162017-09-05 13:44:22 -0700185 if (err != NO_ERROR) return err; // the buffer data is corrupted.
Yi Jinc23fad22017-09-15 17:24:59 -0700186 if (privacyBuffer.size() == 0) goto DONE;
Yi Jin0f047162017-09-05 13:44:22 -0700187
Yi Jinc23fad22017-09-15 17:24:59 -0700188 err = write_section_header(requests->mainFd(), id, privacyBuffer.size());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700189 if (err != NO_ERROR) { requests->setMainFd(-1); goto DONE; }
Yi Jinc23fad22017-09-15 17:24:59 -0700190 err = privacyBuffer.flush(requests->mainFd());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700191 if (err != NO_ERROR) { requests->setMainFd(-1); goto DONE; }
192 writeable++;
Yi Jinc23fad22017-09-15 17:24:59 -0700193 ALOGD("Section %d flushed %zu bytes to dropbox %d", id, privacyBuffer.size(), requests->mainFd());
Yi Jin99c248f2017-08-25 18:11:58 -0700194 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700195
196DONE:
Yi Jin99c248f2017-08-25 18:11:58 -0700197 // only returns error if there is no fd to write to.
198 return writeable > 0 ? NO_ERROR : err;
199}
200
201// ================================================================================
Yi Jinb44f7d42017-07-21 12:12:59 -0700202Section::Section(int i, const int64_t timeoutMs)
Yi Jinedfd5bb2017-09-06 17:09:11 -0700203 :id(i),
204 timeoutMs(timeoutMs)
Joe Onorato1754d742016-11-21 17:51:35 -0800205{
206}
207
208Section::~Section()
209{
210}
211
Joe Onorato1754d742016-11-21 17:51:35 -0800212// ================================================================================
Yi Jinedfd5bb2017-09-06 17:09:11 -0700213HeaderSection::HeaderSection()
214 :Section(FIELD_ID_INCIDENT_HEADER, 0)
215{
216}
217
218HeaderSection::~HeaderSection()
219{
220}
221
222status_t
223HeaderSection::Execute(ReportRequestSet* requests) const
224{
225 for (ReportRequestSet::iterator it=requests->begin(); it!=requests->end(); it++) {
226 const sp<ReportRequest> request = *it;
Yi Jinbdf58942017-11-14 17:58:19 -0800227 const vector<vector<uint8_t>>& headers = request->args.headers();
Yi Jinedfd5bb2017-09-06 17:09:11 -0700228
Yi Jinbdf58942017-11-14 17:58:19 -0800229 for (vector<vector<uint8_t>>::const_iterator buf=headers.begin(); buf!=headers.end(); buf++) {
Yi Jinedfd5bb2017-09-06 17:09:11 -0700230 if (buf->empty()) continue;
231
232 // So the idea is only requests with negative fd are written to dropbox file.
233 int fd = request->fd >= 0 ? request->fd : requests->mainFd();
234 write_section_header(fd, FIELD_ID_INCIDENT_HEADER, buf->size());
235 write_all(fd, (uint8_t const*)buf->data(), buf->size());
236 // If there was an error now, there will be an error later and we will remove
237 // it from the list then.
238 }
239 }
240 return NO_ERROR;
241}
242
243// ================================================================================
Yi Jinb44f7d42017-07-21 12:12:59 -0700244FileSection::FileSection(int id, const char* filename, const int64_t timeoutMs)
Yi Jinedfd5bb2017-09-06 17:09:11 -0700245 :Section(id, timeoutMs),
246 mFilename(filename)
247{
Yi Jinb44f7d42017-07-21 12:12:59 -0700248 name = filename;
Yi Jin0eb22342017-11-06 17:17:27 -0800249 mIsSysfs = strncmp(filename, "/sys/", 5) == 0;
Yi Jin0a3406f2017-06-22 19:23:11 -0700250}
251
252FileSection::~FileSection() {}
253
Yi Jin99c248f2017-08-25 18:11:58 -0700254status_t
255FileSection::Execute(ReportRequestSet* requests) const
256{
Yi Jinb44f7d42017-07-21 12:12:59 -0700257 // read from mFilename first, make sure the file is available
258 // add O_CLOEXEC to make sure it is closed when exec incident helper
George Burgess IV6f9735b2017-08-03 16:08:29 -0700259 int fd = open(mFilename, O_RDONLY | O_CLOEXEC);
Yi Jin0a3406f2017-06-22 19:23:11 -0700260 if (fd == -1) {
261 ALOGW("FileSection '%s' failed to open file", this->name.string());
262 return -errno;
263 }
264
Yi Jinb44f7d42017-07-21 12:12:59 -0700265 FdBuffer buffer;
266 Fpipe p2cPipe;
267 Fpipe c2pPipe;
268 // initiate pipes to pass data to/from incident_helper
269 if (!p2cPipe.init() || !c2pPipe.init()) {
270 ALOGW("FileSection '%s' failed to setup pipes", this->name.string());
Yi Jin0a3406f2017-06-22 19:23:11 -0700271 return -errno;
272 }
273
Yi Jinedfd5bb2017-09-06 17:09:11 -0700274 pid_t pid = fork_execute_incident_helper(this->id, this->name.string(), p2cPipe, c2pPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -0700275 if (pid == -1) {
276 ALOGW("FileSection '%s' failed to fork", this->name.string());
277 return -errno;
278 }
279
280 // parent process
281 status_t readStatus = buffer.readProcessedDataInStream(fd, p2cPipe.writeFd(), c2pPipe.readFd(),
Yi Jin0eb22342017-11-06 17:17:27 -0800282 this->timeoutMs, mIsSysfs);
Yi Jinb44f7d42017-07-21 12:12:59 -0700283 if (readStatus != NO_ERROR || buffer.timedOut()) {
Yi Jin4bab3a12018-01-10 16:50:59 -0800284 ALOGW("FileSection '%s' failed to read data from incident helper: %s, timedout: %s",
285 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
286 kill_child(pid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700287 return readStatus;
288 }
289
Yi Jinedfd5bb2017-09-06 17:09:11 -0700290 status_t ihStatus = wait_child(pid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700291 if (ihStatus != NO_ERROR) {
292 ALOGW("FileSection '%s' abnormal child process: %s", this->name.string(), strerror(-ihStatus));
293 return ihStatus;
294 }
295
296 ALOGD("FileSection '%s' wrote %zd bytes in %d ms", this->name.string(), buffer.size(),
Yi Jin0a3406f2017-06-22 19:23:11 -0700297 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700298 status_t err = write_report_requests(this->id, buffer, requests);
Yi Jin0a3406f2017-06-22 19:23:11 -0700299 if (err != NO_ERROR) {
300 ALOGW("FileSection '%s' failed writing: %s", this->name.string(), strerror(-err));
301 return err;
302 }
303
304 return NO_ERROR;
305}
306
307// ================================================================================
Joe Onorato1754d742016-11-21 17:51:35 -0800308struct WorkerThreadData : public virtual RefBase
309{
310 const WorkerThreadSection* section;
311 int fds[2];
312
313 // Lock protects these fields
314 mutex lock;
315 bool workerDone;
316 status_t workerError;
317
318 WorkerThreadData(const WorkerThreadSection* section);
319 virtual ~WorkerThreadData();
320
321 int readFd() { return fds[0]; }
322 int writeFd() { return fds[1]; }
323};
324
325WorkerThreadData::WorkerThreadData(const WorkerThreadSection* sec)
326 :section(sec),
327 workerDone(false),
328 workerError(NO_ERROR)
329{
330 fds[0] = -1;
331 fds[1] = -1;
332}
333
334WorkerThreadData::~WorkerThreadData()
335{
336}
337
338// ================================================================================
339WorkerThreadSection::WorkerThreadSection(int id)
340 :Section(id)
341{
342}
343
344WorkerThreadSection::~WorkerThreadSection()
345{
346}
347
348static void*
349worker_thread_func(void* cookie)
350{
351 WorkerThreadData* data = (WorkerThreadData*)cookie;
352 status_t err = data->section->BlockingCall(data->writeFd());
353
354 {
355 unique_lock<mutex> lock(data->lock);
356 data->workerDone = true;
357 data->workerError = err;
358 }
359
360 close(data->writeFd());
361 data->decStrong(data->section);
362 // data might be gone now. don't use it after this point in this thread.
363 return NULL;
364}
365
366status_t
367WorkerThreadSection::Execute(ReportRequestSet* requests) const
368{
369 status_t err = NO_ERROR;
370 pthread_t thread;
371 pthread_attr_t attr;
372 bool timedOut = false;
373 FdBuffer buffer;
374
375 // Data shared between this thread and the worker thread.
376 sp<WorkerThreadData> data = new WorkerThreadData(this);
377
378 // Create the pipe
379 err = pipe(data->fds);
380 if (err != 0) {
381 return -errno;
382 }
383
384 // The worker thread needs a reference and we can't let the count go to zero
385 // if that thread is slow to start.
386 data->incStrong(this);
387
388 // Create the thread
389 err = pthread_attr_init(&attr);
390 if (err != 0) {
391 return -err;
392 }
393 // TODO: Do we need to tweak thread priority?
394 err = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
395 if (err != 0) {
396 pthread_attr_destroy(&attr);
397 return -err;
398 }
399 err = pthread_create(&thread, &attr, worker_thread_func, (void*)data.get());
400 if (err != 0) {
401 pthread_attr_destroy(&attr);
402 return -err;
403 }
404 pthread_attr_destroy(&attr);
405
406 // Loop reading until either the timeout or the worker side is done (i.e. eof).
Yi Jinb44f7d42017-07-21 12:12:59 -0700407 err = buffer.read(data->readFd(), this->timeoutMs);
Joe Onorato1754d742016-11-21 17:51:35 -0800408 if (err != NO_ERROR) {
409 // TODO: Log this error into the incident report.
410 ALOGW("WorkerThreadSection '%s' reader failed with error '%s'", this->name.string(),
411 strerror(-err));
412 }
413
414 // Done with the read fd. The worker thread closes the write one so
415 // we never race and get here first.
416 close(data->readFd());
417
418 // If the worker side is finished, then return its error (which may overwrite
419 // our possible error -- but it's more interesting anyway). If not, then we timed out.
420 {
421 unique_lock<mutex> lock(data->lock);
422 if (!data->workerDone) {
423 // We timed out
424 timedOut = true;
425 } else {
426 if (data->workerError != NO_ERROR) {
427 err = data->workerError;
428 // TODO: Log this error into the incident report.
429 ALOGW("WorkerThreadSection '%s' worker failed with error '%s'", this->name.string(),
430 strerror(-err));
431 }
432 }
433 }
434
435 if (timedOut || buffer.timedOut()) {
436 ALOGW("WorkerThreadSection '%s' timed out", this->name.string());
437 return NO_ERROR;
438 }
439
440 if (buffer.truncated()) {
441 // TODO: Log this into the incident report.
442 }
443
444 // TODO: There was an error with the command or buffering. Report that. For now
445 // just exit with a log messasge.
446 if (err != NO_ERROR) {
447 ALOGW("WorkerThreadSection '%s' failed with error '%s'", this->name.string(),
448 strerror(-err));
449 return NO_ERROR;
450 }
451
452 // Write the data that was collected
Yi Jinb44f7d42017-07-21 12:12:59 -0700453 ALOGD("WorkerThreadSection '%s' wrote %zd bytes in %d ms", name.string(), buffer.size(),
Joe Onorato1754d742016-11-21 17:51:35 -0800454 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700455 err = write_report_requests(this->id, buffer, requests);
Joe Onorato1754d742016-11-21 17:51:35 -0800456 if (err != NO_ERROR) {
457 ALOGW("WorkerThreadSection '%s' failed writing: '%s'", this->name.string(), strerror(-err));
458 return err;
459 }
460
461 return NO_ERROR;
462}
463
464// ================================================================================
Yi Jin99c248f2017-08-25 18:11:58 -0700465void
466CommandSection::init(const char* command, va_list args)
Yi Jinb44f7d42017-07-21 12:12:59 -0700467{
468 va_list copied_args;
Yi Jinb44f7d42017-07-21 12:12:59 -0700469 int numOfArgs = 0;
Yi Jin4ef28b72017-08-14 14:45:28 -0700470
471 va_copy(copied_args, args);
472 while(va_arg(copied_args, const char*) != NULL) {
Yi Jinb44f7d42017-07-21 12:12:59 -0700473 numOfArgs++;
474 }
Yi Jin4ef28b72017-08-14 14:45:28 -0700475 va_end(copied_args);
Yi Jinb44f7d42017-07-21 12:12:59 -0700476
477 // allocate extra 1 for command and 1 for NULL terminator
478 mCommand = (const char**)malloc(sizeof(const char*) * (numOfArgs + 2));
479
480 mCommand[0] = command;
481 name = command;
482 for (int i=0; i<numOfArgs; i++) {
Yi Jin4ef28b72017-08-14 14:45:28 -0700483 const char* arg = va_arg(args, const char*);
Yi Jinb44f7d42017-07-21 12:12:59 -0700484 mCommand[i+1] = arg;
485 name += " ";
486 name += arg;
487 }
488 mCommand[numOfArgs+1] = NULL;
Yi Jinb44f7d42017-07-21 12:12:59 -0700489}
490
491CommandSection::CommandSection(int id, const int64_t timeoutMs, const char* command, ...)
Yi Jinedfd5bb2017-09-06 17:09:11 -0700492 :Section(id, timeoutMs)
Joe Onorato1754d742016-11-21 17:51:35 -0800493{
494 va_list args;
Yi Jinb44f7d42017-07-21 12:12:59 -0700495 va_start(args, command);
496 init(command, args);
Joe Onorato1754d742016-11-21 17:51:35 -0800497 va_end(args);
Yi Jinb44f7d42017-07-21 12:12:59 -0700498}
Joe Onorato1754d742016-11-21 17:51:35 -0800499
Yi Jinb44f7d42017-07-21 12:12:59 -0700500CommandSection::CommandSection(int id, const char* command, ...)
Yi Jinedfd5bb2017-09-06 17:09:11 -0700501 :Section(id)
Yi Jinb44f7d42017-07-21 12:12:59 -0700502{
503 va_list args;
504 va_start(args, command);
505 init(command, args);
Joe Onorato1754d742016-11-21 17:51:35 -0800506 va_end(args);
507}
508
509CommandSection::~CommandSection()
510{
Yi Jinb44f7d42017-07-21 12:12:59 -0700511 free(mCommand);
Joe Onorato1754d742016-11-21 17:51:35 -0800512}
513
514status_t
Yi Jinb44f7d42017-07-21 12:12:59 -0700515CommandSection::Execute(ReportRequestSet* requests) const
Joe Onorato1754d742016-11-21 17:51:35 -0800516{
Yi Jinb44f7d42017-07-21 12:12:59 -0700517 FdBuffer buffer;
518 Fpipe cmdPipe;
519 Fpipe ihPipe;
520
521 if (!cmdPipe.init() || !ihPipe.init()) {
522 ALOGW("CommandSection '%s' failed to setup pipes", this->name.string());
523 return -errno;
524 }
525
526 pid_t cmdPid = fork();
527 if (cmdPid == -1) {
528 ALOGW("CommandSection '%s' failed to fork", this->name.string());
529 return -errno;
530 }
531 // child process to execute the command as root
532 if (cmdPid == 0) {
533 // replace command's stdout with ihPipe's write Fd
534 if (dup2(cmdPipe.writeFd(), STDOUT_FILENO) != 1 || !ihPipe.close() || !cmdPipe.close()) {
535 ALOGW("CommandSection '%s' failed to set up stdout: %s", this->name.string(), strerror(errno));
536 _exit(EXIT_FAILURE);
537 }
Kweku Adamsf5cc5752017-12-20 17:59:17 -0800538 execvp(this->mCommand[0], (char *const *) this->mCommand);
Yi Jinb44f7d42017-07-21 12:12:59 -0700539 int err = errno; // record command error code
540 ALOGW("CommandSection '%s' failed in executing command: %s", this->name.string(), strerror(errno));
541 _exit(err); // exit with command error code
542 }
Yi Jinedfd5bb2017-09-06 17:09:11 -0700543 pid_t ihPid = fork_execute_incident_helper(this->id, this->name.string(), cmdPipe, ihPipe);
Yi Jinb44f7d42017-07-21 12:12:59 -0700544 if (ihPid == -1) {
545 ALOGW("CommandSection '%s' failed to fork", this->name.string());
546 return -errno;
547 }
548
549 close(cmdPipe.writeFd());
550 status_t readStatus = buffer.read(ihPipe.readFd(), this->timeoutMs);
551 if (readStatus != NO_ERROR || buffer.timedOut()) {
Yi Jin4bab3a12018-01-10 16:50:59 -0800552 ALOGW("CommandSection '%s' failed to read data from incident helper: %s, timedout: %s",
553 this->name.string(), strerror(-readStatus), buffer.timedOut() ? "true" : "false");
554 kill_child(cmdPid);
555 kill_child(ihPid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700556 return readStatus;
557 }
558
559 // TODO: wait for command here has one trade-off: the failed status of command won't be detected until
560 // buffer timeout, but it has advatage on starting the data stream earlier.
Yi Jinedfd5bb2017-09-06 17:09:11 -0700561 status_t cmdStatus = wait_child(cmdPid);
562 status_t ihStatus = wait_child(ihPid);
Yi Jinb44f7d42017-07-21 12:12:59 -0700563 if (cmdStatus != NO_ERROR || ihStatus != NO_ERROR) {
Yi Jinadd11e92017-07-30 16:10:07 -0700564 ALOGW("CommandSection '%s' abnormal child processes, return status: command: %s, incident helper: %s",
Yi Jinb44f7d42017-07-21 12:12:59 -0700565 this->name.string(), strerror(-cmdStatus), strerror(-ihStatus));
566 return cmdStatus != NO_ERROR ? cmdStatus : ihStatus;
567 }
568
569 ALOGD("CommandSection '%s' wrote %zd bytes in %d ms", this->name.string(), buffer.size(),
570 (int)buffer.durationMs());
Yi Jinedfd5bb2017-09-06 17:09:11 -0700571 status_t err = write_report_requests(this->id, buffer, requests);
Yi Jinb44f7d42017-07-21 12:12:59 -0700572 if (err != NO_ERROR) {
573 ALOGW("CommandSection '%s' failed writing: %s", this->name.string(), strerror(-err));
574 return err;
575 }
Joe Onorato1754d742016-11-21 17:51:35 -0800576 return NO_ERROR;
577}
578
579// ================================================================================
580DumpsysSection::DumpsysSection(int id, const char* service, ...)
581 :WorkerThreadSection(id),
582 mService(service)
583{
584 name = "dumpsys ";
585 name += service;
586
587 va_list args;
588 va_start(args, service);
589 while (true) {
Yi Jin0a3406f2017-06-22 19:23:11 -0700590 const char* arg = va_arg(args, const char*);
Joe Onorato1754d742016-11-21 17:51:35 -0800591 if (arg == NULL) {
592 break;
593 }
594 mArgs.add(String16(arg));
595 name += " ";
596 name += arg;
597 }
598 va_end(args);
599}
600
601DumpsysSection::~DumpsysSection()
602{
603}
604
605status_t
606DumpsysSection::BlockingCall(int pipeWriteFd) const
607{
608 // checkService won't wait for the service to show up like getService will.
609 sp<IBinder> service = defaultServiceManager()->checkService(mService);
Yi Jin0a3406f2017-06-22 19:23:11 -0700610
Joe Onorato1754d742016-11-21 17:51:35 -0800611 if (service == NULL) {
612 // Returning an error interrupts the entire incident report, so just
613 // log the failure.
614 // TODO: have a meta record inside the report that would log this
615 // failure inside the report, because the fact that we can't find
616 // the service is good data in and of itself. This is running in
617 // another thread so lock that carefully...
618 ALOGW("DumpsysSection: Can't lookup service: %s", String8(mService).string());
619 return NO_ERROR;
620 }
621
622 service->dump(pipeWriteFd, mArgs);
623
624 return NO_ERROR;
625}
Yi Jin3c034c92017-12-22 17:36:47 -0800626
627// ================================================================================
628// initialization only once in Section.cpp.
629map<log_id_t, log_time> LogSection::gLastLogsRetrieved;
630
631LogSection::LogSection(int id, log_id_t logID)
632 :WorkerThreadSection(id),
633 mLogID(logID)
634{
635 name += "logcat ";
636 name += android_log_id_to_name(logID);
637 switch (logID) {
638 case LOG_ID_EVENTS:
639 case LOG_ID_STATS:
640 case LOG_ID_SECURITY:
641 mBinary = true;
642 break;
643 default:
644 mBinary = false;
645 }
646}
647
648LogSection::~LogSection()
649{
650}
651
652static size_t
653trimTail(char const* buf, size_t len)
654{
655 while (len > 0) {
656 char c = buf[len - 1];
657 if (c == '\0' || c == ' ' || c == '\n' || c == '\r' || c == ':') {
658 len--;
659 } else {
660 break;
661 }
662 }
663 return len;
664}
665
666static inline int32_t get4LE(uint8_t const* src) {
667 return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
668}
669
670status_t
671LogSection::BlockingCall(int pipeWriteFd) const
672{
673 status_t err = NO_ERROR;
674 // Open log buffer and getting logs since last retrieved time if any.
675 unique_ptr<logger_list, void (*)(logger_list*)> loggers(
676 gLastLogsRetrieved.find(mLogID) == gLastLogsRetrieved.end() ?
677 android_logger_list_alloc(ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 0, 0) :
678 android_logger_list_alloc_time(ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
679 gLastLogsRetrieved[mLogID], 0),
680 android_logger_list_free);
681
682 if (android_logger_open(loggers.get(), mLogID) == NULL) {
683 ALOGW("LogSection %s: Can't get logger.", this->name.string());
684 return err;
685 }
686
687 log_msg msg;
688 log_time lastTimestamp(0);
689
690 ProtoOutputStream proto;
691 while (true) { // keeps reading until logd buffer is fully read.
692 status_t err = android_logger_list_read(loggers.get(), &msg);
693 // err = 0 - no content, unexpected connection drop or EOF.
694 // err = +ive number - size of retrieved data from logger
695 // err = -ive number, OS supplied error _except_ for -EAGAIN
696 // err = -EAGAIN, graceful indication for ANDRODI_LOG_NONBLOCK that this is the end of data.
697 if (err <= 0) {
698 if (err != -EAGAIN) {
699 ALOGE("LogSection %s: fails to read a log_msg.\n", this->name.string());
700 }
701 break;
702 }
703 if (mBinary) {
704 // remove the first uint32 which is tag's index in event log tags
705 android_log_context context = create_android_log_parser(msg.msg() + sizeof(uint32_t),
706 msg.len() - sizeof(uint32_t));;
707 android_log_list_element elem;
708
709 lastTimestamp.tv_sec = msg.entry_v1.sec;
710 lastTimestamp.tv_nsec = msg.entry_v1.nsec;
711
712 // format a BinaryLogEntry
713 long long token = proto.start(LogProto::BINARY_LOGS);
714 proto.write(BinaryLogEntry::SEC, msg.entry_v1.sec);
715 proto.write(BinaryLogEntry::NANOSEC, msg.entry_v1.nsec);
716 proto.write(BinaryLogEntry::UID, (int) msg.entry_v4.uid);
717 proto.write(BinaryLogEntry::PID, msg.entry_v1.pid);
718 proto.write(BinaryLogEntry::TID, msg.entry_v1.tid);
719 proto.write(BinaryLogEntry::TAG_INDEX, get4LE(reinterpret_cast<uint8_t const*>(msg.msg())));
720 do {
721 elem = android_log_read_next(context);
722 long long elemToken = proto.start(BinaryLogEntry::ELEMS);
723 switch (elem.type) {
724 case EVENT_TYPE_INT:
725 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_INT);
726 proto.write(BinaryLogEntry::Elem::VAL_INT32, (int) elem.data.int32);
727 break;
728 case EVENT_TYPE_LONG:
729 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_LONG);
730 proto.write(BinaryLogEntry::Elem::VAL_INT64, (long long) elem.data.int64);
731 break;
732 case EVENT_TYPE_STRING:
733 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_STRING);
734 proto.write(BinaryLogEntry::Elem::VAL_STRING, elem.data.string, elem.len);
735 break;
736 case EVENT_TYPE_FLOAT:
737 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_FLOAT);
738 proto.write(BinaryLogEntry::Elem::VAL_FLOAT, elem.data.float32);
739 break;
740 case EVENT_TYPE_LIST:
741 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_LIST);
742 break;
743 case EVENT_TYPE_LIST_STOP:
744 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_LIST_STOP);
745 break;
746 case EVENT_TYPE_UNKNOWN:
747 proto.write(BinaryLogEntry::Elem::TYPE, BinaryLogEntry::Elem::EVENT_TYPE_UNKNOWN);
748 break;
749 }
750 proto.end(elemToken);
751 } while ((elem.type != EVENT_TYPE_UNKNOWN) && !elem.complete);
752 proto.end(token);
753 if (context) {
754 android_log_destroy(&context);
755 }
756 } else {
757 AndroidLogEntry entry;
758 err = android_log_processLogBuffer(&msg.entry_v1, &entry);
759 if (err != NO_ERROR) {
760 ALOGE("LogSection %s: fails to process to an entry.\n", this->name.string());
761 break;
762 }
763 lastTimestamp.tv_sec = entry.tv_sec;
764 lastTimestamp.tv_nsec = entry.tv_nsec;
765
766 // format a TextLogEntry
767 long long token = proto.start(LogProto::TEXT_LOGS);
768 proto.write(TextLogEntry::SEC, (long long)entry.tv_sec);
769 proto.write(TextLogEntry::NANOSEC, (long long)entry.tv_nsec);
770 proto.write(TextLogEntry::PRIORITY, (int)entry.priority);
771 proto.write(TextLogEntry::UID, entry.uid);
772 proto.write(TextLogEntry::PID, entry.pid);
773 proto.write(TextLogEntry::TID, entry.tid);
774 proto.write(TextLogEntry::TAG, entry.tag, trimTail(entry.tag, entry.tagLen));
775 proto.write(TextLogEntry::LOG, entry.message, trimTail(entry.message, entry.messageLen));
776 proto.end(token);
777 }
778 }
779 gLastLogsRetrieved[mLogID] = lastTimestamp;
780 proto.flush(pipeWriteFd);
781 return err;
782}