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_host/log_message_parser.h"
18 #include <endian.h>
19 #include "chre/util/time.h"
20 #include "chre_host/daemon_base.h"
21 #include "chre_host/log.h"
22 #include "include/chre_host/log_message_parser.h"
23
24 using chre::kOneMillisecondInNanoseconds;
25 using chre::kOneSecondInMilliseconds;
26
27 namespace android {
28 namespace chre {
29
30 namespace {
31 #if defined(LOG_NDEBUG) || LOG_NDEBUG != 0
32 constexpr bool kVerboseLoggingEnabled = true;
33 #else
34 constexpr bool kVerboseLoggingEnabled = false;
35 #endif
36 } // anonymous namespace
37
LogMessageParser()38 LogMessageParser::LogMessageParser()
39 : mVerboseLoggingEnabled(kVerboseLoggingEnabled) {}
40
logDetokenizerInit()41 std::unique_ptr<Detokenizer> LogMessageParser::logDetokenizerInit() {
42 #ifdef CHRE_TOKENIZED_LOGGING_ENABLED
43 constexpr const char kLogDatabaseFilePath[] =
44 "/vendor/etc/chre/libchre_log_database.bin";
45 std::vector<uint8_t> tokenData;
46 if (ChreDaemonBase::readFileContents(kLogDatabaseFilePath, &tokenData)) {
47 pw::tokenizer::TokenDatabase database =
48 pw::tokenizer::TokenDatabase::Create(tokenData);
49 if (database.ok()) {
50 LOGD("Log database initialized, creating detokenizer");
51 return std::make_unique<Detokenizer>(database);
52 } else {
53 LOGE("CHRE Token database creation not OK");
54 }
55 } else {
56 LOGE("Failed to read CHRE Token database file");
57 }
58 #endif
59 return std::unique_ptr<Detokenizer>(nullptr);
60 }
61
init()62 void LogMessageParser::init() {
63 mDetokenizer = logDetokenizerInit();
64 }
65
dump(const uint8_t * buffer,size_t size)66 void LogMessageParser::dump(const uint8_t *buffer, size_t size) {
67 if (mVerboseLoggingEnabled) {
68 char line[32];
69 char lineChars[32];
70 int offset = 0;
71 int offsetChars = 0;
72
73 size_t orig_size = size;
74 if (size > 128) {
75 size = 128;
76 LOGV("Dumping first 128 bytes of buffer of size %zu", orig_size);
77 } else {
78 LOGV("Dumping buffer of size %zu bytes", size);
79 }
80 for (size_t i = 1; i <= size; ++i) {
81 offset += snprintf(&line[offset], sizeof(line) - offset, "%02x ",
82 buffer[i - 1]);
83 offsetChars +=
84 snprintf(&lineChars[offsetChars], sizeof(lineChars) - offsetChars,
85 "%c", (isprint(buffer[i - 1])) ? buffer[i - 1] : '.');
86 if ((i % 8) == 0) {
87 LOGV(" %s\t%s", line, lineChars);
88 offset = 0;
89 offsetChars = 0;
90 } else if ((i % 4) == 0) {
91 offset += snprintf(&line[offset], sizeof(line) - offset, " ");
92 }
93 }
94
95 if (offset > 0) {
96 char tabs[8];
97 char *pos = tabs;
98 while (offset < 28) {
99 *pos++ = '\t';
100 offset += 8;
101 }
102 *pos = '\0';
103 LOGV(" %s%s%s", line, tabs, lineChars);
104 }
105 }
106 }
107
chreLogLevelToAndroidLogPriority(uint8_t level)108 android_LogPriority LogMessageParser::chreLogLevelToAndroidLogPriority(
109 uint8_t level) {
110 switch (level) {
111 case LogLevel::ERROR:
112 return ANDROID_LOG_ERROR;
113 case LogLevel::WARNING:
114 return ANDROID_LOG_WARN;
115 case LogLevel::INFO:
116 return ANDROID_LOG_INFO;
117 case LogLevel::DEBUG:
118 return ANDROID_LOG_DEBUG;
119 default:
120 return ANDROID_LOG_SILENT;
121 }
122 }
123
getLogLevelFromMetadata(uint8_t metadata)124 uint8_t LogMessageParser::getLogLevelFromMetadata(uint8_t metadata) {
125 // The lower nibble of the metadata denotes the loglevel, as indicated
126 // by the schema in host_messages.fbs.
127 return (metadata & 0xf);
128 }
129
isLogMessageEncoded(uint8_t metadata)130 bool LogMessageParser::isLogMessageEncoded(uint8_t metadata) {
131 // The upper nibble of the metadata denotes the encoding, as indicated
132 // by the schema in host_messages.fbs.
133 return (((metadata >> 4) & 0xf) != 0);
134 }
135
log(const uint8_t * logBuffer,size_t logBufferSize)136 void LogMessageParser::log(const uint8_t *logBuffer, size_t logBufferSize) {
137 size_t bufferIndex = 0;
138 while (bufferIndex < logBufferSize) {
139 const LogMessage *message =
140 reinterpret_cast<const LogMessage *>(&logBuffer[bufferIndex]);
141 uint64_t timeNs = le64toh(message->timestampNanos);
142 emitLogMessage(message->logLevel, timeNs / kOneMillisecondInNanoseconds,
143 message->logMessage);
144 bufferIndex += sizeof(LogMessage) +
145 strnlen(message->logMessage, logBufferSize - bufferIndex) +
146 1;
147 }
148 }
149
parseAndEmitTokenizedLogMessageAndGetSize(const LogMessageV2 * message)150 size_t LogMessageParser::parseAndEmitTokenizedLogMessageAndGetSize(
151 const LogMessageV2 *message) {
152 size_t logMessageSize = 0;
153 auto detokenizer = mDetokenizer.get();
154 if (detokenizer != nullptr) {
155 auto *encodedLog = const_cast<EncodedLog *>(
156 reinterpret_cast<const EncodedLog *>(message->logMessage));
157 DetokenizedString detokenizedString =
158 detokenizer->Detokenize(encodedLog->data, encodedLog->size);
159 std::string decodedString = detokenizedString.BestStringWithErrors();
160 emitLogMessage(getLogLevelFromMetadata(message->metadata),
161 le32toh(message->timestampMillis), decodedString.c_str());
162 logMessageSize = encodedLog->size + sizeof(struct EncodedLog);
163 } else {
164 LOGE("Null detokenizer! Cannot decode log message");
165 }
166 return logMessageSize;
167 }
168
parseAndEmitLogMessage(const LogMessageV2 * message)169 void LogMessageParser::parseAndEmitLogMessage(const LogMessageV2 *message) {
170 emitLogMessage(getLogLevelFromMetadata(message->metadata),
171 le32toh(message->timestampMillis), message->logMessage);
172 }
173
updateAndPrintDroppedLogs(uint32_t numLogsDropped)174 void LogMessageParser::updateAndPrintDroppedLogs(uint32_t numLogsDropped) {
175 if (numLogsDropped < mNumLogsDropped) {
176 LOGE(
177 "The numLogsDropped value received from CHRE is less than the last "
178 "value received. Received: %" PRIu32 " Last value: %" PRIu32,
179 numLogsDropped, mNumLogsDropped);
180 }
181 // Log the number of logs dropped once before logging remaining logs from CHRE
182 uint32_t diffLogsDropped = numLogsDropped - mNumLogsDropped;
183 mNumLogsDropped = numLogsDropped;
184 if (diffLogsDropped > 0) {
185 LOGI("# logs dropped: %" PRIu32, diffLogsDropped);
186 }
187 }
188
emitLogMessage(uint8_t level,uint32_t timestampMillis,const char * logMessage)189 void LogMessageParser::emitLogMessage(uint8_t level, uint32_t timestampMillis,
190 const char *logMessage) {
191 constexpr const char kLogTag[] = "CHRE";
192 uint32_t timeSec = timestampMillis / kOneSecondInMilliseconds;
193 uint32_t timeMsRemainder = timestampMillis % kOneSecondInMilliseconds;
194 android_LogPriority priority = chreLogLevelToAndroidLogPriority(level);
195 LOG_PRI(priority, kLogTag, kHubLogFormatStr, timeSec, timeMsRemainder,
196 logMessage);
197 }
198
logV2(const uint8_t * logBuffer,size_t logBufferSize,uint32_t numLogsDropped)199 void LogMessageParser::logV2(const uint8_t *logBuffer, size_t logBufferSize,
200 uint32_t numLogsDropped) {
201 updateAndPrintDroppedLogs(numLogsDropped);
202
203 size_t bufferIndex = 0;
204 while (bufferIndex < logBufferSize) {
205 const LogMessageV2 *message =
206 reinterpret_cast<const LogMessageV2 *>(&logBuffer[bufferIndex]);
207 size_t bufferIndexDelta = logBufferSize - bufferIndex;
208 size_t logMessageSize;
209 if (isLogMessageEncoded(message->metadata)) {
210 logMessageSize = parseAndEmitTokenizedLogMessageAndGetSize(message);
211 } else {
212 parseAndEmitLogMessage(message);
213 logMessageSize = strlen(message->logMessage) + 1;
214 }
215 bufferIndex +=
216 sizeof(LogMessageV2) + std::min(logMessageSize, bufferIndexDelta);
217 }
218 }
219
220 } // namespace chre
221 } // namespace android
222