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 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 24 | #include <cutils/sockets.h> |
Mark Salyzyn | aeaaf81 | 2016-09-30 13:30:33 -0700 | [diff] [blame] | 25 | #include <private/android_logger.h> |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 26 | |
Mark Salyzyn | 2ad0bd0 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 27 | #include "LogBuffer.h" |
| 28 | #include "LogBufferElement.h" |
| 29 | #include "LogReader.h" |
| 30 | #include "LogUtils.h" |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 31 | |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame^] | 32 | static bool CanReadSecurityLogs(SocketClient* client) { |
| 33 | return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM; |
| 34 | } |
| 35 | |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 36 | LogReader::LogReader(LogBuffer* logbuf) |
| 37 | : SocketListener(getLogSocket(), true), mLogbuf(*logbuf) { |
Mark Salyzyn | 7718778 | 2015-05-12 15:21:31 -0700 | [diff] [blame] | 38 | } |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 39 | |
| 40 | // When we are notified a new log entry is available, inform |
Hao Wang | f6e2296 | 2017-12-04 14:10:40 +0800 | [diff] [blame] | 41 | // listening sockets who are watching this entry's log id. |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame^] | 42 | void LogReader::notifyNewLog(log_mask_t log_mask) { |
| 43 | LastLogTimes& times = mLogbuf.mTimes; |
| 44 | |
| 45 | LogTimeEntry::wrlock(); |
| 46 | for (const auto& entry : times) { |
| 47 | if (!entry->isWatchingMultiple(log_mask)) { |
| 48 | continue; |
| 49 | } |
| 50 | if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) { |
| 51 | continue; |
| 52 | } |
| 53 | entry->triggerReader_Locked(); |
| 54 | } |
| 55 | LogTimeEntry::unlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 56 | } |
| 57 | |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 58 | // Note returning false will release the SocketClient instance. |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 59 | bool LogReader::onDataAvailable(SocketClient* cli) { |
Mark Salyzyn | e3aeeee | 2015-03-17 07:56:32 -0700 | [diff] [blame] | 60 | static bool name_set; |
| 61 | if (!name_set) { |
| 62 | prctl(PR_SET_NAME, "logd.reader"); |
| 63 | name_set = true; |
| 64 | } |
Mark Salyzyn | 8daa9af | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 65 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 66 | char buffer[255]; |
| 67 | |
| 68 | int len = read(cli->getSocket(), buffer, sizeof(buffer) - 1); |
| 69 | if (len <= 0) { |
| 70 | doSocketDelete(cli); |
| 71 | return false; |
| 72 | } |
| 73 | buffer[len] = '\0'; |
| 74 | |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 75 | // Clients are only allowed to send one command, disconnect them if they |
| 76 | // send another. |
| 77 | LogTimeEntry::wrlock(); |
| 78 | for (const auto& entry : mLogbuf.mTimes) { |
| 79 | if (entry->mClient == cli) { |
| 80 | entry->release_Locked(); |
| 81 | LogTimeEntry::unlock(); |
| 82 | return false; |
| 83 | } |
| 84 | } |
| 85 | LogTimeEntry::unlock(); |
| 86 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 87 | unsigned long tail = 0; |
| 88 | static const char _tail[] = " tail="; |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 89 | char* cp = strstr(buffer, _tail); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 90 | if (cp) { |
| 91 | tail = atol(cp + sizeof(_tail) - 1); |
| 92 | } |
| 93 | |
Mark Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 94 | log_time start(log_time::EPOCH); |
| 95 | static const char _start[] = " start="; |
| 96 | cp = strstr(buffer, _start); |
| 97 | if (cp) { |
| 98 | // Parse errors will result in current time |
| 99 | start.strptime(cp + sizeof(_start) - 1, "%s.%q"); |
| 100 | } |
| 101 | |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 102 | uint64_t timeout = 0; |
| 103 | static const char _timeout[] = " timeout="; |
| 104 | cp = strstr(buffer, _timeout); |
| 105 | if (cp) { |
Tom Cherry | c9fa42c | 2020-04-08 10:37:09 -0700 | [diff] [blame] | 106 | timeout = atol(cp + sizeof(_timeout) - 1) * NS_PER_SEC + log_time(CLOCK_MONOTONIC).nsec(); |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 107 | } |
| 108 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 109 | unsigned int logMask = -1; |
| 110 | static const char _logIds[] = " lids="; |
| 111 | cp = strstr(buffer, _logIds); |
| 112 | if (cp) { |
| 113 | logMask = 0; |
| 114 | cp += sizeof(_logIds) - 1; |
| 115 | while (*cp && *cp != '\0') { |
| 116 | int val = 0; |
Mark Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 117 | while (isdigit(*cp)) { |
| 118 | val = val * 10 + *cp - '0'; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 119 | ++cp; |
| 120 | } |
| 121 | logMask |= 1 << val; |
| 122 | if (*cp != ',') { |
| 123 | break; |
| 124 | } |
| 125 | ++cp; |
| 126 | } |
| 127 | } |
| 128 | |
| 129 | pid_t pid = 0; |
| 130 | static const char _pid[] = " pid="; |
| 131 | cp = strstr(buffer, _pid); |
| 132 | if (cp) { |
| 133 | pid = atol(cp + sizeof(_pid) - 1); |
| 134 | } |
| 135 | |
| 136 | bool nonBlock = false; |
Mark Salyzyn | 0eeb06b | 2016-12-02 10:08:48 -0800 | [diff] [blame] | 137 | if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) { |
Mark Salyzyn | f669acb | 2014-09-16 09:19:47 -0700 | [diff] [blame] | 138 | // Allow writer to get some cycles, and wait for pending notifications |
| 139 | sched_yield(); |
Mark Salyzyn | 3c501b5 | 2017-04-18 14:09:45 -0700 | [diff] [blame] | 140 | LogTimeEntry::wrlock(); |
Mark Salyzyn | f669acb | 2014-09-16 09:19:47 -0700 | [diff] [blame] | 141 | LogTimeEntry::unlock(); |
| 142 | sched_yield(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 143 | nonBlock = true; |
| 144 | } |
| 145 | |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame^] | 146 | bool privileged = clientHasLogCredentials(cli); |
| 147 | bool can_read_security = CanReadSecurityLogs(cli); |
| 148 | |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 149 | uint64_t sequence = 1; |
| 150 | // Convert realtime to sequence number |
| 151 | if (start != log_time::EPOCH) { |
| 152 | class LogFindStart { |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 153 | const pid_t mPid; |
| 154 | const unsigned mLogMask; |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 155 | bool startTimeSet; |
Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 156 | const log_time start; |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 157 | uint64_t& sequence; |
| 158 | uint64_t last; |
| 159 | bool isMonotonic; |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 160 | |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 161 | public: |
Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 162 | LogFindStart(unsigned logMask, pid_t pid, log_time start, uint64_t& sequence, |
Mark Salyzyn | 5a34d6e | 2017-03-10 08:44:14 -0800 | [diff] [blame] | 163 | bool isMonotonic) |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 164 | : mPid(pid), |
| 165 | mLogMask(logMask), |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 166 | startTimeSet(false), |
| 167 | start(start), |
| 168 | sequence(sequence), |
| 169 | last(sequence), |
| 170 | isMonotonic(isMonotonic) {} |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 171 | |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 172 | static int callback(const LogBufferElement* element, void* obj) { |
| 173 | LogFindStart* me = reinterpret_cast<LogFindStart*>(obj); |
| 174 | if ((!me->mPid || (me->mPid == element->getPid())) && |
| 175 | (me->mLogMask & (1 << element->getLogId()))) { |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 176 | if (me->start == element->getRealTime()) { |
| 177 | me->sequence = element->getSequence(); |
| 178 | me->startTimeSet = true; |
Mark Salyzyn | f7c0f75 | 2015-03-03 13:39:37 -0800 | [diff] [blame] | 179 | return -1; |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 180 | } else if (!me->isMonotonic || android::isMonotonic(element->getRealTime())) { |
| 181 | if (me->start < element->getRealTime()) { |
| 182 | me->sequence = me->last; |
| 183 | me->startTimeSet = true; |
Mark Salyzyn | f7c0f75 | 2015-03-03 13:39:37 -0800 | [diff] [blame] | 184 | return -1; |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 185 | } |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 186 | me->last = element->getSequence(); |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 187 | } else { |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 188 | me->last = element->getSequence(); |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 189 | } |
| 190 | } |
| 191 | return false; |
| 192 | } |
| 193 | |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 194 | bool found() { return startTimeSet; } |
| 195 | } logFindStart(logMask, pid, start, sequence, |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 196 | logbuf().isMonotonic() && android::isMonotonic(start)); |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 197 | |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame^] | 198 | logbuf().flushTo(cli, sequence, nullptr, privileged, can_read_security, |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 199 | logFindStart.callback, &logFindStart); |
| 200 | |
| 201 | if (!logFindStart.found()) { |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 202 | if (nonBlock) { |
| 203 | doSocketDelete(cli); |
| 204 | return false; |
| 205 | } |
| 206 | sequence = LogBufferElement::getCurrentSequence(); |
Mark Salyzyn | a1c60cf | 2014-02-19 07:33:12 -0800 | [diff] [blame] | 207 | } |
Mark Salyzyn | fa3716b | 2014-02-14 16:05:05 -0800 | [diff] [blame] | 208 | } |
| 209 | |
Mark Salyzyn | fa3add3 | 2016-12-29 07:26:30 -0800 | [diff] [blame] | 210 | android::prdebug( |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 211 | "logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d " |
| 212 | "start=%" PRIu64 "ns timeout=%" PRIu64 "ns\n", |
| 213 | cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask, |
| 214 | (int)pid, start.nsec(), timeout); |
Mark Salyzyn | fa3add3 | 2016-12-29 07:26:30 -0800 | [diff] [blame] | 215 | |
Tom Cherry | 10d086e | 2019-08-21 14:16:34 -0700 | [diff] [blame] | 216 | if (start == log_time::EPOCH) { |
Tom Cherry | e2d30d1 | 2018-10-19 13:51:35 -0700 | [diff] [blame] | 217 | timeout = 0; |
| 218 | } |
| 219 | |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 220 | LogTimeEntry::wrlock(); |
Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 221 | auto entry = std::make_unique<LogTimeEntry>(*this, cli, nonBlock, tail, logMask, pid, start, |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame^] | 222 | sequence, timeout, privileged, can_read_security); |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 223 | if (!entry->startReader_Locked()) { |
| 224 | LogTimeEntry::unlock(); |
| 225 | return false; |
| 226 | } |
| 227 | |
| 228 | // release client and entry reference counts once done |
| 229 | cli->incRef(); |
| 230 | mLogbuf.mTimes.emplace_front(std::move(entry)); |
Mark Salyzyn | 5c77ad5 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 231 | |
| 232 | // Set acceptable upper limit to wait for slow reader processing b/27242723 |
| 233 | struct timeval t = { LOGD_SNDTIMEO, 0 }; |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 234 | setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t, |
| 235 | sizeof(t)); |
Mark Salyzyn | 5c77ad5 | 2016-02-23 08:55:43 -0800 | [diff] [blame] | 236 | |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 237 | LogTimeEntry::unlock(); |
| 238 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 239 | return true; |
| 240 | } |
| 241 | |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 242 | void LogReader::doSocketDelete(SocketClient* cli) { |
| 243 | LastLogTimes& times = mLogbuf.mTimes; |
Mark Salyzyn | 3c501b5 | 2017-04-18 14:09:45 -0700 | [diff] [blame] | 244 | LogTimeEntry::wrlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 245 | LastLogTimes::iterator it = times.begin(); |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 246 | while (it != times.end()) { |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 247 | LogTimeEntry* entry = it->get(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 248 | if (entry->mClient == cli) { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 249 | entry->release_Locked(); |
| 250 | break; |
| 251 | } |
| 252 | it++; |
| 253 | } |
| 254 | LogTimeEntry::unlock(); |
| 255 | } |
Mark Salyzyn | dfc47e8 | 2014-03-24 10:26:47 -0700 | [diff] [blame] | 256 | |
| 257 | int LogReader::getLogSocket() { |
| 258 | static const char socketName[] = "logdr"; |
| 259 | int sock = android_get_control_socket(socketName); |
| 260 | |
| 261 | if (sock < 0) { |
Mark Salyzyn | 501c373 | 2017-03-10 14:31:54 -0800 | [diff] [blame] | 262 | sock = socket_local_server( |
| 263 | socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET); |
Mark Salyzyn | dfc47e8 | 2014-03-24 10:26:47 -0700 | [diff] [blame] | 264 | } |
| 265 | |
| 266 | return sock; |
| 267 | } |