blob: 6c976931fff08f10a8a278960e0f05227d70311d [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 Cherryf93b4002020-06-03 09:23:49 -070026#include <android-base/logging.h>
Tom Cherry283c9a12020-05-14 19:25:05 -070027#include <android-base/stringprintf.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080028#include <cutils/sockets.h>
Tom Cherryd5b38382020-05-12 13:16:41 -070029#include <private/android_filesystem_config.h>
Mark Salyzynaeaaf812016-09-30 13:30:33 -070030#include <private/android_logger.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080031
Mark Salyzyn2ad0bd02016-02-23 08:55:43 -080032#include "LogBuffer.h"
33#include "LogBufferElement.h"
Tom Cherry4e9bf952020-05-15 10:13:38 -070034#include "LogPermissions.h"
Mark Salyzyn2ad0bd02016-02-23 08:55:43 -080035#include "LogReader.h"
36#include "LogUtils.h"
Tom Cherry283c9a12020-05-14 19:25:05 -070037#include "LogWriter.h"
Mark Salyzyn0175b072014-02-26 09:50:16 -080038
Tom Cherry79d54f72020-05-04 11:13:55 -070039static bool CanReadSecurityLogs(SocketClient* client) {
40 return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;
41}
42
Tom Cherry283c9a12020-05-14 19:25:05 -070043static std::string SocketClientToName(SocketClient* client) {
44 return android::base::StringPrintf("pid %d, fd %d", client->getPid(), client->getSocket());
45}
46
47class SocketLogWriter : public LogWriter {
48 public:
Tom Cherryeb49b042020-05-28 21:03:43 -070049 SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged)
50 : LogWriter(client->getUid(), privileged), reader_(reader), client_(client) {}
Tom Cherry283c9a12020-05-14 19:25:05 -070051
52 bool Write(const logger_entry& entry, const char* msg) override {
53 struct iovec iovec[2];
54 iovec[0].iov_base = const_cast<logger_entry*>(&entry);
55 iovec[0].iov_len = entry.hdr_size;
56 iovec[1].iov_base = const_cast<char*>(msg);
57 iovec[1].iov_len = entry.len;
58
59 return client_->sendDatav(iovec, 1 + (entry.len != 0)) == 0;
60 }
61
62 void Release() override {
63 reader_->release(client_);
64 client_->decRef();
65 }
66
67 void Shutdown() override { shutdown(client_->getSocket(), SHUT_RDWR); }
68
69 std::string name() const override { return SocketClientToName(client_); }
70
71 private:
72 LogReader* reader_;
73 SocketClient* client_;
74};
75
Tom Cherry68630a02020-05-11 16:29:29 -070076LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list)
77 : SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {}
Mark Salyzyn0175b072014-02-26 09:50:16 -080078
Tom Cherry4f227862018-10-08 17:33:50 -070079// Note returning false will release the SocketClient instance.
Mark Salyzyn501c3732017-03-10 14:31:54 -080080bool LogReader::onDataAvailable(SocketClient* cli) {
Mark Salyzyne3aeeee2015-03-17 07:56:32 -070081 static bool name_set;
82 if (!name_set) {
83 prctl(PR_SET_NAME, "logd.reader");
84 name_set = true;
85 }
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070086
Mark Salyzyn0175b072014-02-26 09:50:16 -080087 char buffer[255];
88
89 int len = read(cli->getSocket(), buffer, sizeof(buffer) - 1);
90 if (len <= 0) {
Tom Cherry283c9a12020-05-14 19:25:05 -070091 DoSocketDelete(cli);
Mark Salyzyn0175b072014-02-26 09:50:16 -080092 return false;
93 }
94 buffer[len] = '\0';
95
Tom Cherry283c9a12020-05-14 19:25:05 -070096 // Clients are only allowed to send one command, disconnect them if they send another.
97 if (DoSocketDelete(cli)) {
98 return false;
Tom Cherry4f227862018-10-08 17:33:50 -070099 }
Tom Cherry4f227862018-10-08 17:33:50 -0700100
Mark Salyzyn0175b072014-02-26 09:50:16 -0800101 unsigned long tail = 0;
102 static const char _tail[] = " tail=";
Mark Salyzyn501c3732017-03-10 14:31:54 -0800103 char* cp = strstr(buffer, _tail);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800104 if (cp) {
105 tail = atol(cp + sizeof(_tail) - 1);
106 }
107
Mark Salyzynfa3716b2014-02-14 16:05:05 -0800108 log_time start(log_time::EPOCH);
109 static const char _start[] = " start=";
110 cp = strstr(buffer, _start);
111 if (cp) {
112 // Parse errors will result in current time
113 start.strptime(cp + sizeof(_start) - 1, "%s.%q");
114 }
115
Tom Cherry68630a02020-05-11 16:29:29 -0700116 std::chrono::steady_clock::time_point deadline = {};
Mark Salyzynb75cce02015-11-30 11:35:56 -0800117 static const char _timeout[] = " timeout=";
118 cp = strstr(buffer, _timeout);
119 if (cp) {
Tom Cherry68630a02020-05-11 16:29:29 -0700120 long timeout_seconds = atol(cp + sizeof(_timeout) - 1);
121 deadline = std::chrono::steady_clock::now() + std::chrono::seconds(timeout_seconds);
Mark Salyzynb75cce02015-11-30 11:35:56 -0800122 }
123
Mark Salyzyn0175b072014-02-26 09:50:16 -0800124 unsigned int logMask = -1;
125 static const char _logIds[] = " lids=";
126 cp = strstr(buffer, _logIds);
127 if (cp) {
128 logMask = 0;
129 cp += sizeof(_logIds) - 1;
Tom Cherry9b4246d2020-06-17 11:40:55 -0700130 while (*cp != '\0') {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800131 int val = 0;
Mark Salyzynfa3716b2014-02-14 16:05:05 -0800132 while (isdigit(*cp)) {
133 val = val * 10 + *cp - '0';
Mark Salyzyn0175b072014-02-26 09:50:16 -0800134 ++cp;
135 }
136 logMask |= 1 << val;
137 if (*cp != ',') {
138 break;
139 }
140 ++cp;
141 }
142 }
143
144 pid_t pid = 0;
145 static const char _pid[] = " pid=";
146 cp = strstr(buffer, _pid);
147 if (cp) {
148 pid = atol(cp + sizeof(_pid) - 1);
149 }
150
151 bool nonBlock = false;
Mark Salyzyn0eeb06b2016-12-02 10:08:48 -0800152 if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) {
Mark Salyzynf669acb2014-09-16 09:19:47 -0700153 // Allow writer to get some cycles, and wait for pending notifications
154 sched_yield();
Tom Cherry68630a02020-05-11 16:29:29 -0700155 reader_list_->reader_threads_lock().lock();
156 reader_list_->reader_threads_lock().unlock();
Mark Salyzynf669acb2014-09-16 09:19:47 -0700157 sched_yield();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800158 nonBlock = true;
159 }
160
Tom Cherry79d54f72020-05-04 11:13:55 -0700161 bool privileged = clientHasLogCredentials(cli);
162 bool can_read_security = CanReadSecurityLogs(cli);
Tom Cherryeb49b042020-05-28 21:03:43 -0700163 if (!can_read_security) {
164 logMask &= ~(1 << LOG_ID_SECURITY);
165 }
Tom Cherry79d54f72020-05-04 11:13:55 -0700166
Tom Cherryeb49b042020-05-28 21:03:43 -0700167 std::unique_ptr<LogWriter> socket_log_writer(new SocketLogWriter(this, cli, privileged));
Tom Cherry283c9a12020-05-14 19:25:05 -0700168
Tom Cherry10d086e2019-08-21 14:16:34 -0700169 uint64_t sequence = 1;
170 // Convert realtime to sequence number
171 if (start != log_time::EPOCH) {
Tom Cherry320f5962020-05-04 17:25:34 -0700172 bool start_time_set = false;
Tom Cherry320f5962020-05-04 17:25:34 -0700173 uint64_t last = sequence;
Tom Cherry855c7c82020-05-28 12:38:21 -0700174 auto log_find_start = [pid, start, &sequence, &start_time_set, &last](
175 log_id_t, pid_t element_pid, uint64_t element_sequence,
Tom Cherryb3e16332020-05-28 20:02:42 -0700176 log_time element_realtime) -> FilterResult {
Tom Cherry70fadea2020-05-27 14:43:19 -0700177 if (pid && pid != element_pid) {
Tom Cherry3e61a132020-05-27 10:46:37 -0700178 return FilterResult::kSkip;
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800179 }
Tom Cherry70fadea2020-05-27 14:43:19 -0700180 if (start == element_realtime) {
181 sequence = element_sequence;
Tom Cherry320f5962020-05-04 17:25:34 -0700182 start_time_set = true;
Tom Cherry3e61a132020-05-27 10:46:37 -0700183 return FilterResult::kStop;
Tom Cherryf2c27462020-04-08 14:36:05 -0700184 } else {
Tom Cherry70fadea2020-05-27 14:43:19 -0700185 if (start < element_realtime) {
Tom Cherry320f5962020-05-04 17:25:34 -0700186 sequence = last;
187 start_time_set = true;
Tom Cherry3e61a132020-05-27 10:46:37 -0700188 return FilterResult::kStop;
Tom Cherry320f5962020-05-04 17:25:34 -0700189 }
Tom Cherry70fadea2020-05-27 14:43:19 -0700190 last = element_sequence;
Tom Cherry320f5962020-05-04 17:25:34 -0700191 }
Tom Cherry3e61a132020-05-27 10:46:37 -0700192 return FilterResult::kSkip;
Tom Cherry320f5962020-05-04 17:25:34 -0700193 };
Tom Cherry855c7c82020-05-28 12:38:21 -0700194 auto flush_to_state = log_buffer_->CreateFlushToState(sequence, logMask);
195 log_buffer_->FlushTo(socket_log_writer.get(), *flush_to_state, log_find_start);
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800196
Tom Cherry320f5962020-05-04 17:25:34 -0700197 if (!start_time_set) {
Tom Cherry10d086e2019-08-21 14:16:34 -0700198 if (nonBlock) {
Tom Cherry10d086e2019-08-21 14:16:34 -0700199 return false;
200 }
Tom Cherrya3c5ff52020-05-21 13:56:33 -0700201 sequence = log_buffer_->sequence();
Mark Salyzyna1c60cf2014-02-19 07:33:12 -0800202 }
Mark Salyzynfa3716b2014-02-14 16:05:05 -0800203 }
204
Tom Cherryf93b4002020-06-03 09:23:49 -0700205 LOG(INFO) << android::base::StringPrintf(
Tom Cherry10d086e2019-08-21 14:16:34 -0700206 "logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d "
Tom Cherryf93b4002020-06-03 09:23:49 -0700207 "start=%" PRIu64 "ns deadline=%" PRIi64 "ns",
Tom Cherry10d086e2019-08-21 14:16:34 -0700208 cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask,
Tom Cherry68630a02020-05-11 16:29:29 -0700209 (int)pid, start.nsec(), static_cast<int64_t>(deadline.time_since_epoch().count()));
Mark Salyzynfa3add32016-12-29 07:26:30 -0800210
Tom Cherry10d086e2019-08-21 14:16:34 -0700211 if (start == log_time::EPOCH) {
Tom Cherry68630a02020-05-11 16:29:29 -0700212 deadline = {};
Tom Cherrye2d30d12018-10-19 13:51:35 -0700213 }
214
Tom Cherry68630a02020-05-11 16:29:29 -0700215 auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
Tom Cherry283c9a12020-05-14 19:25:05 -0700216 auto entry = std::make_unique<LogReaderThread>(log_buffer_, reader_list_,
217 std::move(socket_log_writer), nonBlock, tail,
218 logMask, pid, start, sequence, deadline);
Tom Cherry4f227862018-10-08 17:33:50 -0700219 // release client and entry reference counts once done
220 cli->incRef();
Tom Cherry68630a02020-05-11 16:29:29 -0700221 reader_list_->reader_threads().emplace_front(std::move(entry));
Mark Salyzyn5c77ad52016-02-23 08:55:43 -0800222
223 // Set acceptable upper limit to wait for slow reader processing b/27242723
224 struct timeval t = { LOGD_SNDTIMEO, 0 };
Mark Salyzyn501c3732017-03-10 14:31:54 -0800225 setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t,
226 sizeof(t));
Mark Salyzyn5c77ad52016-02-23 08:55:43 -0800227
Mark Salyzyn0175b072014-02-26 09:50:16 -0800228 return true;
229}
230
Tom Cherry283c9a12020-05-14 19:25:05 -0700231bool LogReader::DoSocketDelete(SocketClient* cli) {
232 auto cli_name = SocketClientToName(cli);
Tom Cherry68630a02020-05-11 16:29:29 -0700233 auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
Tom Cherry283c9a12020-05-14 19:25:05 -0700234 for (const auto& reader : reader_list_->reader_threads()) {
235 if (reader->name() == cli_name) {
236 reader->release_Locked();
237 return true;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800238 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800239 }
Tom Cherry283c9a12020-05-14 19:25:05 -0700240 return false;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800241}
Mark Salyzyndfc47e82014-03-24 10:26:47 -0700242
243int LogReader::getLogSocket() {
244 static const char socketName[] = "logdr";
245 int sock = android_get_control_socket(socketName);
246
247 if (sock < 0) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800248 sock = socket_local_server(
249 socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET);
Mark Salyzyndfc47e82014-03-24 10:26:47 -0700250 }
251
252 return sock;
253}