Mark Salyzyn | 12bac90 | 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 | 1647cd4 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 17 | #include "LogReaderThread.h" |
| 18 | |
Mark Salyzyn | c959c64 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 19 | #include <errno.h> |
Mark Salyzyn | bec7b2d | 2017-03-31 10:48:39 -0700 | [diff] [blame] | 20 | #include <string.h> |
Mark Salyzyn | 4e5efdc | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 21 | #include <sys/prctl.h> |
| 22 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 23 | #include <thread> |
| 24 | |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 25 | #include "LogBuffer.h" |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 26 | #include "LogReaderList.h" |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 27 | |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 28 | LogReaderThread::LogReaderThread(LogBuffer* log_buffer, LogReaderList* reader_list, |
| 29 | std::unique_ptr<LogWriter> writer, bool non_block, |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 30 | unsigned long tail, LogMask log_mask, pid_t pid, |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 31 | log_time start_time, uint64_t start, |
| 32 | std::chrono::steady_clock::time_point deadline) |
| 33 | : log_buffer_(log_buffer), |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 34 | reader_list_(reader_list), |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 35 | writer_(std::move(writer)), |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 36 | pid_(pid), |
| 37 | tail_(tail), |
| 38 | count_(0), |
| 39 | index_(0), |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 40 | start_time_(start_time), |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 41 | deadline_(deadline), |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 42 | non_block_(non_block) { |
Mark Salyzyn | cd766f9 | 2015-05-12 15:21:31 -0700 | [diff] [blame] | 43 | cleanSkip_Locked(); |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 44 | flush_to_state_ = log_buffer_->CreateFlushToState(start, log_mask); |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 45 | auto thread = std::thread{&LogReaderThread::ThreadFunction, this}; |
| 46 | thread.detach(); |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 47 | } |
| 48 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 49 | void LogReaderThread::ThreadFunction() { |
Mark Salyzyn | 4e5efdc | 2014-04-28 14:07:23 -0700 | [diff] [blame] | 50 | prctl(PR_SET_NAME, "logd.reader.per"); |
| 51 | |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 52 | auto lock = std::unique_lock{reader_list_->reader_threads_lock()}; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 53 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 54 | while (!release_) { |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 55 | if (deadline_.time_since_epoch().count() != 0) { |
| 56 | if (thread_triggered_condition_.wait_until(lock, deadline_) == |
| 57 | std::cv_status::timeout) { |
| 58 | deadline_ = {}; |
Mark Salyzyn | c959c64 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 59 | } |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 60 | if (release_) { |
Mark Salyzyn | c959c64 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 61 | break; |
| 62 | } |
| 63 | } |
| 64 | |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 65 | lock.unlock(); |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 66 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 67 | if (tail_) { |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 68 | auto first_pass_state = log_buffer_->CreateFlushToState(flush_to_state_->start(), |
| 69 | flush_to_state_->log_mask()); |
Tom Cherry | ca4b25d | 2020-05-28 20:02:42 -0700 | [diff] [blame] | 70 | log_buffer_->FlushTo( |
| 71 | writer_.get(), *first_pass_state, |
| 72 | [this](log_id_t log_id, pid_t pid, uint64_t sequence, log_time realtime) { |
| 73 | return FilterFirstPass(log_id, pid, sequence, realtime); |
| 74 | }); |
Tom Cherry | 154b63a | 2020-10-05 11:35:59 -0700 | [diff] [blame] | 75 | log_buffer_->DeleteFlushToState(std::move(first_pass_state)); |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 76 | } |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 77 | bool flush_success = log_buffer_->FlushTo( |
| 78 | writer_.get(), *flush_to_state_, |
Tom Cherry | ca4b25d | 2020-05-28 20:02:42 -0700 | [diff] [blame] | 79 | [this](log_id_t log_id, pid_t pid, uint64_t sequence, log_time realtime) { |
| 80 | return FilterSecondPass(log_id, pid, sequence, realtime); |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 81 | }); |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 82 | |
Tom Cherry | e8d2089 | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 83 | // We only ignore entries before the original start time for the first flushTo(), if we |
| 84 | // get entries after this first flush before the original start time, then the client |
| 85 | // wouldn't have seen them. |
| 86 | // Note: this is still racy and may skip out of order events that came in since the last |
| 87 | // time the client disconnected and then reconnected with the new start time. The long term |
| 88 | // solution here is that clients must request events since a specific sequence number. |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 89 | start_time_.tv_sec = 0; |
| 90 | start_time_.tv_nsec = 0; |
Tom Cherry | e8d2089 | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 91 | |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 92 | lock.lock(); |
Mark Salyzyn | 740d7c2 | 2014-08-07 08:16:52 -0700 | [diff] [blame] | 93 | |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 94 | if (!flush_success) { |
Mark Salyzyn | 28cb69a | 2015-09-16 15:34:00 -0700 | [diff] [blame] | 95 | break; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 96 | } |
| 97 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 98 | if (non_block_ || release_) { |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 99 | break; |
| 100 | } |
| 101 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 102 | cleanSkip_Locked(); |
TraianX Schiau | 6ba427e | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 103 | |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 104 | if (deadline_.time_since_epoch().count() == 0) { |
| 105 | thread_triggered_condition_.wait(lock); |
Mark Salyzyn | c959c64 | 2015-11-30 11:35:56 -0800 | [diff] [blame] | 106 | } |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 107 | } |
| 108 | |
Tom Cherry | 154b63a | 2020-10-05 11:35:59 -0700 | [diff] [blame] | 109 | lock.unlock(); |
| 110 | log_buffer_->DeleteFlushToState(std::move(flush_to_state_)); |
| 111 | lock.lock(); |
| 112 | |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 113 | writer_->Release(); |
Tom Cherry | 06e478b | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 114 | |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 115 | auto& log_reader_threads = reader_list_->reader_threads(); |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 116 | auto it = std::find_if(log_reader_threads.begin(), log_reader_threads.end(), |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 117 | [this](const auto& other) { return other.get() == this; }); |
Tom Cherry | 06e478b | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 118 | |
Tom Cherry | 5ecfbf0 | 2020-05-11 16:29:29 -0700 | [diff] [blame] | 119 | if (it != log_reader_threads.end()) { |
| 120 | log_reader_threads.erase(it); |
Tom Cherry | 06e478b | 2018-10-08 17:33:50 -0700 | [diff] [blame] | 121 | } |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 122 | } |
| 123 | |
| 124 | // A first pass to count the number of elements |
Tom Cherry | ca4b25d | 2020-05-28 20:02:42 -0700 | [diff] [blame] | 125 | FilterResult LogReaderThread::FilterFirstPass(log_id_t, pid_t pid, uint64_t, log_time realtime) { |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 126 | auto lock = std::lock_guard{reader_list_->reader_threads_lock()}; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 127 | |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 128 | if ((!pid_ || pid_ == pid) && (start_time_ == log_time::EPOCH || start_time_ <= realtime)) { |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 129 | ++count_; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 130 | } |
| 131 | |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 132 | return FilterResult::kSkip; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 133 | } |
| 134 | |
| 135 | // A second pass to send the selected elements |
Tom Cherry | d444ab4 | 2020-05-28 12:38:21 -0700 | [diff] [blame] | 136 | FilterResult LogReaderThread::FilterSecondPass(log_id_t log_id, pid_t pid, uint64_t, |
Tom Cherry | ca4b25d | 2020-05-28 20:02:42 -0700 | [diff] [blame] | 137 | log_time realtime) { |
Tom Cherry | adf2e44 | 2020-05-14 19:25:05 -0700 | [diff] [blame] | 138 | auto lock = std::lock_guard{reader_list_->reader_threads_lock()}; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 139 | |
Tom Cherry | baa25a2 | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 140 | if (skip_ahead_[log_id]) { |
| 141 | skip_ahead_[log_id]--; |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 142 | return FilterResult::kSkip; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 143 | } |
| 144 | |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 145 | // Truncate to close race between first and second pass |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 146 | if (non_block_ && tail_ && index_ >= count_) { |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 147 | return FilterResult::kStop; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 148 | } |
| 149 | |
Tom Cherry | baa25a2 | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 150 | if (pid_ && pid_ != pid) { |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 151 | return FilterResult::kSkip; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 152 | } |
| 153 | |
Tom Cherry | baa25a2 | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 154 | if (start_time_ != log_time::EPOCH && realtime <= start_time_) { |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 155 | return FilterResult::kSkip; |
Tom Cherry | e8d2089 | 2019-08-21 14:53:06 -0700 | [diff] [blame] | 156 | } |
| 157 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 158 | if (release_) { |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 159 | return FilterResult::kStop; |
Jintao_Zhu | 3e6f9d8 | 2018-11-11 03:13:24 -0800 | [diff] [blame] | 160 | } |
| 161 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 162 | if (!tail_) { |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 163 | goto ok; |
| 164 | } |
| 165 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 166 | ++index_; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 167 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 168 | if (count_ > tail_ && index_ <= (count_ - tail_)) { |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 169 | return FilterResult::kSkip; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 170 | } |
| 171 | |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 172 | if (!non_block_) { |
| 173 | tail_ = 0; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 174 | } |
| 175 | |
| 176 | ok: |
Tom Cherry | baa25a2 | 2020-05-27 14:43:19 -0700 | [diff] [blame] | 177 | if (!skip_ahead_[log_id]) { |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 178 | return FilterResult::kWrite; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 179 | } |
Tom Cherry | c92cbf6 | 2020-05-27 10:46:37 -0700 | [diff] [blame] | 180 | return FilterResult::kSkip; |
Mark Salyzyn | 12bac90 | 2014-02-26 09:50:16 -0800 | [diff] [blame] | 181 | } |
TraianX Schiau | 6ba427e | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 182 | |
Tom Cherry | 1647cd4 | 2020-05-04 12:53:36 -0700 | [diff] [blame] | 183 | void LogReaderThread::cleanSkip_Locked(void) { |
Tom Cherry | 7e3bc96 | 2020-05-04 17:10:16 -0700 | [diff] [blame] | 184 | memset(skip_ahead_, 0, sizeof(skip_ahead_)); |
TraianX Schiau | 6ba427e | 2014-12-17 10:53:41 +0200 | [diff] [blame] | 185 | } |