blob: 5413c4de10632eae439cd80e9654cdc7228381f5 [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"
Mark Salyzyn0175b072014-02-26 09:50:16 -080026#include "LogReader.h"
27
Tom Cherry320f5962020-05-04 17:25:34 -070028using namespace std::placeholders;
29
Tom Cherry6ec71e92020-05-04 12:53:36 -070030pthread_mutex_t LogReaderThread::timesLock = PTHREAD_MUTEX_INITIALIZER;
Mark Salyzyn0175b072014-02-26 09:50:16 -080031
Tom Cherry6ec71e92020-05-04 12:53:36 -070032LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool non_block,
Tom Cherrycef47bb2020-05-04 17:10:16 -070033 unsigned long tail, unsigned int log_mask, pid_t pid,
Tom Cherry6ec71e92020-05-04 12:53:36 -070034 log_time start_time, uint64_t start, uint64_t timeout,
35 bool privileged, bool can_read_security_logs)
Tom Cherrycef47bb2020-05-04 17:10:16 -070036 : 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 Cherry79d54f72020-05-04 11:13:55 -070047 privileged_(privileged),
48 can_read_security_logs_(can_read_security_logs) {
Tom Cherrycef47bb2020-05-04 17:10:16 -070049 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 Salyzyn77187782015-05-12 15:21:31 -070053 cleanSkip_Locked();
Mark Salyzyna16f7612014-08-07 08:16:52 -070054}
Mark Salyzyn0175b072014-02-26 09:50:16 -080055
Tom Cherry6ec71e92020-05-04 12:53:36 -070056bool LogReaderThread::startReader_Locked() {
Tom Cherrycef47bb2020-05-04 17:10:16 -070057 auto thread = std::thread{&LogReaderThread::ThreadFunction, this};
58 thread.detach();
59 return true;
Mark Salyzyn0175b072014-02-26 09:50:16 -080060}
61
Tom Cherrycef47bb2020-05-04 17:10:16 -070062void LogReaderThread::ThreadFunction() {
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070063 prctl(PR_SET_NAME, "logd.reader.per");
64
Tom Cherrycef47bb2020-05-04 17:10:16 -070065 SocketClient* client = client_;
Mark Salyzyn0175b072014-02-26 09:50:16 -080066
Tom Cherrycef47bb2020-05-04 17:10:16 -070067 LogBuffer& logbuf = reader_.logbuf();
Mark Salyzyn0175b072014-02-26 09:50:16 -080068
Tom Cherrycef47bb2020-05-04 17:10:16 -070069 leading_dropped_ = true;
Mark Salyzyn047cc072015-06-04 13:35:30 -070070
Mark Salyzyn3c501b52017-04-18 14:09:45 -070071 wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -080072
Tom Cherrycef47bb2020-05-04 17:10:16 -070073 uint64_t start = start_;
Mark Salyzyn0175b072014-02-26 09:50:16 -080074
Tom Cherrycef47bb2020-05-04 17:10:16 -070075 while (!release_) {
76 if (timeout_.tv_sec || timeout_.tv_nsec) {
77 if (pthread_cond_clockwait(&thread_triggered_condition_, &timesLock, CLOCK_MONOTONIC,
78 &timeout_) == ETIMEDOUT) {
79 timeout_.tv_sec = 0;
80 timeout_.tv_nsec = 0;
Mark Salyzynb75cce02015-11-30 11:35:56 -080081 }
Tom Cherrycef47bb2020-05-04 17:10:16 -070082 if (release_) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080083 break;
84 }
85 }
86
Mark Salyzyn0175b072014-02-26 09:50:16 -080087 unlock();
88
Tom Cherrycef47bb2020-05-04 17:10:16 -070089 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 Salyzyn0175b072014-02-26 09:50:16 -080095 }
Tom Cherrycef47bb2020-05-04 17:10:16 -070096 start = logbuf.flushTo(client, start, last_tid_, privileged_, can_read_security_logs_,
97 std::bind(&LogReaderThread::FilterSecondPass, this, _1));
Mark Salyzyn0175b072014-02-26 09:50:16 -080098
Tom Cherry65ab7fe2019-08-21 14:53:06 -070099 // 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 Cherrycef47bb2020-05-04 17:10:16 -0700105 start_time_.tv_sec = 0;
106 start_time_.tv_nsec = 0;
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700107
Mark Salyzyn3c501b52017-04-18 14:09:45 -0700108 wrlock();
Mark Salyzyna16f7612014-08-07 08:16:52 -0700109
Mark Salyzyn0175b072014-02-26 09:50:16 -0800110 if (start == LogBufferElement::FLUSH_ERROR) {
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700111 break;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800112 }
113
Tom Cherrycef47bb2020-05-04 17:10:16 -0700114 start_ = start + 1;
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700115
Tom Cherrycef47bb2020-05-04 17:10:16 -0700116 if (non_block_ || release_) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800117 break;
118 }
119
Tom Cherrycef47bb2020-05-04 17:10:16 -0700120 cleanSkip_Locked();
TraianX Schiauda6495d2014-12-17 10:53:41 +0200121
Tom Cherrycef47bb2020-05-04 17:10:16 -0700122 if (!timeout_.tv_sec && !timeout_.tv_nsec) {
123 pthread_cond_wait(&thread_triggered_condition_, &timesLock);
Mark Salyzynb75cce02015-11-30 11:35:56 -0800124 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800125 }
126
Tom Cherrycef47bb2020-05-04 17:10:16 -0700127 LogReader& reader = reader_;
Tom Cherry4f227862018-10-08 17:33:50 -0700128 reader.release(client);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800129
Tom Cherry4f227862018-10-08 17:33:50 -0700130 client->decRef();
131
132 LastLogTimes& times = reader.logbuf().mTimes;
Tom Cherry6ec71e92020-05-04 12:53:36 -0700133 auto it = std::find_if(times.begin(), times.end(),
Tom Cherrycef47bb2020-05-04 17:10:16 -0700134 [this](const auto& other) { return other.get() == this; });
Tom Cherry4f227862018-10-08 17:33:50 -0700135
136 if (it != times.end()) {
137 times.erase(it);
138 }
139
140 unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800141}
142
143// A first pass to count the number of elements
Tom Cherrycef47bb2020-05-04 17:10:16 -0700144int LogReaderThread::FilterFirstPass(const LogBufferElement* element) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700145 LogReaderThread::wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800146
Tom Cherrycef47bb2020-05-04 17:10:16 -0700147 if (leading_dropped_) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700148 if (element->getDropped()) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700149 LogReaderThread::unlock();
Mark Salyzyn047cc072015-06-04 13:35:30 -0700150 return false;
151 }
Tom Cherrycef47bb2020-05-04 17:10:16 -0700152 leading_dropped_ = false;
Mark Salyzyn047cc072015-06-04 13:35:30 -0700153 }
154
Tom Cherrycef47bb2020-05-04 17:10:16 -0700155 if (count_ == 0) {
156 start_ = element->getSequence();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800157 }
158
Tom Cherrycef47bb2020-05-04 17:10:16 -0700159 if ((!pid_ || pid_ == element->getPid()) && IsWatching(element->getLogId()) &&
160 (start_time_ == log_time::EPOCH || start_time_ <= element->getRealTime())) {
161 ++count_;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800162 }
163
Tom Cherry6ec71e92020-05-04 12:53:36 -0700164 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800165
166 return false;
167}
168
169// A second pass to send the selected elements
Tom Cherrycef47bb2020-05-04 17:10:16 -0700170int LogReaderThread::FilterSecondPass(const LogBufferElement* element) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700171 LogReaderThread::wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800172
Tom Cherrycef47bb2020-05-04 17:10:16 -0700173 start_ = element->getSequence();
TraianX Schiauda6495d2014-12-17 10:53:41 +0200174
Tom Cherrycef47bb2020-05-04 17:10:16 -0700175 if (skip_ahead_[element->getLogId()]) {
176 skip_ahead_[element->getLogId()]--;
Mark Salyzyn8d7656b2014-06-05 15:58:43 -0700177 goto skip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800178 }
179
Tom Cherrycef47bb2020-05-04 17:10:16 -0700180 if (leading_dropped_) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700181 if (element->getDropped()) {
182 goto skip;
183 }
Tom Cherrycef47bb2020-05-04 17:10:16 -0700184 leading_dropped_ = false;
Mark Salyzyn047cc072015-06-04 13:35:30 -0700185 }
186
Mark Salyzyn0175b072014-02-26 09:50:16 -0800187 // Truncate to close race between first and second pass
Tom Cherrycef47bb2020-05-04 17:10:16 -0700188 if (non_block_ && tail_ && index_ >= count_) {
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800189 goto stop;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800190 }
191
Tom Cherrycef47bb2020-05-04 17:10:16 -0700192 if (!IsWatching(element->getLogId())) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800193 goto skip;
194 }
195
Tom Cherrycef47bb2020-05-04 17:10:16 -0700196 if (pid_ && pid_ != element->getPid()) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800197 goto skip;
198 }
199
Tom Cherrycef47bb2020-05-04 17:10:16 -0700200 if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) {
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700201 goto skip;
202 }
203
Tom Cherrycef47bb2020-05-04 17:10:16 -0700204 if (release_) {
Jintao_Zhu5f930722018-11-11 03:13:24 -0800205 goto stop;
206 }
207
Tom Cherrycef47bb2020-05-04 17:10:16 -0700208 if (!tail_) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800209 goto ok;
210 }
211
Tom Cherrycef47bb2020-05-04 17:10:16 -0700212 ++index_;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800213
Tom Cherrycef47bb2020-05-04 17:10:16 -0700214 if (count_ > tail_ && index_ <= (count_ - tail_)) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800215 goto skip;
216 }
217
Tom Cherrycef47bb2020-05-04 17:10:16 -0700218 if (!non_block_) {
219 tail_ = 0;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800220 }
221
222ok:
Tom Cherrycef47bb2020-05-04 17:10:16 -0700223 if (!skip_ahead_[element->getLogId()]) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700224 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800225 return true;
226 }
Tom Cherry6ec71e92020-05-04 12:53:36 -0700227 // FALLTHRU
Mark Salyzyn0175b072014-02-26 09:50:16 -0800228
229skip:
Tom Cherry6ec71e92020-05-04 12:53:36 -0700230 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800231 return false;
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800232
233stop:
Tom Cherry6ec71e92020-05-04 12:53:36 -0700234 LogReaderThread::unlock();
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800235 return -1;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800236}
TraianX Schiauda6495d2014-12-17 10:53:41 +0200237
Tom Cherry6ec71e92020-05-04 12:53:36 -0700238void LogReaderThread::cleanSkip_Locked(void) {
Tom Cherrycef47bb2020-05-04 17:10:16 -0700239 memset(skip_ahead_, 0, sizeof(skip_ahead_));
TraianX Schiauda6495d2014-12-17 10:53:41 +0200240}