blob: 1c6a85f1687135f00bf6bca0e2664d91a5873d2f [file] [log] [blame]
Mark Salyzyn12bac902014-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 Salyzyn9addf592014-02-14 16:05:05 -080017#include <ctype.h>
Mark Salyzynbe90ba42016-12-29 07:26:30 -080018#include <inttypes.h>
Mark Salyzyn12bac902014-02-26 09:50:16 -080019#include <poll.h>
Tom Cherryc5c9eba2020-10-06 10:22:35 -070020#include <sched.h>
Mark Salyzyn4e5efdc2014-04-28 14:07:23 -070021#include <sys/prctl.h>
Mark Salyzyn12bac902014-02-26 09:50:16 -080022#include <sys/socket.h>
Mark Salyzyn2296d332016-02-23 08:55:43 -080023#include <sys/types.h>
Mark Salyzyn3f6151e2014-03-24 10:26:47 -070024
Tom Cherry5ecfbf02020-05-11 16:29:29 -070025#include <chrono>
26
Tom Cherry7e12f592020-06-03 09:23:49 -070027#include <android-base/logging.h>
Tom Cherryadf2e442020-05-14 19:25:05 -070028#include <android-base/stringprintf.h>
Mark Salyzyn12bac902014-02-26 09:50:16 -080029#include <cutils/sockets.h>
Tom Cherry0281b202020-05-12 13:16:41 -070030#include <private/android_filesystem_config.h>
Mark Salyzyn8b8bfd22016-09-30 13:30:33 -070031#include <private/android_logger.h>
Mark Salyzyn12bac902014-02-26 09:50:16 -080032
Mark Salyzyn1d21d542016-02-23 08:55:43 -080033#include "LogBuffer.h"
34#include "LogBufferElement.h"
Tom Cherry134096f2020-05-15 10:13:38 -070035#include "LogPermissions.h"
Mark Salyzyn1d21d542016-02-23 08:55:43 -080036#include "LogReader.h"
37#include "LogUtils.h"
Tom Cherryadf2e442020-05-14 19:25:05 -070038#include "LogWriter.h"
Mark Salyzyn12bac902014-02-26 09:50:16 -080039
Tom Cherry3086c182020-05-04 11:13:55 -070040static bool CanReadSecurityLogs(SocketClient* client) {
41 return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;
42}
43
Tom Cherryadf2e442020-05-14 19:25:05 -070044static std::string SocketClientToName(SocketClient* client) {
45 return android::base::StringPrintf("pid %d, fd %d", client->getPid(), client->getSocket());
46}
47
48class SocketLogWriter : public LogWriter {
49 public:
Tom Cherry106b3a32020-05-28 21:03:43 -070050 SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged)
51 : LogWriter(client->getUid(), privileged), reader_(reader), client_(client) {}
Tom Cherryadf2e442020-05-14 19:25:05 -070052
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 Cherry5ecfbf02020-05-11 16:29:29 -070077LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list)
78 : SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {}
Mark Salyzyn12bac902014-02-26 09:50:16 -080079
Tom Cherry06e478b2018-10-08 17:33:50 -070080// Note returning false will release the SocketClient instance.
Mark Salyzyn65059532017-03-10 14:31:54 -080081bool LogReader::onDataAvailable(SocketClient* cli) {
Mark Salyzynb4853952015-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 Salyzyn4e5efdc2014-04-28 14:07:23 -070087
Mark Salyzyn12bac902014-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 Cherryadf2e442020-05-14 19:25:05 -070092 DoSocketDelete(cli);
Mark Salyzyn12bac902014-02-26 09:50:16 -080093 return false;
94 }
95 buffer[len] = '\0';
96
Tom Cherryadf2e442020-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 Cherry06e478b2018-10-08 17:33:50 -0700100 }
Tom Cherry06e478b2018-10-08 17:33:50 -0700101
Mark Salyzyn12bac902014-02-26 09:50:16 -0800102 unsigned long tail = 0;
103 static const char _tail[] = " tail=";
Mark Salyzyn65059532017-03-10 14:31:54 -0800104 char* cp = strstr(buffer, _tail);
Mark Salyzyn12bac902014-02-26 09:50:16 -0800105 if (cp) {
106 tail = atol(cp + sizeof(_tail) - 1);
107 }
108
Mark Salyzyn9addf592014-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 Cherry5ecfbf02020-05-11 16:29:29 -0700117 std::chrono::steady_clock::time_point deadline = {};
Mark Salyzync959c642015-11-30 11:35:56 -0800118 static const char _timeout[] = " timeout=";
119 cp = strstr(buffer, _timeout);
120 if (cp) {
Tom Cherry5ecfbf02020-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 Salyzync959c642015-11-30 11:35:56 -0800123 }
124
Mark Salyzyn12bac902014-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;
Tom Cherry17b77582020-06-17 11:40:55 -0700131 while (*cp != '\0') {
Mark Salyzyn12bac902014-02-26 09:50:16 -0800132 int val = 0;
Mark Salyzyn9addf592014-02-14 16:05:05 -0800133 while (isdigit(*cp)) {
134 val = val * 10 + *cp - '0';
Mark Salyzyn12bac902014-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 Salyzyn3eeec052016-12-02 10:08:48 -0800153 if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) {
Mark Salyzyn1f068e92014-09-16 09:19:47 -0700154 // Allow writer to get some cycles, and wait for pending notifications
155 sched_yield();
Tom Cherryc5c9eba2020-10-06 10:22:35 -0700156 logd_lock.lock();
157 logd_lock.unlock();
Mark Salyzyn1f068e92014-09-16 09:19:47 -0700158 sched_yield();
Mark Salyzyn12bac902014-02-26 09:50:16 -0800159 nonBlock = true;
160 }
161
Tom Cherry3086c182020-05-04 11:13:55 -0700162 bool privileged = clientHasLogCredentials(cli);
163 bool can_read_security = CanReadSecurityLogs(cli);
Tom Cherry106b3a32020-05-28 21:03:43 -0700164 if (!can_read_security) {
165 logMask &= ~(1 << LOG_ID_SECURITY);
166 }
Tom Cherry3086c182020-05-04 11:13:55 -0700167
Tom Cherry106b3a32020-05-28 21:03:43 -0700168 std::unique_ptr<LogWriter> socket_log_writer(new SocketLogWriter(this, cli, privileged));
Tom Cherryadf2e442020-05-14 19:25:05 -0700169
Tom Cherryac228f12019-08-21 14:16:34 -0700170 uint64_t sequence = 1;
171 // Convert realtime to sequence number
172 if (start != log_time::EPOCH) {
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700173 bool start_time_set = false;
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700174 uint64_t last = sequence;
Tom Cherryd444ab42020-05-28 12:38:21 -0700175 auto log_find_start = [pid, start, &sequence, &start_time_set, &last](
176 log_id_t, pid_t element_pid, uint64_t element_sequence,
Tom Cherryca4b25d2020-05-28 20:02:42 -0700177 log_time element_realtime) -> FilterResult {
Tom Cherrybaa25a22020-05-27 14:43:19 -0700178 if (pid && pid != element_pid) {
Tom Cherryc92cbf62020-05-27 10:46:37 -0700179 return FilterResult::kSkip;
Mark Salyzyn69459632014-02-19 07:33:12 -0800180 }
Tom Cherrybaa25a22020-05-27 14:43:19 -0700181 if (start == element_realtime) {
182 sequence = element_sequence;
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700183 start_time_set = true;
Tom Cherryc92cbf62020-05-27 10:46:37 -0700184 return FilterResult::kStop;
Tom Cherrya5ff7ae2020-04-08 14:36:05 -0700185 } else {
Tom Cherrybaa25a22020-05-27 14:43:19 -0700186 if (start < element_realtime) {
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700187 sequence = last;
188 start_time_set = true;
Tom Cherryc92cbf62020-05-27 10:46:37 -0700189 return FilterResult::kStop;
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700190 }
Tom Cherrybaa25a22020-05-27 14:43:19 -0700191 last = element_sequence;
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700192 }
Tom Cherryc92cbf62020-05-27 10:46:37 -0700193 return FilterResult::kSkip;
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700194 };
Tom Cherryc5c9eba2020-10-06 10:22:35 -0700195 auto lock = std::lock_guard{logd_lock};
Tom Cherryd444ab42020-05-28 12:38:21 -0700196 auto flush_to_state = log_buffer_->CreateFlushToState(sequence, logMask);
197 log_buffer_->FlushTo(socket_log_writer.get(), *flush_to_state, log_find_start);
Mark Salyzyn69459632014-02-19 07:33:12 -0800198
Tom Cherrye7c73ef2020-05-04 17:25:34 -0700199 if (!start_time_set) {
Tom Cherryac228f12019-08-21 14:16:34 -0700200 if (nonBlock) {
Tom Cherryac228f12019-08-21 14:16:34 -0700201 return false;
202 }
Tom Cherry0bf66db2020-05-21 13:56:33 -0700203 sequence = log_buffer_->sequence();
Mark Salyzyn69459632014-02-19 07:33:12 -0800204 }
Mark Salyzyn9addf592014-02-14 16:05:05 -0800205 }
206
Tom Cherry7e12f592020-06-03 09:23:49 -0700207 LOG(INFO) << android::base::StringPrintf(
Tom Cherryac228f12019-08-21 14:16:34 -0700208 "logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d "
Tom Cherry7e12f592020-06-03 09:23:49 -0700209 "start=%" PRIu64 "ns deadline=%" PRIi64 "ns",
Tom Cherryac228f12019-08-21 14:16:34 -0700210 cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask,
Tom Cherry5ecfbf02020-05-11 16:29:29 -0700211 (int)pid, start.nsec(), static_cast<int64_t>(deadline.time_since_epoch().count()));
Mark Salyzynbe90ba42016-12-29 07:26:30 -0800212
Tom Cherryac228f12019-08-21 14:16:34 -0700213 if (start == log_time::EPOCH) {
Tom Cherry5ecfbf02020-05-11 16:29:29 -0700214 deadline = {};
Tom Cherry38656ef2018-10-19 13:51:35 -0700215 }
216
Tom Cherryc5c9eba2020-10-06 10:22:35 -0700217 auto lock = std::lock_guard{logd_lock};
Tom Cherryadf2e442020-05-14 19:25:05 -0700218 auto entry = std::make_unique<LogReaderThread>(log_buffer_, reader_list_,
219 std::move(socket_log_writer), nonBlock, tail,
220 logMask, pid, start, sequence, deadline);
Tom Cherry06e478b2018-10-08 17:33:50 -0700221 // release client and entry reference counts once done
222 cli->incRef();
Tom Cherry5ecfbf02020-05-11 16:29:29 -0700223 reader_list_->reader_threads().emplace_front(std::move(entry));
Mark Salyzyn2296d332016-02-23 08:55:43 -0800224
225 // Set acceptable upper limit to wait for slow reader processing b/27242723
226 struct timeval t = { LOGD_SNDTIMEO, 0 };
Mark Salyzyn65059532017-03-10 14:31:54 -0800227 setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t,
228 sizeof(t));
Mark Salyzyn2296d332016-02-23 08:55:43 -0800229
Mark Salyzyn12bac902014-02-26 09:50:16 -0800230 return true;
231}
232
Tom Cherryadf2e442020-05-14 19:25:05 -0700233bool LogReader::DoSocketDelete(SocketClient* cli) {
234 auto cli_name = SocketClientToName(cli);
Tom Cherryc5c9eba2020-10-06 10:22:35 -0700235 auto lock = std::lock_guard{logd_lock};
Tom Cherryadf2e442020-05-14 19:25:05 -0700236 for (const auto& reader : reader_list_->reader_threads()) {
237 if (reader->name() == cli_name) {
Tom Cherryc5c9eba2020-10-06 10:22:35 -0700238 reader->Release();
Tom Cherryadf2e442020-05-14 19:25:05 -0700239 return true;
Mark Salyzyn12bac902014-02-26 09:50:16 -0800240 }
Mark Salyzyn12bac902014-02-26 09:50:16 -0800241 }
Tom Cherryadf2e442020-05-14 19:25:05 -0700242 return false;
Mark Salyzyn12bac902014-02-26 09:50:16 -0800243}
Mark Salyzyn3f6151e2014-03-24 10:26:47 -0700244
245int LogReader::getLogSocket() {
246 static const char socketName[] = "logdr";
247 int sock = android_get_control_socket(socketName);
248
249 if (sock < 0) {
Mark Salyzyn65059532017-03-10 14:31:54 -0800250 sock = socket_local_server(
251 socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET);
Mark Salyzyn3f6151e2014-03-24 10:26:47 -0700252 }
253
254 return sock;
255}