blob: f1452a663c25a555a5eab58d06fb34a20008c4b4 [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 Cherry6ec71e92020-05-04 12:53:36 -070026pthread_mutex_t LogReaderThread::timesLock = PTHREAD_MUTEX_INITIALIZER;
Mark Salyzyn0175b072014-02-26 09:50:16 -080027
Tom Cherry6ec71e92020-05-04 12:53:36 -070028LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool non_block,
29 unsigned long tail, log_mask_t log_mask, pid_t pid,
30 log_time start_time, uint64_t start, uint64_t timeout,
31 bool privileged, bool can_read_security_logs)
Tom Cherry4f227862018-10-08 17:33:50 -070032 : leadingDropped(false),
Mark Salyzyn501c3732017-03-10 14:31:54 -080033 mReader(reader),
Tom Cherry6ec71e92020-05-04 12:53:36 -070034 mLogMask(log_mask),
Mark Salyzyn501c3732017-03-10 14:31:54 -080035 mPid(pid),
36 mCount(0),
37 mTail(tail),
38 mIndex(0),
39 mClient(client),
Tom Cherry65ab7fe2019-08-21 14:53:06 -070040 mStartTime(start_time),
Mark Salyzyn501c3732017-03-10 14:31:54 -080041 mStart(start),
Tom Cherry6ec71e92020-05-04 12:53:36 -070042 mNonBlock(non_block),
Tom Cherry79d54f72020-05-04 11:13:55 -070043 privileged_(privileged),
44 can_read_security_logs_(can_read_security_logs) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080045 mTimeout.tv_sec = timeout / NS_PER_SEC;
46 mTimeout.tv_nsec = timeout % NS_PER_SEC;
Mark Salyzynae2abf12017-03-31 10:48:39 -070047 memset(mLastTid, 0, sizeof(mLastTid));
48 pthread_cond_init(&threadTriggeredCondition, nullptr);
Mark Salyzyn77187782015-05-12 15:21:31 -070049 cleanSkip_Locked();
Mark Salyzyna16f7612014-08-07 08:16:52 -070050}
Mark Salyzyn0175b072014-02-26 09:50:16 -080051
Tom Cherry6ec71e92020-05-04 12:53:36 -070052bool LogReaderThread::startReader_Locked() {
Mark Salyzyn765f7822014-04-04 12:47:44 -070053 pthread_attr_t attr;
54
Mark Salyzyn765f7822014-04-04 12:47:44 -070055 if (!pthread_attr_init(&attr)) {
56 if (!pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
Tom Cherry6ec71e92020-05-04 12:53:36 -070057 if (!pthread_create(&mThread, &attr, LogReaderThread::threadStart, this)) {
Mark Salyzyn765f7822014-04-04 12:47:44 -070058 pthread_attr_destroy(&attr);
Tom Cherry4f227862018-10-08 17:33:50 -070059 return true;
Mark Salyzyn765f7822014-04-04 12:47:44 -070060 }
Mark Salyzyn0175b072014-02-26 09:50:16 -080061 }
Mark Salyzyn765f7822014-04-04 12:47:44 -070062 pthread_attr_destroy(&attr);
Mark Salyzyn0175b072014-02-26 09:50:16 -080063 }
Mark Salyzyn0175b072014-02-26 09:50:16 -080064
Tom Cherry4f227862018-10-08 17:33:50 -070065 return false;
Mark Salyzyn0175b072014-02-26 09:50:16 -080066}
67
Tom Cherry6ec71e92020-05-04 12:53:36 -070068void* LogReaderThread::threadStart(void* obj) {
Mark Salyzyn8daa9af2014-04-28 14:07:23 -070069 prctl(PR_SET_NAME, "logd.reader.per");
70
Tom Cherry6ec71e92020-05-04 12:53:36 -070071 LogReaderThread* me = reinterpret_cast<LogReaderThread*>(obj);
Mark Salyzyn0175b072014-02-26 09:50:16 -080072
Mark Salyzyn501c3732017-03-10 14:31:54 -080073 SocketClient* client = me->mClient;
Mark Salyzyn0175b072014-02-26 09:50:16 -080074
Mark Salyzyn501c3732017-03-10 14:31:54 -080075 LogBuffer& logbuf = me->mReader.logbuf();
Mark Salyzyn0175b072014-02-26 09:50:16 -080076
Mark Salyzyn047cc072015-06-04 13:35:30 -070077 me->leadingDropped = true;
78
Mark Salyzyn3c501b52017-04-18 14:09:45 -070079 wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -080080
Tom Cherry10d086e2019-08-21 14:16:34 -070081 uint64_t start = me->mStart;
Mark Salyzyn0175b072014-02-26 09:50:16 -080082
Tom Cherry4f227862018-10-08 17:33:50 -070083 while (!me->mRelease) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080084 if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) {
Tom Cherryc9fa42c2020-04-08 10:37:09 -070085 if (pthread_cond_clockwait(&me->threadTriggeredCondition, &timesLock, CLOCK_MONOTONIC,
86 &me->mTimeout) == ETIMEDOUT) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080087 me->mTimeout.tv_sec = 0;
88 me->mTimeout.tv_nsec = 0;
89 }
Tom Cherry4f227862018-10-08 17:33:50 -070090 if (me->mRelease) {
Mark Salyzynb75cce02015-11-30 11:35:56 -080091 break;
92 }
93 }
94
Mark Salyzyn0175b072014-02-26 09:50:16 -080095 unlock();
96
97 if (me->mTail) {
Tom Cherry79d54f72020-05-04 11:13:55 -070098 logbuf.flushTo(client, start, nullptr, me->privileged_, me->can_read_security_logs_,
Mark Salyzynae2abf12017-03-31 10:48:39 -070099 FilterFirstPass, me);
Mark Salyzyn047cc072015-06-04 13:35:30 -0700100 me->leadingDropped = true;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800101 }
Tom Cherry79d54f72020-05-04 11:13:55 -0700102 start = logbuf.flushTo(client, start, me->mLastTid, me->privileged_,
103 me->can_read_security_logs_, FilterSecondPass, me);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800104
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700105 // We only ignore entries before the original start time for the first flushTo(), if we
106 // get entries after this first flush before the original start time, then the client
107 // wouldn't have seen them.
108 // Note: this is still racy and may skip out of order events that came in since the last
109 // time the client disconnected and then reconnected with the new start time. The long term
110 // solution here is that clients must request events since a specific sequence number.
111 me->mStartTime.tv_sec = 0;
112 me->mStartTime.tv_nsec = 0;
113
Mark Salyzyn3c501b52017-04-18 14:09:45 -0700114 wrlock();
Mark Salyzyna16f7612014-08-07 08:16:52 -0700115
Mark Salyzyn0175b072014-02-26 09:50:16 -0800116 if (start == LogBufferElement::FLUSH_ERROR) {
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700117 break;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800118 }
119
Tom Cherry10d086e2019-08-21 14:16:34 -0700120 me->mStart = start + 1;
Mark Salyzynde4bb9c2015-09-16 15:34:00 -0700121
Tom Cherry4f227862018-10-08 17:33:50 -0700122 if (me->mNonBlock || me->mRelease) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800123 break;
124 }
125
TraianX Schiauda6495d2014-12-17 10:53:41 +0200126 me->cleanSkip_Locked();
127
Mark Salyzynb75cce02015-11-30 11:35:56 -0800128 if (!me->mTimeout.tv_sec && !me->mTimeout.tv_nsec) {
129 pthread_cond_wait(&me->threadTriggeredCondition, &timesLock);
130 }
Mark Salyzyn0175b072014-02-26 09:50:16 -0800131 }
132
Tom Cherry4f227862018-10-08 17:33:50 -0700133 LogReader& reader = me->mReader;
134 reader.release(client);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800135
Tom Cherry4f227862018-10-08 17:33:50 -0700136 client->decRef();
137
138 LastLogTimes& times = reader.logbuf().mTimes;
Tom Cherry6ec71e92020-05-04 12:53:36 -0700139 auto it = std::find_if(times.begin(), times.end(),
140 [&me](const auto& other) { return other.get() == me; });
Tom Cherry4f227862018-10-08 17:33:50 -0700141
142 if (it != times.end()) {
143 times.erase(it);
144 }
145
146 unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800147
Mark Salyzynae2abf12017-03-31 10:48:39 -0700148 return nullptr;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800149}
150
151// A first pass to count the number of elements
Tom Cherry6ec71e92020-05-04 12:53:36 -0700152int LogReaderThread::FilterFirstPass(const LogBufferElement* element, void* obj) {
153 LogReaderThread* me = reinterpret_cast<LogReaderThread*>(obj);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800154
Tom Cherry6ec71e92020-05-04 12:53:36 -0700155 LogReaderThread::wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800156
Mark Salyzyn047cc072015-06-04 13:35:30 -0700157 if (me->leadingDropped) {
158 if (element->getDropped()) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700159 LogReaderThread::unlock();
Mark Salyzyn047cc072015-06-04 13:35:30 -0700160 return false;
161 }
162 me->leadingDropped = false;
163 }
164
Mark Salyzyn0175b072014-02-26 09:50:16 -0800165 if (me->mCount == 0) {
Tom Cherry10d086e2019-08-21 14:16:34 -0700166 me->mStart = element->getSequence();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800167 }
168
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700169 if ((!me->mPid || me->mPid == element->getPid()) && me->isWatching(element->getLogId()) &&
170 (me->mStartTime == log_time::EPOCH || me->mStartTime <= element->getRealTime())) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800171 ++me->mCount;
172 }
173
Tom Cherry6ec71e92020-05-04 12:53:36 -0700174 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800175
176 return false;
177}
178
179// A second pass to send the selected elements
Tom Cherry6ec71e92020-05-04 12:53:36 -0700180int LogReaderThread::FilterSecondPass(const LogBufferElement* element, void* obj) {
181 LogReaderThread* me = reinterpret_cast<LogReaderThread*>(obj);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800182
Tom Cherry6ec71e92020-05-04 12:53:36 -0700183 LogReaderThread::wrlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800184
Tom Cherry10d086e2019-08-21 14:16:34 -0700185 me->mStart = element->getSequence();
TraianX Schiauda6495d2014-12-17 10:53:41 +0200186
187 if (me->skipAhead[element->getLogId()]) {
188 me->skipAhead[element->getLogId()]--;
Mark Salyzyn8d7656b2014-06-05 15:58:43 -0700189 goto skip;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800190 }
191
Mark Salyzyn047cc072015-06-04 13:35:30 -0700192 if (me->leadingDropped) {
193 if (element->getDropped()) {
194 goto skip;
195 }
196 me->leadingDropped = false;
197 }
198
Mark Salyzyn0175b072014-02-26 09:50:16 -0800199 // Truncate to close race between first and second pass
200 if (me->mNonBlock && me->mTail && (me->mIndex >= me->mCount)) {
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800201 goto stop;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800202 }
203
TraianX Schiauda6495d2014-12-17 10:53:41 +0200204 if (!me->isWatching(element->getLogId())) {
Mark Salyzyn0175b072014-02-26 09:50:16 -0800205 goto skip;
206 }
207
208 if (me->mPid && (me->mPid != element->getPid())) {
209 goto skip;
210 }
211
Tom Cherry65ab7fe2019-08-21 14:53:06 -0700212 if (me->mStartTime != log_time::EPOCH && element->getRealTime() <= me->mStartTime) {
213 goto skip;
214 }
215
Jintao_Zhu5f930722018-11-11 03:13:24 -0800216 if (me->mRelease) {
217 goto stop;
218 }
219
Mark Salyzyn0175b072014-02-26 09:50:16 -0800220 if (!me->mTail) {
221 goto ok;
222 }
223
224 ++me->mIndex;
225
226 if ((me->mCount > me->mTail) && (me->mIndex <= (me->mCount - me->mTail))) {
227 goto skip;
228 }
229
230 if (!me->mNonBlock) {
231 me->mTail = 0;
232 }
233
234ok:
TraianX Schiauda6495d2014-12-17 10:53:41 +0200235 if (!me->skipAhead[element->getLogId()]) {
Tom Cherry6ec71e92020-05-04 12:53:36 -0700236 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800237 return true;
238 }
Tom Cherry6ec71e92020-05-04 12:53:36 -0700239 // FALLTHRU
Mark Salyzyn0175b072014-02-26 09:50:16 -0800240
241skip:
Tom Cherry6ec71e92020-05-04 12:53:36 -0700242 LogReaderThread::unlock();
Mark Salyzyn0175b072014-02-26 09:50:16 -0800243 return false;
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800244
245stop:
Tom Cherry6ec71e92020-05-04 12:53:36 -0700246 LogReaderThread::unlock();
Mark Salyzynf7c0f752015-03-03 13:39:37 -0800247 return -1;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800248}
TraianX Schiauda6495d2014-12-17 10:53:41 +0200249
Tom Cherry6ec71e92020-05-04 12:53:36 -0700250void LogReaderThread::cleanSkip_Locked(void) {
Mark Salyzynae2abf12017-03-31 10:48:39 -0700251 memset(skipAhead, 0, sizeof(skipAhead));
TraianX Schiauda6495d2014-12-17 10:53:41 +0200252}