Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 1 | /* |
| 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 Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 17 | #include <ctype.h> |
Mark Salyzyn | fa3add3 | 2016-12-29 07:26:30 -0800 | [diff] [blame] | 18 | #include <inttypes.h> |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 19 | #include <poll.h> |
Mark Salyzyn | 8daa9af | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 20 | #include <sys/prctl.h> |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 21 | #include <sys/socket.h> |
Mark Salyzyn | 5c77ad5 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 22 | #include <sys/types.h> |
Mark Salyzyn | dfc47e8 | 2014-03-24 10:26:47 -0700 | [diff] [blame] | 23 | |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 24 | #include <chrono> |
| 25 | |
Tom Cherry | f93b400 | 2020-06-03 09:23:49 -0700 | [diff] [blame] | 26 | #include <android-base/logging.h> |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 27 | #include <android-base/stringprintf.h> |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 28 | #include <cutils/sockets.h> |
Tom Cherry | d5b3838 | 2020-05-12 13:16:41 -0700 | [diff] [blame] | 29 | #include <private/android_filesystem_config.h> |
Mark Salyzyn | aeaaf81 | 2016-09-30 13:30:33 -0700 | [diff] [blame] | 30 | #include <private/android_logger.h> |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 31 | |
Mark Salyzyn | 2ad0bd0 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 32 | #include "LogBuffer.h" |
| 33 | #include "LogBufferElement.h" |
Tom Cherry | 4e9bf95 | 2020-05-15 10:13:38 -0700 | [diff] [blame] | 34 | #include "LogPermissions.h" |
Mark Salyzyn | 2ad0bd0 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 35 | #include "LogReader.h" |
| 36 | #include "LogUtils.h" |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 37 | #include "LogWriter.h" |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 38 | |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame] | 39 | static bool CanReadSecurityLogs(SocketClient* client) { |
| 40 | return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM; |
| 41 | } |
| 42 | |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 43 | static std::string SocketClientToName(SocketClient* client) { |
| 44 | return android::base::StringPrintf("pid %d, fd %d", client->getPid(), client->getSocket()); |
| 45 | } |
| 46 | |
| 47 | class SocketLogWriter : public LogWriter { |
| 48 | public: |
Tom Cherry | eb49b04 | 2020-05-28 21:03:43 -0700 | [diff] [blame] | 49 | SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged) |
| 50 | : LogWriter(client->getUid(), privileged), reader_(reader), client_(client) {} |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 51 | |
| 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 Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 76 | LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list) |
| 77 | : SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {} |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 78 | |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 79 | // Note returning false will release the SocketClient instance. |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 80 | bool LogReader::onDataAvailable(SocketClient* cli) { |
Mark Salyzyn | e3aeeee | 2015-03-17 07:56:32 -0700 | [diff] [blame] | 81 | static bool name_set; |
| 82 | if (!name_set) { |
| 83 | prctl(PR_SET_NAME, "logd.reader"); |
| 84 | name_set = true; |
| 85 | } |
Mark Salyzyn | 8daa9af | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 86 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 87 | char buffer[255]; |
| 88 | |
| 89 | int len = read(cli->getSocket(), buffer, sizeof(buffer) - 1); |
| 90 | if (len <= 0) { |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 91 | DoSocketDelete(cli); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 92 | return false; |
| 93 | } |
| 94 | buffer[len] = '\0'; |
| 95 | |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 96 | // Clients are only allowed to send one command, disconnect them if they send another. |
| 97 | if (DoSocketDelete(cli)) { |
| 98 | return false; |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 99 | } |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 100 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 101 | unsigned long tail = 0; |
| 102 | static const char _tail[] = " tail="; |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 103 | char* cp = strstr(buffer, _tail); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 104 | if (cp) { |
| 105 | tail = atol(cp + sizeof(_tail) - 1); |
| 106 | } |
| 107 | |
Mark Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 108 | 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 Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 116 | std::chrono::steady_clock::time_point deadline = {}; |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 117 | static const char _timeout[] = " timeout="; |
| 118 | cp = strstr(buffer, _timeout); |
| 119 | if (cp) { |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 120 | long timeout_seconds = atol(cp + sizeof(_timeout) - 1); |
| 121 | deadline = std::chrono::steady_clock::now() + std::chrono::seconds(timeout_seconds); |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 122 | } |
| 123 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 124 | 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 Cherry | 9b4246d | 2020-06-17 11:40:55 -0700 | [diff] [blame] | 130 | while (*cp != '\0') { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 131 | int val = 0; |
Mark Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 132 | while (isdigit(*cp)) { |
| 133 | val = val * 10 + *cp - '0'; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 134 | ++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 Salyzyn | 0eeb06b | 2016-12-02 10:08:48 -0800 | [diff] [blame] | 152 | if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) { |
Mark Salyzyn | f669acb | 2014-09-16 09:19:47 -0700 | [diff] [blame] | 153 | // Allow writer to get some cycles, and wait for pending notifications |
| 154 | sched_yield(); |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 155 | reader_list_->reader_threads_lock().lock(); |
| 156 | reader_list_->reader_threads_lock().unlock(); |
Mark Salyzyn | f669acb | 2014-09-16 09:19:47 -0700 | [diff] [blame] | 157 | sched_yield(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 158 | nonBlock = true; |
| 159 | } |
| 160 | |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame] | 161 | bool privileged = clientHasLogCredentials(cli); |
| 162 | bool can_read_security = CanReadSecurityLogs(cli); |
Tom Cherry | eb49b04 | 2020-05-28 21:03:43 -0700 | [diff] [blame] | 163 | if (!can_read_security) { |
| 164 | logMask &= ~(1 << LOG_ID_SECURITY); |
| 165 | } |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame] | 166 | |
Tom Cherry | eb49b04 | 2020-05-28 21:03:43 -0700 | [diff] [blame] | 167 | std::unique_ptr<LogWriter> socket_log_writer(new SocketLogWriter(this, cli, privileged)); |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 168 | |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 169 | uint64_t sequence = 1; |
| 170 | // Convert realtime to sequence number |
| 171 | if (start != log_time::EPOCH) { |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 172 | bool start_time_set = false; |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 173 | uint64_t last = sequence; |
Tom Cherry | 855c7c8 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 174 | auto log_find_start = [pid, start, &sequence, &start_time_set, &last]( |
| 175 | log_id_t, pid_t element_pid, uint64_t element_sequence, |
Tom Cherry | b3e1633 | 2020-05-28 20:02:42 -0700 | [diff] [blame] | 176 | log_time element_realtime) -> FilterResult { |
Tom Cherry | 70fadea | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 177 | if (pid && pid != element_pid) { |
Tom Cherry | 3e61a13 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 178 | return FilterResult::kSkip; |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 179 | } |
Tom Cherry | 70fadea | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 180 | if (start == element_realtime) { |
| 181 | sequence = element_sequence; |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 182 | start_time_set = true; |
Tom Cherry | 3e61a13 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 183 | return FilterResult::kStop; |
Tom Cherry | f2c2746 | 2020-04-08 14:36:05 -0700 | [diff] [blame] | 184 | } else { |
Tom Cherry | 70fadea | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 185 | if (start < element_realtime) { |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 186 | sequence = last; |
| 187 | start_time_set = true; |
Tom Cherry | 3e61a13 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 188 | return FilterResult::kStop; |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 189 | } |
Tom Cherry | 70fadea | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 190 | last = element_sequence; |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 191 | } |
Tom Cherry | 3e61a13 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 192 | return FilterResult::kSkip; |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 193 | }; |
Tom Cherry | 855c7c8 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 194 | auto flush_to_state = log_buffer_->CreateFlushToState(sequence, logMask); |
| 195 | log_buffer_->FlushTo(socket_log_writer.get(), *flush_to_state, log_find_start); |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 196 | |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 197 | if (!start_time_set) { |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 198 | if (nonBlock) { |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 199 | return false; |
| 200 | } |
Tom Cherry | a3c5ff5 | 2020-05-21 13:56:33 -0700 | [diff] [blame] | 201 | sequence = log_buffer_->sequence(); |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 202 | } |
Mark Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 203 | } |
| 204 | |
Tom Cherry | f93b400 | 2020-06-03 09:23:49 -0700 | [diff] [blame] | 205 | LOG(INFO) << android::base::StringPrintf( |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 206 | "logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d " |
Tom Cherry | f93b400 | 2020-06-03 09:23:49 -0700 | [diff] [blame] | 207 | "start=%" PRIu64 "ns deadline=%" PRIi64 "ns", |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 208 | cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask, |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 209 | (int)pid, start.nsec(), static_cast<int64_t>(deadline.time_since_epoch().count())); |
Mark Salyzyn | fa3add3 | 2016-12-29 07:26:30 -0800 | [diff] [blame] | 210 | |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 211 | if (start == log_time::EPOCH) { |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 212 | deadline = {}; |
Tom Cherry | e2d30d1 | 2018-10-19 13:51:35 -0700 | [diff] [blame] | 213 | } |
| 214 | |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 215 | auto lock = std::lock_guard{reader_list_->reader_threads_lock()}; |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 216 | 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 Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 219 | // release client and entry reference counts once done |
| 220 | cli->incRef(); |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 221 | reader_list_->reader_threads().emplace_front(std::move(entry)); |
Mark Salyzyn | 5c77ad5 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 222 | |
| 223 | // Set acceptable upper limit to wait for slow reader processing b/27242723 |
| 224 | struct timeval t = { LOGD_SNDTIMEO, 0 }; |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 225 | setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t, |
| 226 | sizeof(t)); |
Mark Salyzyn | 5c77ad5 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 227 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 228 | return true; |
| 229 | } |
| 230 | |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 231 | bool LogReader::DoSocketDelete(SocketClient* cli) { |
| 232 | auto cli_name = SocketClientToName(cli); |
Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 233 | auto lock = std::lock_guard{reader_list_->reader_threads_lock()}; |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 234 | for (const auto& reader : reader_list_->reader_threads()) { |
| 235 | if (reader->name() == cli_name) { |
| 236 | reader->release_Locked(); |
| 237 | return true; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 238 | } |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 239 | } |
Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 240 | return false; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 241 | } |
Mark Salyzyn | dfc47e8 | 2014-03-24 10:26:47 -0700 | [diff] [blame] | 242 | |
| 243 | int LogReader::getLogSocket() { |
| 244 | static const char socketName[] = "logdr"; |
| 245 | int sock = android_get_control_socket(socketName); |
| 246 | |
| 247 | if (sock < 0) { |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 248 | sock = socket_local_server( |
| 249 | socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET); |
Mark Salyzyn | dfc47e8 | 2014-03-24 10:26:47 -0700 | [diff] [blame] | 250 | } |
| 251 | |
| 252 | return sock; |
| 253 | } |