1 /*
2 * Copyright (C) 2020 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
17 #include "chre/platform/shared/log_buffer.h"
18 #include "chre/platform/assert.h"
19 #include "chre/platform/shared/generated/host_messages_generated.h"
20 #include "chre/util/lock_guard.h"
21
22 #include <cstdarg>
23 #include <cstdio>
24
25 namespace chre {
26
27 using LogType = fbs::LogType;
28
LogBuffer(LogBufferCallbackInterface * callback,void * buffer,size_t bufferSize)29 LogBuffer::LogBuffer(LogBufferCallbackInterface *callback, void *buffer,
30 size_t bufferSize)
31 : mBufferData(static_cast<uint8_t *>(buffer)),
32 mBufferMaxSize(bufferSize),
33 mCallback(callback) {
34 CHRE_ASSERT(bufferSize >= kBufferMinSize);
35 }
36
handleLog(LogBufferLogLevel logLevel,uint32_t timestampMs,const char * logFormat,...)37 void LogBuffer::handleLog(LogBufferLogLevel logLevel, uint32_t timestampMs,
38 const char *logFormat, ...) {
39 va_list args;
40 va_start(args, logFormat);
41 handleLogVa(logLevel, timestampMs, logFormat, args);
42 va_end(args);
43 }
44
handleLogVa(LogBufferLogLevel logLevel,uint32_t timestampMs,const char * logFormat,va_list args)45 void LogBuffer::handleLogVa(LogBufferLogLevel logLevel, uint32_t timestampMs,
46 const char *logFormat, va_list args) {
47 char tempBuffer[kLogMaxSize];
48 int logLenSigned = vsnprintf(tempBuffer, kLogMaxSize, logFormat, args);
49 processLog(logLevel, timestampMs, tempBuffer, logLenSigned, LogType::STRING);
50 }
51
52 #ifdef CHRE_BLE_SUPPORT_ENABLED
handleBtLog(BtSnoopDirection direction,uint32_t timestampMs,const uint8_t * buffer,size_t size)53 void LogBuffer::handleBtLog(BtSnoopDirection direction, uint32_t timestampMs,
54 const uint8_t *buffer, size_t size) {
55 if (size == 0) {
56 return;
57 }
58 auto logLen = static_cast<uint8_t>(size);
59
60 if (size < kLogMaxSize) {
61 LockGuard<Mutex> lockGuard(mLock);
62
63 static_assert(sizeof(LogType) == sizeof(uint8_t),
64 "LogType size is not equal to size of uint8_t");
65 static_assert(sizeof(direction) == sizeof(uint8_t),
66 "BtSnoopDirection size is not equal to the size of uint8_t");
67 uint8_t snoopLogDirection = static_cast<uint8_t>(direction);
68
69 discardExcessOldLogsLocked(logLen + kBtSnoopLogOffset);
70
71 // Set all BT logs to the CHRE_LOG_LEVEL_INFO.
72 uint8_t metadata =
73 setLogMetadata(LogType::BLUETOOTH, LogBufferLogLevel::INFO);
74
75 copyVarToBuffer(&metadata);
76 copyVarToBuffer(×tampMs);
77 copyVarToBuffer(&snoopLogDirection);
78 copyVarToBuffer(&logLen);
79
80 copyToBuffer(logLen, buffer);
81 } else {
82 // Cannot truncate a BT event. Log a failure message instead.
83 constexpr char kBtSnoopLogGenericErrorMsg[] =
84 "Bt Snoop log message too large";
85 static_assert(
86 sizeof(kBtSnoopLogGenericErrorMsg) <= kLogMaxSize,
87 "Error meessage size needs to be smaller than max log length");
88 logLen = static_cast<uint8_t>(sizeof(kBtSnoopLogGenericErrorMsg));
89 copyLogToBuffer(LogBufferLogLevel::INFO, timestampMs,
90 kBtSnoopLogGenericErrorMsg, logLen, LogType::BLUETOOTH);
91 }
92 dispatch();
93 }
94 #endif // CHRE_BLE_SUPPORT_ENABLED
95
handleEncodedLog(LogBufferLogLevel logLevel,uint32_t timestampMs,const uint8_t * log,size_t logSize)96 void LogBuffer::handleEncodedLog(LogBufferLogLevel logLevel,
97 uint32_t timestampMs, const uint8_t *log,
98 size_t logSize) {
99 processLog(logLevel, timestampMs, log, logSize, LogType::TOKENIZED);
100 }
101
handleNanoappTokenizedLog(LogBufferLogLevel logLevel,uint32_t timestampMs,uint16_t instanceId,const uint8_t * log,size_t logSize)102 void LogBuffer::handleNanoappTokenizedLog(LogBufferLogLevel logLevel,
103 uint32_t timestampMs,
104 uint16_t instanceId,
105 const uint8_t *log, size_t logSize) {
106 processLog(logLevel, timestampMs, log, logSize, LogType::NANOAPP_TOKENIZED,
107 instanceId);
108 }
109
copyLogs(void * destination,size_t size,size_t * numLogsDropped)110 size_t LogBuffer::copyLogs(void *destination, size_t size,
111 size_t *numLogsDropped) {
112 LockGuard<Mutex> lock(mLock);
113 return copyLogsLocked(destination, size, numLogsDropped);
114 }
115
logWouldCauseOverflow(size_t logSize)116 bool LogBuffer::logWouldCauseOverflow(size_t logSize) {
117 LockGuard<Mutex> lock(mLock);
118 return (mBufferDataSize + logSize + kLogDataOffset > mBufferMaxSize);
119 }
120
transferTo(LogBuffer & buffer)121 void LogBuffer::transferTo(LogBuffer &buffer) {
122 LockGuard<Mutex> lockGuardOther(buffer.mLock);
123 size_t numLogsDropped;
124 size_t bytesCopied;
125 {
126 LockGuard<Mutex> lockGuardThis(mLock);
127 // The buffer being transferred to should be as big or bigger.
128 CHRE_ASSERT(buffer.mBufferMaxSize >= mBufferMaxSize);
129
130 buffer.resetLocked();
131
132 bytesCopied = copyLogsLocked(buffer.mBufferData, buffer.mBufferMaxSize,
133 &numLogsDropped);
134
135 resetLocked();
136 }
137 buffer.mBufferDataTailIndex = bytesCopied % buffer.mBufferMaxSize;
138 buffer.mBufferDataSize = bytesCopied;
139 buffer.mNumLogsDropped = numLogsDropped;
140 }
141
updateNotificationSetting(LogBufferNotificationSetting setting,size_t thresholdBytes)142 void LogBuffer::updateNotificationSetting(LogBufferNotificationSetting setting,
143 size_t thresholdBytes) {
144 LockGuard<Mutex> lock(mLock);
145
146 mNotificationSetting = setting;
147 mNotificationThresholdBytes = thresholdBytes;
148 }
149
reset()150 void LogBuffer::reset() {
151 LockGuard<Mutex> lock(mLock);
152 resetLocked();
153 }
154
getBufferData()155 const uint8_t *LogBuffer::getBufferData() {
156 return mBufferData;
157 }
158
getBufferSize()159 size_t LogBuffer::getBufferSize() {
160 LockGuard<Mutex> lockGuard(mLock);
161 return mBufferDataSize;
162 }
163
getNumLogsDropped()164 size_t LogBuffer::getNumLogsDropped() {
165 LockGuard<Mutex> lockGuard(mLock);
166 return mNumLogsDropped;
167 }
168
incrementAndModByBufferMaxSize(size_t originalVal,size_t incrementBy) const169 size_t LogBuffer::incrementAndModByBufferMaxSize(size_t originalVal,
170 size_t incrementBy) const {
171 return (originalVal + incrementBy) % mBufferMaxSize;
172 }
173
copyToBuffer(size_t size,const void * source)174 void LogBuffer::copyToBuffer(size_t size, const void *source) {
175 const uint8_t *sourceBytes = static_cast<const uint8_t *>(source);
176 if (mBufferDataTailIndex + size > mBufferMaxSize) {
177 size_t firstSize = mBufferMaxSize - mBufferDataTailIndex;
178 size_t secondSize = size - firstSize;
179 memcpy(&mBufferData[mBufferDataTailIndex], sourceBytes, firstSize);
180 memcpy(mBufferData, &sourceBytes[firstSize], secondSize);
181 } else {
182 memcpy(&mBufferData[mBufferDataTailIndex], sourceBytes, size);
183 }
184 mBufferDataSize += size;
185 mBufferDataTailIndex =
186 incrementAndModByBufferMaxSize(mBufferDataTailIndex, size);
187 }
188
copyFromBuffer(size_t size,void * destination)189 void LogBuffer::copyFromBuffer(size_t size, void *destination) {
190 uint8_t *destinationBytes = static_cast<uint8_t *>(destination);
191 if (mBufferDataHeadIndex + size > mBufferMaxSize) {
192 size_t firstSize = mBufferMaxSize - mBufferDataHeadIndex;
193 size_t secondSize = size - firstSize;
194 memcpy(destinationBytes, &mBufferData[mBufferDataHeadIndex], firstSize);
195 memcpy(&destinationBytes[firstSize], mBufferData, secondSize);
196 } else {
197 memcpy(destinationBytes, &mBufferData[mBufferDataHeadIndex], size);
198 }
199 mBufferDataSize -= size;
200 mBufferDataHeadIndex =
201 incrementAndModByBufferMaxSize(mBufferDataHeadIndex, size);
202 }
203
copyLogsLocked(void * destination,size_t size,size_t * numLogsDropped)204 size_t LogBuffer::copyLogsLocked(void *destination, size_t size,
205 size_t *numLogsDropped) {
206 size_t copySize = 0;
207
208 if (size != 0 && destination != nullptr && mBufferDataSize != 0) {
209 if (size >= mBufferDataSize) {
210 copySize = mBufferDataSize;
211 } else {
212 size_t logSize;
213 size_t logStartIndex = getNextLogIndex(mBufferDataHeadIndex, &logSize);
214 while (copySize + logSize <= size &&
215 copySize + logSize <= mBufferDataSize) {
216 copySize += logSize;
217 logStartIndex = getNextLogIndex(logStartIndex, &logSize);
218 }
219 }
220 copyFromBuffer(copySize, destination);
221 }
222
223 *numLogsDropped = mNumLogsDropped;
224
225 return copySize;
226 }
227
resetLocked()228 void LogBuffer::resetLocked() {
229 mBufferDataHeadIndex = 0;
230 mBufferDataTailIndex = 0;
231 mBufferDataSize = 0;
232 mNumLogsDropped = 0;
233 }
234
getNextLogIndex(size_t startingIndex,size_t * logSize)235 size_t LogBuffer::getNextLogIndex(size_t startingIndex, size_t *logSize) {
236 size_t logDataStartIndex =
237 incrementAndModByBufferMaxSize(startingIndex, kLogDataOffset);
238 LogType type = getLogTypeFromMetadata(mBufferData[startingIndex]);
239 size_t logDataSize = getLogDataLength(logDataStartIndex, type);
240 *logSize = kLogDataOffset + logDataSize;
241 return incrementAndModByBufferMaxSize(startingIndex, *logSize);
242 }
243
getLogDataLength(size_t startingIndex,LogType type)244 size_t LogBuffer::getLogDataLength(size_t startingIndex, LogType type) {
245 size_t currentIndex = startingIndex;
246 size_t numBytes = kLogMaxSize;
247
248 switch (type) {
249 case LogType::STRING:
250 for (size_t i = 0; i < kLogMaxSize; i++) {
251 if (mBufferData[currentIndex] == '\0') {
252 // +1 to include the null terminator
253 numBytes = i + 1;
254 break;
255 }
256 currentIndex = incrementAndModByBufferMaxSize(currentIndex, 1);
257 }
258 break;
259
260 case LogType::TOKENIZED:
261 numBytes = mBufferData[startingIndex] + kTokenizedLogOffset;
262 break;
263
264 case LogType::BLUETOOTH:
265 // +1 to account for the bt snoop direction.
266 currentIndex = incrementAndModByBufferMaxSize(startingIndex, 1);
267 numBytes = mBufferData[currentIndex] + kBtSnoopLogOffset;
268 break;
269
270 case LogType::NANOAPP_TOKENIZED:
271 // +2 to account for the uint16_t instance ID.
272 currentIndex = incrementAndModByBufferMaxSize(startingIndex, 2);
273 numBytes = mBufferData[currentIndex] + kNanoappTokenizedLogOffset;
274 break;
275
276 default:
277 CHRE_ASSERT_LOG(false, "Received unexpected log message type");
278 break;
279 }
280
281 return numBytes;
282 }
283
processLog(LogBufferLogLevel logLevel,uint32_t timestampMs,const void * logBuffer,size_t logSize,LogType type,uint16_t instanceId)284 void LogBuffer::processLog(LogBufferLogLevel logLevel, uint32_t timestampMs,
285 const void *logBuffer, size_t logSize, LogType type,
286 uint16_t instanceId) {
287 if (logSize == 0) {
288 return;
289 }
290 auto logLen = static_cast<uint8_t>(logSize);
291
292 constexpr char kTokenizedLogGenericErrorMsg[] =
293 "Tokenized log message too large";
294
295 // For tokenized logs, need to leave space for the message size offset. For
296 // string logs, need to leave 1 byte for the null terminator at the end.
297 if (type == LogType::STRING && logSize >= kLogMaxSize - 1) {
298 // String logs longer than kLogMaxSize - 1 will be truncated.
299 logLen = static_cast<uint8_t>(kLogMaxSize - 1);
300 } else if (tokenizedLogExceedsMaxSize(type, logSize)) {
301 // There is no way of decoding an encoded message if we truncate it, so
302 // we do the next best thing and try to log a generic failure message
303 // reusing the logbuffer for as much as we can. Note that we also need
304 // flip the encoding flag for proper decoding by the host log message
305 // parser.
306 static_assert(
307 sizeof(kTokenizedLogGenericErrorMsg) <= kLogMaxSize - 1,
308 "Error meessage size needs to be smaller than max log length");
309 logBuffer = kTokenizedLogGenericErrorMsg;
310 logLen = static_cast<uint8_t>(sizeof(kTokenizedLogGenericErrorMsg));
311 type = LogType::STRING;
312 }
313
314 copyLogToBuffer(logLevel, timestampMs, logBuffer, logLen, type, instanceId);
315 dispatch();
316 }
317
copyLogToBuffer(LogBufferLogLevel level,uint32_t timestampMs,const void * logBuffer,uint8_t logLen,LogType type,uint16_t instanceId)318 void LogBuffer::copyLogToBuffer(LogBufferLogLevel level, uint32_t timestampMs,
319 const void *logBuffer, uint8_t logLen,
320 LogType type, uint16_t instanceId) {
321 LockGuard<Mutex> lockGuard(mLock);
322 if (type == LogType::NANOAPP_TOKENIZED) {
323 discardExcessOldLogsLocked(logLen + kNanoappTokenizedLogOffset);
324 } else {
325 // For STRING logs, add 1 byte for null terminator. For TOKENIZED logs, add
326 // 1 byte for the size metadata added to the message.
327 discardExcessOldLogsLocked(logLen + 1);
328 }
329 encodeAndCopyLogLocked(level, timestampMs, logBuffer, logLen, type,
330 instanceId);
331 }
332
discardExcessOldLogsLocked(uint8_t currentLogLen)333 void LogBuffer::discardExcessOldLogsLocked(uint8_t currentLogLen) {
334 size_t totalLogSize = kLogDataOffset + currentLogLen;
335 while (mBufferDataSize + totalLogSize > mBufferMaxSize) {
336 mNumLogsDropped++;
337 size_t logSize;
338 mBufferDataHeadIndex = getNextLogIndex(mBufferDataHeadIndex, &logSize);
339 mBufferDataSize -= logSize;
340 }
341 }
342
encodeAndCopyLogLocked(LogBufferLogLevel level,uint32_t timestampMs,const void * logBuffer,uint8_t logLen,LogType type,uint16_t instanceId)343 void LogBuffer::encodeAndCopyLogLocked(LogBufferLogLevel level,
344 uint32_t timestampMs,
345 const void *logBuffer, uint8_t logLen,
346 LogType type, uint16_t instanceId) {
347 uint8_t metadata = setLogMetadata(type, level);
348
349 copyVarToBuffer(&metadata);
350 copyVarToBuffer(×tampMs);
351
352 if (type == LogType::NANOAPP_TOKENIZED) {
353 copyVarToBuffer(&instanceId);
354 copyVarToBuffer(&logLen);
355 } else if (type == LogType::TOKENIZED) {
356 copyVarToBuffer(&logLen);
357 }
358 copyToBuffer(logLen, logBuffer);
359 if (type == LogType::STRING) {
360 copyToBuffer(1, reinterpret_cast<const void *>("\0"));
361 }
362 }
363
dispatch()364 void LogBuffer::dispatch() {
365 if (mCallback != nullptr) {
366 switch (mNotificationSetting) {
367 case LogBufferNotificationSetting::ALWAYS: {
368 mCallback->onLogsReady();
369 break;
370 }
371 case LogBufferNotificationSetting::NEVER: {
372 break;
373 }
374 case LogBufferNotificationSetting::THRESHOLD: {
375 if (mBufferDataSize > mNotificationThresholdBytes) {
376 mCallback->onLogsReady();
377 }
378 break;
379 }
380 }
381 }
382 }
383
getLogTypeFromMetadata(uint8_t metadata)384 LogType LogBuffer::getLogTypeFromMetadata(uint8_t metadata) {
385 LogType type;
386 if (((metadata & 0x20) != 0) && ((metadata & 0x10) != 0)) {
387 type = LogType::NANOAPP_TOKENIZED;
388 } else if ((metadata & 0x20) != 0) {
389 type = LogType::BLUETOOTH;
390 } else if ((metadata & 0x10) != 0) {
391 type = LogType::TOKENIZED;
392 } else {
393 type = LogType::STRING;
394 }
395 return type;
396 }
397
setLogMetadata(LogType type,LogBufferLogLevel logLevel)398 uint8_t LogBuffer::setLogMetadata(LogType type, LogBufferLogLevel logLevel) {
399 return static_cast<uint8_t>(type) << 4 | static_cast<uint8_t>(logLevel);
400 }
401
tokenizedLogExceedsMaxSize(LogType type,size_t size)402 bool LogBuffer::tokenizedLogExceedsMaxSize(LogType type, size_t size) {
403 return (type == LogType::TOKENIZED &&
404 size >= kLogMaxSize - kTokenizedLogOffset) ||
405 (type == LogType::NANOAPP_TOKENIZED &&
406 size >= kLogMaxSize - kNanoappTokenizedLogOffset);
407 }
408
409 } // namespace chre
410