blob: 8efc282f7da6c499e0401141ca768259a6fcc783 [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
Mark Salyzyn0175b072014-02-26 09:50:16 -080023#include "LogBuffer.h"
Mark Salyzyn0175b072014-02-26 09:50:16 -080024#include "LogReader.h"
25
Tom Cherry320f5962020-05-04 17:25:34 -070026using namespace std::placeholders;
27
Tom Cherry6ec71e92020-05-04 12:53:36 -070028pthread_mutex_t LogReaderThread::timesLock = PTHREAD_MUTEX_INITIALIZER;
Mark Salyzyn0175b072014-02-26 09:50:16 -080029
Tom Cherry6ec71e92020-05-04 12:53:36 -070030LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool non_block,
31 unsigned long tail, log_mask_t log_mask, pid_t pid,
32 log_time start_time, uint64_t start, uint64_t timeout,
33 bool privileged, bool can_read_security_logs)
Tom Cherry4f227862018-10-08 17:33:50 -070034 : leadingDropped(false),
Mark Salyzyn501c3732017-03-10 14:31:54 -080035 mReader(reader),
Tom Cherry6ec71e92020-05-04 12:53:36 -070036 mLogMask(log_mask),
Mark Salyzyn501c3732017-03-10 14:31:54 -080037 mPid(pid),
38 mCount(0),
39 mTail(tail),
40 mIndex(0),
41 mClient(client),
Tom Cherry65ab7fe2019-08-21 14:53:06 -070042 mStartTime(start_time),
Mark Salyzyn501c3732017-03-10 14:31:54 -080043 mStart(start),
Tom Cherry6ec71e92020-05-04 12:53:36 -070044 mNonBlock(non_block),
Tom Cherry79d54f72020-05-04 11:13:55 -070045 privileged_(privileged),
46 can_read_security_logs_(can_read_security_logs) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080047 mTimeout.tv_sec = timeout / NS_PER_SEC;
48 mTimeout.tv_nsec = timeout % NS_PER_SEC;
Mark Salyzynae2abf12017-03-31 10:48:39 -070049 memset(mLastTid, 0, sizeof(mLastTid));
50 pthread_cond_init(&threadTriggeredCondition, nullptr);
Mark Salyzyn77187782015-05-12 15:21:31 -070051 cleanSkip_Locked();
Mark Salyzyna16f7612014-08-07 08:16:52 -070052}
Mark Salyzyn0175b072014-02-26 09:50:16 -080053
Tom Cherry6ec71e92020-05-04 12:53:36 -070054bool LogReaderThread::startReader_Locked() {
Mark Salyzyn765f7822014-04-04 12:47:44 -070055 pthread_attr_t attr;
56
Mark Salyzyn765f7822014-04-04 12:47:44 -070057 if (!pthread_attr_init(&attr)) {
58 if (!pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
Tom Cherry6ec71e92020-05-04 12:53:36 -070059 if (!pthread_create(&mThread, &attr, LogReaderThread::threadStart, this)) {
Mark Salyzyn765f7822014-04-04 12:47:44 -070060 pthread_attr_destroy(&attr);
Tom Cherry4f227862018-10-08 17:33:50 -070061 return true;
Mark Salyzyn765f7822014-04-04 12:47:44 -070062 }
Mark Salyzyn0175b072014-02-26 09:50:16 -080063 }
Mark Salyzyn765f7822014-04-04 12:47:44 -070064 pthread_attr_destroy(&attr);
Mark Salyzyn0175b072014-02-26 09:50:16 -080065 }
Mark Salyzyn0175b072014-02-26 09:50:16 -080066
Tom Cherry4f227862018-10-08 17:33:50 -070067 return false;
Mark Salyzyn0175b072014-02-26 09:50:16 -080068}
69
Tom Cherry6ec71e92020-05-04 12:53:36 -070070void* LogReaderThread::threadStart(void* obj) {
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070071 prctl(PR_SET_NAME, "logd.reader.per");
72
Tom Cherry6ec71e92020-05-04 12:53:36 -070073 LogReaderThread* me = reinterpret_cast<LogReaderThread*>(obj);
Mark Salyzyn0175b072014-02-26 09:50:16 -080074
Mark Salyzyn501c3732017-03-10 14:31:54 -080075 SocketClient* client = me->mClient;
Mark Salyzyn0175b072014-02-26 09:50:16 -080076
Mark Salyzyn501c3732017-03-10 14:31:54 -080077 LogBuffer& logbuf = me->mReader.logbuf();
Mark Salyzyn0175b072014-02-26 09:50:16 -080078
Mark Salyzyn047cc072015-06-04 13:35:30 -070079 me->leadingDropped = true;
80
Mark Salyzyn3c501b52017-04-18 14:09:45 -070081 wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -080082
Tom Cherry10d086e2019-08-21 14:16:34 -070083 uint64_t start = me->mStart;
Mark Salyzyn0175b072014-02-26 09:50:16 -080084
Tom Cherry4f227862018-10-08 17:33:50 -070085 while (!me->mRelease) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080086 if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) {
Tom Cherryc9fa42c2020-04-08 10:37:09 -070087 if (pthread_cond_clockwait(&me->threadTriggeredCondition, &timesLock, CLOCK_MONOTONIC,
88 &me->mTimeout) == ETIMEDOUT) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080089 me->mTimeout.tv_sec = 0;
90 me->mTimeout.tv_nsec = 0;
91 }
Tom Cherry4f227862018-10-08 17:33:50 -070092 if (me->mRelease) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080093 break;
94 }
95 }
96
Mark Salyzyn0175b072014-02-26 09:50:16 -080097 unlock();
98
99 if (me->mTail) {
Tom Cherry79d54f72020-05-04 11:13:55 -0700100 logbuf.flushTo(client, start, nullptr, me->privileged_, me->can_read_security_logs_,
Tom Cherry320f5962020-05-04 17:25:34 -0700101 std::bind(&LogReaderThread::FilterFirstPass, _1, me));
Mark Salyzyn047cc072015-06-04 13:35:30 -0700102 me->leadingDropped = true;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800103 }
Tom Cherry79d54f72020-05-04 11:13:55 -0700104 start = logbuf.flushTo(client, start, me->mLastTid, me->privileged_,
Tom Cherry320f5962020-05-04 17:25:34 -0700105 me->can_read_security_logs_,
106 std::bind(&LogReaderThread::FilterSecondPass, _1, me));
Mark Salyzyn0175b072014-02-26 09:50:16 -0800107
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700108 // We only ignore entries before the original start time for the first flushTo(), if we
109 // get entries after this first flush before the original start time, then the client
110 // wouldn't have seen them.
111 // Note: this is still racy and may skip out of order events that came in since the last
112 // time the client disconnected and then reconnected with the new start time. The long term
113 // solution here is that clients must request events since a specific sequence number.
114 me->mStartTime.tv_sec = 0;
115 me->mStartTime.tv_nsec = 0;
116
Mark Salyzyn3c501b52017-04-18 14:09:45 -0700117 wrlock();
Mark Salyzyna16f7612014-08-07 08:16:52 -0700118
Mark Salyzyn0175b072014-02-26 09:50:16 -0800119 if (start == LogBufferElement::FLUSH_ERROR) {
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700120 break;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800121 }
122
Tom Cherry10d086e2019-08-21 14:16:34 -0700123 me->mStart = start + 1;
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700124
Tom Cherry4f227862018-10-08 17:33:50 -0700125 if (me->mNonBlock || me->mRelease) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800126 break;
127 }
128
TraianX Schiauda6495d2014-12-17 10:53:41 +0200129 me->cleanSkip_Locked();
130
Mark Salyzynb75cce02015-11-30 11:35:56 -0800131 if (!me->mTimeout.tv_sec && !me->mTimeout.tv_nsec) {
132 pthread_cond_wait(&me->threadTriggeredCondition, &timesLock);
133 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800134 }
135
Tom Cherry4f227862018-10-08 17:33:50 -0700136 LogReader& reader = me->mReader;
137 reader.release(client);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800138
Tom Cherry4f227862018-10-08 17:33:50 -0700139 client->decRef();
140
141 LastLogTimes& times = reader.logbuf().mTimes;
Tom Cherry6ec71e92020-05-04 12:53:36 -0700142 auto it = std::find_if(times.begin(), times.end(),
143 [&me](const auto& other) { return other.get() == me; });
Tom Cherry4f227862018-10-08 17:33:50 -0700144
145 if (it != times.end()) {
146 times.erase(it);
147 }
148
149 unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800150
Mark Salyzynae2abf12017-03-31 10:48:39 -0700151 return nullptr;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800152}
153
154// A first pass to count the number of elements
Tom Cherry6ec71e92020-05-04 12:53:36 -0700155int LogReaderThread::FilterFirstPass(const LogBufferElement* element, void* obj) {
156 LogReaderThread* me = reinterpret_cast<LogReaderThread*>(obj);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800157
Tom Cherry6ec71e92020-05-04 12:53:36 -0700158 LogReaderThread::wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800159
Mark Salyzyn047cc072015-06-04 13:35:30 -0700160 if (me->leadingDropped) {
161 if (element->getDropped()) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700162 LogReaderThread::unlock();
Mark Salyzyn047cc072015-06-04 13:35:30 -0700163 return false;
164 }
165 me->leadingDropped = false;
166 }
167
Mark Salyzyn0175b072014-02-26 09:50:16 -0800168 if (me->mCount == 0) {
Tom Cherry10d086e2019-08-21 14:16:34 -0700169 me->mStart = element->getSequence();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800170 }
171
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700172 if ((!me->mPid || me->mPid == element->getPid()) && me->isWatching(element->getLogId()) &&
173 (me->mStartTime == log_time::EPOCH || me->mStartTime <= element->getRealTime())) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800174 ++me->mCount;
175 }
176
Tom Cherry6ec71e92020-05-04 12:53:36 -0700177 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800178
179 return false;
180}
181
182// A second pass to send the selected elements
Tom Cherry6ec71e92020-05-04 12:53:36 -0700183int LogReaderThread::FilterSecondPass(const LogBufferElement* element, void* obj) {
184 LogReaderThread* me = reinterpret_cast<LogReaderThread*>(obj);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800185
Tom Cherry6ec71e92020-05-04 12:53:36 -0700186 LogReaderThread::wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800187
Tom Cherry10d086e2019-08-21 14:16:34 -0700188 me->mStart = element->getSequence();
TraianX Schiauda6495d2014-12-17 10:53:41 +0200189
190 if (me->skipAhead[element->getLogId()]) {
191 me->skipAhead[element->getLogId()]--;
Mark Salyzyn8d7656b2014-06-05 15:58:43 -0700192 goto skip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800193 }
194
Mark Salyzyn047cc072015-06-04 13:35:30 -0700195 if (me->leadingDropped) {
196 if (element->getDropped()) {
197 goto skip;
198 }
199 me->leadingDropped = false;
200 }
201
Mark Salyzyn0175b072014-02-26 09:50:16 -0800202 // Truncate to close race between first and second pass
203 if (me->mNonBlock && me->mTail && (me->mIndex >= me->mCount)) {
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800204 goto stop;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800205 }
206
TraianX Schiauda6495d2014-12-17 10:53:41 +0200207 if (!me->isWatching(element->getLogId())) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800208 goto skip;
209 }
210
211 if (me->mPid && (me->mPid != element->getPid())) {
212 goto skip;
213 }
214
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700215 if (me->mStartTime != log_time::EPOCH && element->getRealTime() <= me->mStartTime) {
216 goto skip;
217 }
218
Jintao_Zhu5f930722018-11-11 03:13:24 -0800219 if (me->mRelease) {
220 goto stop;
221 }
222
Mark Salyzyn0175b072014-02-26 09:50:16 -0800223 if (!me->mTail) {
224 goto ok;
225 }
226
227 ++me->mIndex;
228
229 if ((me->mCount > me->mTail) && (me->mIndex <= (me->mCount - me->mTail))) {
230 goto skip;
231 }
232
233 if (!me->mNonBlock) {
234 me->mTail = 0;
235 }
236
237ok:
TraianX Schiauda6495d2014-12-17 10:53:41 +0200238 if (!me->skipAhead[element->getLogId()]) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700239 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800240 return true;
241 }
Tom Cherry6ec71e92020-05-04 12:53:36 -0700242 // FALLTHRU
Mark Salyzyn0175b072014-02-26 09:50:16 -0800243
244skip:
Tom Cherry6ec71e92020-05-04 12:53:36 -0700245 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800246 return false;
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800247
248stop:
Tom Cherry6ec71e92020-05-04 12:53:36 -0700249 LogReaderThread::unlock();
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800250 return -1;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800251}
TraianX Schiauda6495d2014-12-17 10:53:41 +0200252
Tom Cherry6ec71e92020-05-04 12:53:36 -0700253void LogReaderThread::cleanSkip_Locked(void) {
Mark Salyzynae2abf12017-03-31 10:48:39 -0700254 memset(skipAhead, 0, sizeof(skipAhead));
TraianX Schiauda6495d2014-12-17 10:53:41 +0200255}