blob: c69e4bd5334cebf59eb2ac577232e64eef8e026d [file] [log] [blame]
Mark Salyzyn0175b072014-02-26 09:50:16 -08001/*
2 * Copyright (C) 2012-2013 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
Mark Salyzynfa3716b2014-02-14 16:05:05 -080017#include <ctype.h>
Mark Salyzynfa3add32016-12-29 07:26:30 -080018#include <inttypes.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080019#include <poll.h>
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070020#include <sys/prctl.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080021#include <sys/socket.h>
Mark Salyzyn5c77ad52016-02-23 08:55:43 -080022#include <sys/types.h>
Mark Salyzyndfc47e82014-03-24 10:26:47 -070023
Tom Cherry68630a02020-05-11 16:29:29 -070024#include <chrono>
25
Tom Cherry283c9a12020-05-14 19:25:05 -070026#include <android-base/stringprintf.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080027#include <cutils/sockets.h>
Tom Cherryd5b38382020-05-12 13:16:41 -070028#include <private/android_filesystem_config.h>
Mark Salyzynaeaaf812016-09-30 13:30:33 -070029#include <private/android_logger.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080030
Mark Salyzyn2ad0bd02016-02-23 08:55:43 -080031#include "LogBuffer.h"
32#include "LogBufferElement.h"
33#include "LogReader.h"
34#include "LogUtils.h"
Tom Cherry283c9a12020-05-14 19:25:05 -070035#include "LogWriter.h"
Mark Salyzyn0175b072014-02-26 09:50:16 -080036
Tom Cherry79d54f72020-05-04 11:13:55 -070037static bool CanReadSecurityLogs(SocketClient* client) {
38 return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;
39}
40
Tom Cherry283c9a12020-05-14 19:25:05 -070041static std::string SocketClientToName(SocketClient* client) {
42 return android::base::StringPrintf("pid %d, fd %d", client->getPid(), client->getSocket());
43}
44
45class SocketLogWriter : public LogWriter {
46 public:
47 SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged,
48 bool can_read_security_logs)
49 : LogWriter(client->getUid(), privileged, can_read_security_logs),
50 reader_(reader),
51 client_(client) {}
52
53 bool Write(const logger_entry& entry, const char* msg) override {
54 struct iovec iovec[2];
55 iovec[0].iov_base = const_cast<logger_entry*>(&entry);
56 iovec[0].iov_len = entry.hdr_size;
57 iovec[1].iov_base = const_cast<char*>(msg);
58 iovec[1].iov_len = entry.len;
59
60 return client_->sendDatav(iovec, 1 + (entry.len != 0)) == 0;
61 }
62
63 void Release() override {
64 reader_->release(client_);
65 client_->decRef();
66 }
67
68 void Shutdown() override { shutdown(client_->getSocket(), SHUT_RDWR); }
69
70 std::string name() const override { return SocketClientToName(client_); }
71
72 private:
73 LogReader* reader_;
74 SocketClient* client_;
75};
76
Tom Cherry68630a02020-05-11 16:29:29 -070077LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list)
78 : SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {}
Mark Salyzyn0175b072014-02-26 09:50:16 -080079
Tom Cherry4f227862018-10-08 17:33:50 -070080// Note returning false will release the SocketClient instance.
Mark Salyzyn501c3732017-03-10 14:31:54 -080081bool LogReader::onDataAvailable(SocketClient* cli) {
Mark Salyzyne3aeeee2015-03-17 07:56:32 -070082 static bool name_set;
83 if (!name_set) {
84 prctl(PR_SET_NAME, "logd.reader");
85 name_set = true;
86 }
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070087
Mark Salyzyn0175b072014-02-26 09:50:16 -080088 char buffer[255];
89
90 int len = read(cli->getSocket(), buffer, sizeof(buffer) - 1);
91 if (len <= 0) {
Tom Cherry283c9a12020-05-14 19:25:05 -070092 DoSocketDelete(cli);
Mark Salyzyn0175b072014-02-26 09:50:16 -080093 return false;
94 }
95 buffer[len] = '\0';
96
Tom Cherry283c9a12020-05-14 19:25:05 -070097 // Clients are only allowed to send one command, disconnect them if they send another.
98 if (DoSocketDelete(cli)) {
99 return false;
Tom Cherry4f227862018-10-08 17:33:50 -0700100 }
Tom Cherry4f227862018-10-08 17:33:50 -0700101
Mark Salyzyn0175b072014-02-26 09:50:16 -0800102 unsigned long tail = 0;
103 static const char _tail[] = " tail=";
Mark Salyzyn501c3732017-03-10 14:31:54 -0800104 char* cp = strstr(buffer, _tail);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800105 if (cp) {
106 tail = atol(cp + sizeof(_tail) - 1);
107 }
108
Mark Salyzynfa3716b2014-02-14 16:05:05 -0800109 log_time start(log_time::EPOCH);
110 static const char _start[] = " start=";
111 cp = strstr(buffer, _start);
112 if (cp) {
113 // Parse errors will result in current time
114 start.strptime(cp + sizeof(_start) - 1, "%s.%q");
115 }
116
Tom Cherry68630a02020-05-11 16:29:29 -0700117 std::chrono::steady_clock::time_point deadline = {};
Mark Salyzynb75cce02015-11-30 11:35:56 -0800118 static const char _timeout[] = " timeout=";
119 cp = strstr(buffer, _timeout);
120 if (cp) {
Tom Cherry68630a02020-05-11 16:29:29 -0700121 long timeout_seconds = atol(cp + sizeof(_timeout) - 1);
122 deadline = std::chrono::steady_clock::now() + std::chrono::seconds(timeout_seconds);
Mark Salyzynb75cce02015-11-30 11:35:56 -0800123 }
124
Mark Salyzyn0175b072014-02-26 09:50:16 -0800125 unsigned int logMask = -1;
126 static const char _logIds[] = " lids=";
127 cp = strstr(buffer, _logIds);
128 if (cp) {
129 logMask = 0;
130 cp += sizeof(_logIds) - 1;
131 while (*cp && *cp != '\0') {
132 int val = 0;
Mark Salyzynfa3716b2014-02-14 16:05:05 -0800133 while (isdigit(*cp)) {
134 val = val * 10 + *cp - '0';
Mark Salyzyn0175b072014-02-26 09:50:16 -0800135 ++cp;
136 }
137 logMask |= 1 << val;
138 if (*cp != ',') {
139 break;
140 }
141 ++cp;
142 }
143 }
144
145 pid_t pid = 0;
146 static const char _pid[] = " pid=";
147 cp = strstr(buffer, _pid);
148 if (cp) {
149 pid = atol(cp + sizeof(_pid) - 1);
150 }
151
152 bool nonBlock = false;
Mark Salyzyn0eeb06b2016-12-02 10:08:48 -0800153 if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) {
Mark Salyzynf669acb2014-09-16 09:19:47 -0700154 // Allow writer to get some cycles, and wait for pending notifications
155 sched_yield();
Tom Cherry68630a02020-05-11 16:29:29 -0700156 reader_list_->reader_threads_lock().lock();
157 reader_list_->reader_threads_lock().unlock();
Mark Salyzynf669acb2014-09-16 09:19:47 -0700158 sched_yield();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800159 nonBlock = true;
160 }
161
Tom Cherry79d54f72020-05-04 11:13:55 -0700162 bool privileged = clientHasLogCredentials(cli);
163 bool can_read_security = CanReadSecurityLogs(cli);
164
Tom Cherry283c9a12020-05-14 19:25:05 -0700165 std::unique_ptr<LogWriter> socket_log_writer(
166 new SocketLogWriter(this, cli, privileged, can_read_security));
167
Tom Cherry10d086e2019-08-21 14:16:34 -0700168 uint64_t sequence = 1;
169 // Convert realtime to sequence number
170 if (start != log_time::EPOCH) {
Tom Cherry320f5962020-05-04 17:25:34 -0700171 bool start_time_set = false;
Tom Cherry320f5962020-05-04 17:25:34 -0700172 uint64_t last = sequence;
Tom Cherryf2c27462020-04-08 14:36:05 -0700173 auto log_find_start = [pid, logMask, start, &sequence, &start_time_set,
Tom Cherry68630a02020-05-11 16:29:29 -0700174 &last](const LogBufferElement* element) -> FlushToResult {
Tom Cherry320f5962020-05-04 17:25:34 -0700175 if (pid && pid != element->getPid()) {
Tom Cherry68630a02020-05-11 16:29:29 -0700176 return FlushToResult::kSkip;
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800177 }
Tom Cherry320f5962020-05-04 17:25:34 -0700178 if ((logMask & (1 << element->getLogId())) == 0) {
Tom Cherry68630a02020-05-11 16:29:29 -0700179 return FlushToResult::kSkip;
Tom Cherry320f5962020-05-04 17:25:34 -0700180 }
181 if (start == element->getRealTime()) {
182 sequence = element->getSequence();
183 start_time_set = true;
Tom Cherry68630a02020-05-11 16:29:29 -0700184 return FlushToResult::kStop;
Tom Cherryf2c27462020-04-08 14:36:05 -0700185 } else {
Tom Cherry320f5962020-05-04 17:25:34 -0700186 if (start < element->getRealTime()) {
187 sequence = last;
188 start_time_set = true;
Tom Cherry68630a02020-05-11 16:29:29 -0700189 return FlushToResult::kStop;
Tom Cherry320f5962020-05-04 17:25:34 -0700190 }
191 last = element->getSequence();
Tom Cherry320f5962020-05-04 17:25:34 -0700192 }
Tom Cherry68630a02020-05-11 16:29:29 -0700193 return FlushToResult::kSkip;
Tom Cherry320f5962020-05-04 17:25:34 -0700194 };
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800195
Tom Cherry283c9a12020-05-14 19:25:05 -0700196 log_buffer_->FlushTo(socket_log_writer.get(), sequence, nullptr, log_find_start);
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800197
Tom Cherry320f5962020-05-04 17:25:34 -0700198 if (!start_time_set) {
Tom Cherry10d086e2019-08-21 14:16:34 -0700199 if (nonBlock) {
Tom Cherry10d086e2019-08-21 14:16:34 -0700200 return false;
201 }
202 sequence = LogBufferElement::getCurrentSequence();
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800203 }
Mark Salyzynfa3716b2014-02-14 16:05:05 -0800204 }
205
Mark Salyzynfa3add32016-12-29 07:26:30 -0800206 android::prdebug(
Tom Cherry10d086e2019-08-21 14:16:34 -0700207 "logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d "
Tom Cherry68630a02020-05-11 16:29:29 -0700208 "start=%" PRIu64 "ns deadline=%" PRIi64 "ns\n",
Tom Cherry10d086e2019-08-21 14:16:34 -0700209 cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask,
Tom Cherry68630a02020-05-11 16:29:29 -0700210 (int)pid, start.nsec(), static_cast<int64_t>(deadline.time_since_epoch().count()));
Mark Salyzynfa3add32016-12-29 07:26:30 -0800211
Tom Cherry10d086e2019-08-21 14:16:34 -0700212 if (start == log_time::EPOCH) {
Tom Cherry68630a02020-05-11 16:29:29 -0700213 deadline = {};
Tom Cherrye2d30d12018-10-19 13:51:35 -0700214 }
215
Tom Cherry68630a02020-05-11 16:29:29 -0700216 auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
Tom Cherry283c9a12020-05-14 19:25:05 -0700217 auto entry = std::make_unique<LogReaderThread>(log_buffer_, reader_list_,
218 std::move(socket_log_writer), nonBlock, tail,
219 logMask, pid, start, sequence, deadline);
Tom Cherry4f227862018-10-08 17:33:50 -0700220 // release client and entry reference counts once done
221 cli->incRef();
Tom Cherry68630a02020-05-11 16:29:29 -0700222 reader_list_->reader_threads().emplace_front(std::move(entry));
Mark Salyzyn5c77ad52016-02-23 08:55:43 -0800223
224 // Set acceptable upper limit to wait for slow reader processing b/27242723
225 struct timeval t = { LOGD_SNDTIMEO, 0 };
Mark Salyzyn501c3732017-03-10 14:31:54 -0800226 setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t,
227 sizeof(t));
Mark Salyzyn5c77ad52016-02-23 08:55:43 -0800228
Mark Salyzyn0175b072014-02-26 09:50:16 -0800229 return true;
230}
231
Tom Cherry283c9a12020-05-14 19:25:05 -0700232bool LogReader::DoSocketDelete(SocketClient* cli) {
233 auto cli_name = SocketClientToName(cli);
Tom Cherry68630a02020-05-11 16:29:29 -0700234 auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
Tom Cherry283c9a12020-05-14 19:25:05 -0700235 for (const auto& reader : reader_list_->reader_threads()) {
236 if (reader->name() == cli_name) {
237 reader->release_Locked();
238 return true;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800239 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800240 }
Tom Cherry283c9a12020-05-14 19:25:05 -0700241 return false;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800242}
Mark Salyzyndfc47e82014-03-24 10:26:47 -0700243
244int LogReader::getLogSocket() {
245 static const char socketName[] = "logdr";
246 int sock = android_get_control_socket(socketName);
247
248 if (sock < 0) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800249 sock = socket_local_server(
250 socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET);
Mark Salyzyndfc47e82014-03-24 10:26:47 -0700251 }
252
253 return sock;
254}