blob: b2001b56b17cebf5c9056725def1dad8b7cdfe8d [file] [log] [blame]
Mark Salyzyn0175b072014-02-26 09:50:16 -08001/*
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 Cherry6ec71e92020-05-04 12:53:36 -070017#include "LogReaderThread.h"
18
Mark Salyzynb75cce02015-11-30 11:35:56 -080019#include <errno.h>
Mark Salyzynae2abf12017-03-31 10:48:39 -070020#include <string.h>
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070021#include <sys/prctl.h>
22
Tom Cherrycef47bb2020-05-04 17:10:16 -070023#include <thread>
24
Mark Salyzyn0175b072014-02-26 09:50:16 -080025#include "LogBuffer.h"
Tom Cherry283c9a12020-05-14 19:25:05 -070026#include "LogReaderList.h"
Mark Salyzyn0175b072014-02-26 09:50:16 -080027
Tom Cherry320f5962020-05-04 17:25:34 -070028using namespace std::placeholders;
29
Tom Cherry283c9a12020-05-14 19:25:05 -070030LogReaderThread::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 Cherry68630a02020-05-11 16:29:29 -070036 reader_list_(reader_list),
Tom Cherry283c9a12020-05-14 19:25:05 -070037 writer_(std::move(writer)),
38 leading_dropped_(false),
Tom Cherrycef47bb2020-05-04 17:10:16 -070039 log_mask_(log_mask),
40 pid_(pid),
41 tail_(tail),
42 count_(0),
43 index_(0),
Tom Cherrycef47bb2020-05-04 17:10:16 -070044 start_time_(start_time),
45 start_(start),
Tom Cherry68630a02020-05-11 16:29:29 -070046 deadline_(deadline),
Tom Cherry283c9a12020-05-14 19:25:05 -070047 non_block_(non_block) {
Tom Cherrycef47bb2020-05-04 17:10:16 -070048 memset(last_tid_, 0, sizeof(last_tid_));
Mark Salyzyn77187782015-05-12 15:21:31 -070049 cleanSkip_Locked();
Tom Cherrycef47bb2020-05-04 17:10:16 -070050 auto thread = std::thread{&LogReaderThread::ThreadFunction, this};
51 thread.detach();
Mark Salyzyn0175b072014-02-26 09:50:16 -080052}
53
Tom Cherrycef47bb2020-05-04 17:10:16 -070054void LogReaderThread::ThreadFunction() {
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070055 prctl(PR_SET_NAME, "logd.reader.per");
56
Tom Cherrycef47bb2020-05-04 17:10:16 -070057 leading_dropped_ = true;
Mark Salyzyn047cc072015-06-04 13:35:30 -070058
Tom Cherry283c9a12020-05-14 19:25:05 -070059 auto lock = std::unique_lock{reader_list_->reader_threads_lock()};
Mark Salyzyn0175b072014-02-26 09:50:16 -080060
Tom Cherrycef47bb2020-05-04 17:10:16 -070061 uint64_t start = start_;
Mark Salyzyn0175b072014-02-26 09:50:16 -080062
Tom Cherrycef47bb2020-05-04 17:10:16 -070063 while (!release_) {
Tom Cherry68630a02020-05-11 16:29:29 -070064 if (deadline_.time_since_epoch().count() != 0) {
65 if (thread_triggered_condition_.wait_until(lock, deadline_) ==
66 std::cv_status::timeout) {
67 deadline_ = {};
Mark Salyzynb75cce02015-11-30 11:35:56 -080068 }
Tom Cherrycef47bb2020-05-04 17:10:16 -070069 if (release_) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080070 break;
71 }
72 }
73
Tom Cherry68630a02020-05-11 16:29:29 -070074 lock.unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -080075
Tom Cherrycef47bb2020-05-04 17:10:16 -070076 if (tail_) {
Tom Cherry283c9a12020-05-14 19:25:05 -070077 log_buffer_->FlushTo(writer_.get(), start, nullptr,
78 std::bind(&LogReaderThread::FilterFirstPass, this, _1));
Tom Cherrycef47bb2020-05-04 17:10:16 -070079 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 Salyzyn0175b072014-02-26 09:50:16 -080082 }
Tom Cherry283c9a12020-05-14 19:25:05 -070083 start = log_buffer_->FlushTo(writer_.get(), start, last_tid_,
84 std::bind(&LogReaderThread::FilterSecondPass, this, _1));
Mark Salyzyn0175b072014-02-26 09:50:16 -080085
Tom Cherry65ab7fe2019-08-21 14:53:06 -070086 // 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 Cherrycef47bb2020-05-04 17:10:16 -070092 start_time_.tv_sec = 0;
93 start_time_.tv_nsec = 0;
Tom Cherry65ab7fe2019-08-21 14:53:06 -070094
Tom Cherry68630a02020-05-11 16:29:29 -070095 lock.lock();
Mark Salyzyna16f7612014-08-07 08:16:52 -070096
Tom Cherry283c9a12020-05-14 19:25:05 -070097 if (start == LogBuffer::FLUSH_ERROR) {
Mark Salyzynde4bb9c2015-09-16 15:34:00 -070098 break;
Mark Salyzyn0175b072014-02-26 09:50:16 -080099 }
100
Tom Cherrycef47bb2020-05-04 17:10:16 -0700101 start_ = start + 1;
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700102
Tom Cherrycef47bb2020-05-04 17:10:16 -0700103 if (non_block_ || release_) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800104 break;
105 }
106
Tom Cherrycef47bb2020-05-04 17:10:16 -0700107 cleanSkip_Locked();
TraianX Schiauda6495d2014-12-17 10:53:41 +0200108
Tom Cherry68630a02020-05-11 16:29:29 -0700109 if (deadline_.time_since_epoch().count() == 0) {
110 thread_triggered_condition_.wait(lock);
Mark Salyzynb75cce02015-11-30 11:35:56 -0800111 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800112 }
113
Tom Cherry283c9a12020-05-14 19:25:05 -0700114 writer_->Release();
Tom Cherry4f227862018-10-08 17:33:50 -0700115
Tom Cherry283c9a12020-05-14 19:25:05 -0700116 auto& log_reader_threads = reader_list_->reader_threads();
Tom Cherry68630a02020-05-11 16:29:29 -0700117 auto it = std::find_if(log_reader_threads.begin(), log_reader_threads.end(),
Tom Cherrycef47bb2020-05-04 17:10:16 -0700118 [this](const auto& other) { return other.get() == this; });
Tom Cherry4f227862018-10-08 17:33:50 -0700119
Tom Cherry68630a02020-05-11 16:29:29 -0700120 if (it != log_reader_threads.end()) {
121 log_reader_threads.erase(it);
Tom Cherry4f227862018-10-08 17:33:50 -0700122 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800123}
124
125// A first pass to count the number of elements
Tom Cherry68630a02020-05-11 16:29:29 -0700126FlushToResult LogReaderThread::FilterFirstPass(const LogBufferElement* element) {
Tom Cherry283c9a12020-05-14 19:25:05 -0700127 auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
Mark Salyzyn0175b072014-02-26 09:50:16 -0800128
Tom Cherrycef47bb2020-05-04 17:10:16 -0700129 if (leading_dropped_) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700130 if (element->getDropped()) {
Tom Cherry68630a02020-05-11 16:29:29 -0700131 return FlushToResult::kSkip;
Mark Salyzyn047cc072015-06-04 13:35:30 -0700132 }
Tom Cherrycef47bb2020-05-04 17:10:16 -0700133 leading_dropped_ = false;
Mark Salyzyn047cc072015-06-04 13:35:30 -0700134 }
135
Tom Cherrycef47bb2020-05-04 17:10:16 -0700136 if (count_ == 0) {
137 start_ = element->getSequence();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800138 }
139
Tom Cherrycef47bb2020-05-04 17:10:16 -0700140 if ((!pid_ || pid_ == element->getPid()) && IsWatching(element->getLogId()) &&
141 (start_time_ == log_time::EPOCH || start_time_ <= element->getRealTime())) {
142 ++count_;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800143 }
144
Tom Cherry68630a02020-05-11 16:29:29 -0700145 return FlushToResult::kSkip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800146}
147
148// A second pass to send the selected elements
Tom Cherry68630a02020-05-11 16:29:29 -0700149FlushToResult LogReaderThread::FilterSecondPass(const LogBufferElement* element) {
Tom Cherry283c9a12020-05-14 19:25:05 -0700150 auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
Mark Salyzyn0175b072014-02-26 09:50:16 -0800151
Tom Cherrycef47bb2020-05-04 17:10:16 -0700152 start_ = element->getSequence();
TraianX Schiauda6495d2014-12-17 10:53:41 +0200153
Tom Cherrycef47bb2020-05-04 17:10:16 -0700154 if (skip_ahead_[element->getLogId()]) {
155 skip_ahead_[element->getLogId()]--;
Tom Cherry68630a02020-05-11 16:29:29 -0700156 return FlushToResult::kSkip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800157 }
158
Tom Cherrycef47bb2020-05-04 17:10:16 -0700159 if (leading_dropped_) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700160 if (element->getDropped()) {
Tom Cherry68630a02020-05-11 16:29:29 -0700161 return FlushToResult::kSkip;
Mark Salyzyn047cc072015-06-04 13:35:30 -0700162 }
Tom Cherrycef47bb2020-05-04 17:10:16 -0700163 leading_dropped_ = false;
Mark Salyzyn047cc072015-06-04 13:35:30 -0700164 }
165
Mark Salyzyn0175b072014-02-26 09:50:16 -0800166 // Truncate to close race between first and second pass
Tom Cherrycef47bb2020-05-04 17:10:16 -0700167 if (non_block_ && tail_ && index_ >= count_) {
Tom Cherry68630a02020-05-11 16:29:29 -0700168 return FlushToResult::kStop;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800169 }
170
Tom Cherrycef47bb2020-05-04 17:10:16 -0700171 if (!IsWatching(element->getLogId())) {
Tom Cherry68630a02020-05-11 16:29:29 -0700172 return FlushToResult::kSkip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800173 }
174
Tom Cherrycef47bb2020-05-04 17:10:16 -0700175 if (pid_ && pid_ != element->getPid()) {
Tom Cherry68630a02020-05-11 16:29:29 -0700176 return FlushToResult::kSkip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800177 }
178
Tom Cherrycef47bb2020-05-04 17:10:16 -0700179 if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) {
Tom Cherry68630a02020-05-11 16:29:29 -0700180 return FlushToResult::kSkip;
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700181 }
182
Tom Cherrycef47bb2020-05-04 17:10:16 -0700183 if (release_) {
Tom Cherry68630a02020-05-11 16:29:29 -0700184 return FlushToResult::kStop;
Jintao_Zhu5f930722018-11-11 03:13:24 -0800185 }
186
Tom Cherrycef47bb2020-05-04 17:10:16 -0700187 if (!tail_) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800188 goto ok;
189 }
190
Tom Cherrycef47bb2020-05-04 17:10:16 -0700191 ++index_;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800192
Tom Cherrycef47bb2020-05-04 17:10:16 -0700193 if (count_ > tail_ && index_ <= (count_ - tail_)) {
Tom Cherry68630a02020-05-11 16:29:29 -0700194 return FlushToResult::kSkip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800195 }
196
Tom Cherrycef47bb2020-05-04 17:10:16 -0700197 if (!non_block_) {
198 tail_ = 0;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800199 }
200
201ok:
Tom Cherrycef47bb2020-05-04 17:10:16 -0700202 if (!skip_ahead_[element->getLogId()]) {
Tom Cherry68630a02020-05-11 16:29:29 -0700203 return FlushToResult::kWrite;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800204 }
Tom Cherry68630a02020-05-11 16:29:29 -0700205 return FlushToResult::kSkip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800206}
TraianX Schiauda6495d2014-12-17 10:53:41 +0200207
Tom Cherry6ec71e92020-05-04 12:53:36 -0700208void LogReaderThread::cleanSkip_Locked(void) {
Tom Cherrycef47bb2020-05-04 17:10:16 -0700209 memset(skip_ahead_, 0, sizeof(skip_ahead_));
TraianX Schiauda6495d2014-12-17 10:53:41 +0200210}