Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (C) 2014 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 | |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 17 | #include "LogReaderThread.h" |
| 18 | |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 19 | #include <errno.h> |
Mark Salyzyn | ae2abf1 | 2017-03-31 10:48:39 -0700 | [diff] [blame] | 20 | #include <string.h> |
Mark Salyzyn | 8daa9af | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 21 | #include <sys/prctl.h> |
| 22 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 23 | #include <thread> |
| 24 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 25 | #include "LogBuffer.h" |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 26 | #include "LogReader.h" |
| 27 | |
Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 28 | using namespace std::placeholders; |
| 29 | |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 30 | pthread_mutex_t LogReaderThread::timesLock = PTHREAD_MUTEX_INITIALIZER; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 31 | |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 32 | LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool non_block, |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 33 | unsigned long tail, unsigned int log_mask, pid_t pid, |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 34 | log_time start_time, uint64_t start, uint64_t timeout, |
| 35 | bool privileged, bool can_read_security_logs) |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 36 | : leading_dropped_(false), |
| 37 | reader_(reader), |
| 38 | log_mask_(log_mask), |
| 39 | pid_(pid), |
| 40 | tail_(tail), |
| 41 | count_(0), |
| 42 | index_(0), |
| 43 | client_(client), |
| 44 | start_time_(start_time), |
| 45 | start_(start), |
| 46 | non_block_(non_block), |
Tom Cherry | 79d54f7 | 2020-05-04 11:13:55 -0700 | [diff] [blame] | 47 | privileged_(privileged), |
| 48 | can_read_security_logs_(can_read_security_logs) { |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 49 | timeout_.tv_sec = timeout / NS_PER_SEC; |
| 50 | timeout_.tv_nsec = timeout % NS_PER_SEC; |
| 51 | memset(last_tid_, 0, sizeof(last_tid_)); |
| 52 | pthread_cond_init(&thread_triggered_condition_, nullptr); |
Mark Salyzyn | 7718778 | 2015-05-12 15:21:31 -0700 | [diff] [blame] | 53 | cleanSkip_Locked(); |
Mark Salyzyn | a16f761 | 2014-08-07 08:16:52 -0700 | [diff] [blame] | 54 | } |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 55 | |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 56 | bool LogReaderThread::startReader_Locked() { |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 57 | auto thread = std::thread{&LogReaderThread::ThreadFunction, this}; |
| 58 | thread.detach(); |
| 59 | return true; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 60 | } |
| 61 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 62 | void LogReaderThread::ThreadFunction() { |
Mark Salyzyn | 8daa9af | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 63 | prctl(PR_SET_NAME, "logd.reader.per"); |
| 64 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 65 | SocketClient* client = client_; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 66 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 67 | LogBuffer& logbuf = reader_.logbuf(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 68 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 69 | leading_dropped_ = true; |
Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 70 | |
Mark Salyzyn | 3c501b5 | 2017-04-18 14:09:45 -0700 | [diff] [blame] | 71 | wrlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 72 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 73 | uint64_t start = start_; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 74 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 75 | while (!release_) { |
| 76 | if (timeout_.tv_sec || timeout_.tv_nsec) { |
| 77 | if (pthread_cond_clockwait(&thread_triggered_condition_, ×Lock, CLOCK_MONOTONIC, |
| 78 | &timeout_) == ETIMEDOUT) { |
| 79 | timeout_.tv_sec = 0; |
| 80 | timeout_.tv_nsec = 0; |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 81 | } |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 82 | if (release_) { |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 83 | break; |
| 84 | } |
| 85 | } |
| 86 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 87 | unlock(); |
| 88 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 89 | if (tail_) { |
| 90 | logbuf.flushTo(client, start, nullptr, privileged_, can_read_security_logs_, |
| 91 | std::bind(&LogReaderThread::FilterFirstPass, this, _1)); |
| 92 | leading_dropped_ = |
| 93 | true; // TODO: Likely a bug, if leading_dropped_ was not true before calling |
| 94 | // flushTo(), then it should not be reset to true after. |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 95 | } |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 96 | start = logbuf.flushTo(client, start, last_tid_, privileged_, can_read_security_logs_, |
| 97 | std::bind(&LogReaderThread::FilterSecondPass, this, _1)); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 98 | |
Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 99 | // We only ignore entries before the original start time for the first flushTo(), if we |
| 100 | // get entries after this first flush before the original start time, then the client |
| 101 | // wouldn't have seen them. |
| 102 | // Note: this is still racy and may skip out of order events that came in since the last |
| 103 | // time the client disconnected and then reconnected with the new start time. The long term |
| 104 | // solution here is that clients must request events since a specific sequence number. |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 105 | start_time_.tv_sec = 0; |
| 106 | start_time_.tv_nsec = 0; |
Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 107 | |
Mark Salyzyn | 3c501b5 | 2017-04-18 14:09:45 -0700 | [diff] [blame] | 108 | wrlock(); |
Mark Salyzyn | a16f761 | 2014-08-07 08:16:52 -0700 | [diff] [blame] | 109 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 110 | if (start == LogBufferElement::FLUSH_ERROR) { |
Mark Salyzyn | de4bb9c | 2015-09-16 15:34:00 -0700 | [diff] [blame] | 111 | break; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 112 | } |
| 113 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 114 | start_ = start + 1; |
Mark Salyzyn | de4bb9c | 2015-09-16 15:34:00 -0700 | [diff] [blame] | 115 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 116 | if (non_block_ || release_) { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 117 | break; |
| 118 | } |
| 119 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 120 | cleanSkip_Locked(); |
TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 121 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 122 | if (!timeout_.tv_sec && !timeout_.tv_nsec) { |
| 123 | pthread_cond_wait(&thread_triggered_condition_, ×Lock); |
Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 124 | } |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 125 | } |
| 126 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 127 | LogReader& reader = reader_; |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 128 | reader.release(client); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 129 | |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 130 | client->decRef(); |
| 131 | |
| 132 | LastLogTimes& times = reader.logbuf().mTimes; |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 133 | auto it = std::find_if(times.begin(), times.end(), |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 134 | [this](const auto& other) { return other.get() == this; }); |
Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 135 | |
| 136 | if (it != times.end()) { |
| 137 | times.erase(it); |
| 138 | } |
| 139 | |
| 140 | unlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 141 | } |
| 142 | |
| 143 | // A first pass to count the number of elements |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 144 | int LogReaderThread::FilterFirstPass(const LogBufferElement* element) { |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 145 | LogReaderThread::wrlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 146 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 147 | if (leading_dropped_) { |
Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 148 | if (element->getDropped()) { |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 149 | LogReaderThread::unlock(); |
Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 150 | return false; |
| 151 | } |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 152 | leading_dropped_ = false; |
Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 153 | } |
| 154 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 155 | if (count_ == 0) { |
| 156 | start_ = element->getSequence(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 157 | } |
| 158 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 159 | if ((!pid_ || pid_ == element->getPid()) && IsWatching(element->getLogId()) && |
| 160 | (start_time_ == log_time::EPOCH || start_time_ <= element->getRealTime())) { |
| 161 | ++count_; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 162 | } |
| 163 | |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 164 | LogReaderThread::unlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 165 | |
| 166 | return false; |
| 167 | } |
| 168 | |
| 169 | // A second pass to send the selected elements |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 170 | int LogReaderThread::FilterSecondPass(const LogBufferElement* element) { |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 171 | LogReaderThread::wrlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 172 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 173 | start_ = element->getSequence(); |
TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 174 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 175 | if (skip_ahead_[element->getLogId()]) { |
| 176 | skip_ahead_[element->getLogId()]--; |
Mark Salyzyn | 8d7656b | 2014-06-05 15:58:43 -0700 | [diff] [blame] | 177 | goto skip; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 178 | } |
| 179 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 180 | if (leading_dropped_) { |
Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 181 | if (element->getDropped()) { |
| 182 | goto skip; |
| 183 | } |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 184 | leading_dropped_ = false; |
Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 185 | } |
| 186 | |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 187 | // Truncate to close race between first and second pass |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 188 | if (non_block_ && tail_ && index_ >= count_) { |
Mark Salyzyn | f7c0f75 | 2015-03-03 13:39:37 -0800 | [diff] [blame] | 189 | goto stop; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 190 | } |
| 191 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 192 | if (!IsWatching(element->getLogId())) { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 193 | goto skip; |
| 194 | } |
| 195 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 196 | if (pid_ && pid_ != element->getPid()) { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 197 | goto skip; |
| 198 | } |
| 199 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 200 | if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) { |
Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 201 | goto skip; |
| 202 | } |
| 203 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 204 | if (release_) { |
Jintao_Zhu | 5f93072 | 2018-11-11 03:13:24 -0800 | [diff] [blame] | 205 | goto stop; |
| 206 | } |
| 207 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 208 | if (!tail_) { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 209 | goto ok; |
| 210 | } |
| 211 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 212 | ++index_; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 213 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 214 | if (count_ > tail_ && index_ <= (count_ - tail_)) { |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 215 | goto skip; |
| 216 | } |
| 217 | |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 218 | if (!non_block_) { |
| 219 | tail_ = 0; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 220 | } |
| 221 | |
| 222 | ok: |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 223 | if (!skip_ahead_[element->getLogId()]) { |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 224 | LogReaderThread::unlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 225 | return true; |
| 226 | } |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 227 | // FALLTHRU |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 228 | |
| 229 | skip: |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 230 | LogReaderThread::unlock(); |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 231 | return false; |
Mark Salyzyn | f7c0f75 | 2015-03-03 13:39:37 -0800 | [diff] [blame] | 232 | |
| 233 | stop: |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 234 | LogReaderThread::unlock(); |
Mark Salyzyn | f7c0f75 | 2015-03-03 13:39:37 -0800 | [diff] [blame] | 235 | return -1; |
Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 236 | } |
TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 237 | |
Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 238 | void LogReaderThread::cleanSkip_Locked(void) { |
Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame^] | 239 | memset(skip_ahead_, 0, sizeof(skip_ahead_)); |
TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 240 | } |