| 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" | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 26 | #include "LogReaderList.h" | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 27 |  | 
| Tom Cherry | 320f596 | 2020-05-04 17:25:34 -0700 | [diff] [blame] | 28 | using namespace std::placeholders; | 
|  | 29 |  | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 30 | LogReaderThread::LogReaderThread(LogBuffer* log_buffer, LogReaderList* reader_list, | 
|  | 31 | std::unique_ptr<LogWriter> writer, bool non_block, | 
|  | 32 | unsigned long tail, unsigned int log_mask, pid_t pid, | 
|  | 33 | log_time start_time, uint64_t start, | 
|  | 34 | std::chrono::steady_clock::time_point deadline) | 
|  | 35 | : log_buffer_(log_buffer), | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 36 | reader_list_(reader_list), | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 37 | writer_(std::move(writer)), | 
|  | 38 | leading_dropped_(false), | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 39 | log_mask_(log_mask), | 
|  | 40 | pid_(pid), | 
|  | 41 | tail_(tail), | 
|  | 42 | count_(0), | 
|  | 43 | index_(0), | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 44 | start_time_(start_time), | 
|  | 45 | start_(start), | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 46 | deadline_(deadline), | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 47 | non_block_(non_block) { | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 48 | memset(last_tid_, 0, sizeof(last_tid_)); | 
| Mark Salyzyn | 7718778 | 2015-05-12 15:21:31 -0700 | [diff] [blame] | 49 | cleanSkip_Locked(); | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 50 | auto thread = std::thread{&LogReaderThread::ThreadFunction, this}; | 
|  | 51 | thread.detach(); | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 52 | } | 
|  | 53 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 54 | void LogReaderThread::ThreadFunction() { | 
| Mark Salyzyn | 8daa9af | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 55 | prctl(PR_SET_NAME, "logd.reader.per"); | 
|  | 56 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 57 | leading_dropped_ = true; | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 58 |  | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 59 | auto lock = std::unique_lock{reader_list_->reader_threads_lock()}; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 60 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 61 | uint64_t start = start_; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 62 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 63 | while (!release_) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 64 | if (deadline_.time_since_epoch().count() != 0) { | 
|  | 65 | if (thread_triggered_condition_.wait_until(lock, deadline_) == | 
|  | 66 | std::cv_status::timeout) { | 
|  | 67 | deadline_ = {}; | 
| Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 68 | } | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 69 | if (release_) { | 
| Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 70 | break; | 
|  | 71 | } | 
|  | 72 | } | 
|  | 73 |  | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 74 | lock.unlock(); | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 75 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 76 | if (tail_) { | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 77 | log_buffer_->FlushTo(writer_.get(), start, nullptr, | 
|  | 78 | std::bind(&LogReaderThread::FilterFirstPass, this, _1)); | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 79 | leading_dropped_ = | 
|  | 80 | true;  // TODO: Likely a bug, if leading_dropped_ was not true before calling | 
|  | 81 | // flushTo(), then it should not be reset to true after. | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 82 | } | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 83 | start = log_buffer_->FlushTo(writer_.get(), start, last_tid_, | 
|  | 84 | std::bind(&LogReaderThread::FilterSecondPass, this, _1)); | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 85 |  | 
| Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 86 | // We only ignore entries before the original start time for the first flushTo(), if we | 
|  | 87 | // get entries after this first flush before the original start time, then the client | 
|  | 88 | // wouldn't have seen them. | 
|  | 89 | // Note: this is still racy and may skip out of order events that came in since the last | 
|  | 90 | // time the client disconnected and then reconnected with the new start time.  The long term | 
|  | 91 | // 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] | 92 | start_time_.tv_sec = 0; | 
|  | 93 | start_time_.tv_nsec = 0; | 
| Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 94 |  | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 95 | lock.lock(); | 
| Mark Salyzyn | a16f761 | 2014-08-07 08:16:52 -0700 | [diff] [blame] | 96 |  | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 97 | if (start == LogBuffer::FLUSH_ERROR) { | 
| Mark Salyzyn | de4bb9c | 2015-09-16 15:34:00 -0700 | [diff] [blame] | 98 | break; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 99 | } | 
|  | 100 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 101 | start_ = start + 1; | 
| Mark Salyzyn | de4bb9c | 2015-09-16 15:34:00 -0700 | [diff] [blame] | 102 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 103 | if (non_block_ || release_) { | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 104 | break; | 
|  | 105 | } | 
|  | 106 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 107 | cleanSkip_Locked(); | 
| TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 108 |  | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 109 | if (deadline_.time_since_epoch().count() == 0) { | 
|  | 110 | thread_triggered_condition_.wait(lock); | 
| Mark Salyzyn | b75cce0 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 111 | } | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 112 | } | 
|  | 113 |  | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 114 | writer_->Release(); | 
| Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 115 |  | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 116 | auto& log_reader_threads = reader_list_->reader_threads(); | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 117 | auto it = std::find_if(log_reader_threads.begin(), log_reader_threads.end(), | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 118 | [this](const auto& other) { return other.get() == this; }); | 
| Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 119 |  | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 120 | if (it != log_reader_threads.end()) { | 
|  | 121 | log_reader_threads.erase(it); | 
| Tom Cherry | 4f22786 | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 122 | } | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 123 | } | 
|  | 124 |  | 
|  | 125 | // A first pass to count the number of elements | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 126 | FlushToResult LogReaderThread::FilterFirstPass(const LogBufferElement* element) { | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 127 | auto lock = std::lock_guard{reader_list_->reader_threads_lock()}; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 128 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 129 | if (leading_dropped_) { | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 130 | if (element->getDropped()) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 131 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 132 | } | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 133 | leading_dropped_ = false; | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 134 | } | 
|  | 135 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 136 | if (count_ == 0) { | 
|  | 137 | start_ = element->getSequence(); | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 138 | } | 
|  | 139 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 140 | if ((!pid_ || pid_ == element->getPid()) && IsWatching(element->getLogId()) && | 
|  | 141 | (start_time_ == log_time::EPOCH || start_time_ <= element->getRealTime())) { | 
|  | 142 | ++count_; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 143 | } | 
|  | 144 |  | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 145 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 146 | } | 
|  | 147 |  | 
|  | 148 | // A second pass to send the selected elements | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 149 | FlushToResult LogReaderThread::FilterSecondPass(const LogBufferElement* element) { | 
| Tom Cherry | 283c9a1 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 150 | auto lock = std::lock_guard{reader_list_->reader_threads_lock()}; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 151 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 152 | start_ = element->getSequence(); | 
| TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 153 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 154 | if (skip_ahead_[element->getLogId()]) { | 
|  | 155 | skip_ahead_[element->getLogId()]--; | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 156 | return FlushToResult::kSkip; | 
| 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 (leading_dropped_) { | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 160 | if (element->getDropped()) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 161 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 162 | } | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 163 | leading_dropped_ = false; | 
| Mark Salyzyn | 047cc07 | 2015-06-04 13:35:30 -0700 | [diff] [blame] | 164 | } | 
|  | 165 |  | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 166 | // Truncate to close race between first and second pass | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 167 | if (non_block_ && tail_ && index_ >= count_) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 168 | return FlushToResult::kStop; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 169 | } | 
|  | 170 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 171 | if (!IsWatching(element->getLogId())) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 172 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 173 | } | 
|  | 174 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 175 | if (pid_ && pid_ != element->getPid()) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 176 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 177 | } | 
|  | 178 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 179 | if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 180 | return FlushToResult::kSkip; | 
| Tom Cherry | 65ab7fe | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 181 | } | 
|  | 182 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 183 | if (release_) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 184 | return FlushToResult::kStop; | 
| Jintao_Zhu | 5f93072 | 2018-11-11 03:13:24 -0800 | [diff] [blame] | 185 | } | 
|  | 186 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 187 | if (!tail_) { | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 188 | goto ok; | 
|  | 189 | } | 
|  | 190 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 191 | ++index_; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 192 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 193 | if (count_ > tail_ && index_ <= (count_ - tail_)) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 194 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 195 | } | 
|  | 196 |  | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 197 | if (!non_block_) { | 
|  | 198 | tail_ = 0; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 199 | } | 
|  | 200 |  | 
|  | 201 | ok: | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 202 | if (!skip_ahead_[element->getLogId()]) { | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 203 | return FlushToResult::kWrite; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 204 | } | 
| Tom Cherry | 68630a0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 205 | return FlushToResult::kSkip; | 
| Mark Salyzyn | 0175b07 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 206 | } | 
| TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 207 |  | 
| Tom Cherry | 6ec71e9 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 208 | void LogReaderThread::cleanSkip_Locked(void) { | 
| Tom Cherry | cef47bb | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 209 | memset(skip_ahead_, 0, sizeof(skip_ahead_)); | 
| TraianX Schiau | da6495d | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 210 | } |