1 /*
2 * Copyright (c) 2017-2022, The OpenThread Authors.
3 * All rights reserved.
4 *
5 * Redistribution and use in source and binary forms, with or without
6 * modification, are permitted provided that the following conditions are met:
7 * 1. Redistributions of source code must retain the above copyright
8 * notice, this list of conditions and the following disclaimer.
9 * 2. Redistributions in binary form must reproduce the above copyright
10 * notice, this list of conditions and the following disclaimer in the
11 * documentation and/or other materials provided with the distribution.
12 * 3. Neither the name of the copyright holder nor the
13 * names of its contributors may be used to endorse or promote products
14 * derived from this software without specific prior written permission.
15 *
16 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
17 * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19 * ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
20 * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
21 * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
22 * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
23 * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
24 * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
25 * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
26 * POSSIBILITY OF SUCH DAMAGE.
27 */
28
29 /**
30 * @file
31 * This file implements the logging related functions.
32 */
33
34 #include "log.hpp"
35
36 #include <ctype.h>
37
38 #include <openthread/platform/logging.h>
39
40 #include "common/code_utils.hpp"
41 #include "common/num_utils.hpp"
42 #include "common/numeric_limits.hpp"
43 #include "common/string.hpp"
44 #include "instance/instance.hpp"
45
46 /*
47 * Verify debug UART dependency.
48 *
49 * It is reasonable to only enable the debug UART and not enable logs to the DEBUG UART.
50 */
51 #if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_DEBUG_UART) && (!OPENTHREAD_CONFIG_ENABLE_DEBUG_UART)
52 #error "OPENTHREAD_CONFIG_ENABLE_DEBUG_UART_LOG requires OPENTHREAD_CONFIG_ENABLE_DEBUG_UART"
53 #endif
54
55 #if OPENTHREAD_CONFIG_LOG_PREPEND_UPTIME && !OPENTHREAD_CONFIG_UPTIME_ENABLE
56 #error "OPENTHREAD_CONFIG_LOG_PREPEND_UPTIME requires OPENTHREAD_CONFIG_UPTIME_ENABLE"
57 #endif
58
59 #if OPENTHREAD_CONFIG_LOG_PREPEND_UPTIME && OPENTHREAD_CONFIG_MULTIPLE_INSTANCE_ENABLE
60 #error "OPENTHREAD_CONFIG_LOG_PREPEND_UPTIME is not supported under OPENTHREAD_CONFIG_MULTIPLE_INSTANCE_ENABLE"
61 #endif
62
63 namespace ot {
64
65 #if OT_SHOULD_LOG
66
LogAtLevel(const char * aModuleName,const char * aFormat,...)67 template <LogLevel kLogLevel> void Logger::LogAtLevel(const char *aModuleName, const char *aFormat, ...)
68 {
69 va_list args;
70
71 va_start(args, aFormat);
72 LogVarArgs(aModuleName, kLogLevel, aFormat, args);
73 va_end(args);
74 }
75
76 // Explicit instantiations
77 template void Logger::LogAtLevel<kLogLevelNone>(const char *aModuleName, const char *aFormat, ...);
78 template void Logger::LogAtLevel<kLogLevelCrit>(const char *aModuleName, const char *aFormat, ...);
79 template void Logger::LogAtLevel<kLogLevelWarn>(const char *aModuleName, const char *aFormat, ...);
80 template void Logger::LogAtLevel<kLogLevelNote>(const char *aModuleName, const char *aFormat, ...);
81 template void Logger::LogAtLevel<kLogLevelInfo>(const char *aModuleName, const char *aFormat, ...);
82 template void Logger::LogAtLevel<kLogLevelDebg>(const char *aModuleName, const char *aFormat, ...);
83
LogInModule(const char * aModuleName,LogLevel aLogLevel,const char * aFormat,...)84 void Logger::LogInModule(const char *aModuleName, LogLevel aLogLevel, const char *aFormat, ...)
85 {
86 va_list args;
87
88 va_start(args, aFormat);
89 LogVarArgs(aModuleName, aLogLevel, aFormat, args);
90 va_end(args);
91 }
92
LogVarArgs(const char * aModuleName,LogLevel aLogLevel,const char * aFormat,va_list aArgs)93 void Logger::LogVarArgs(const char *aModuleName, LogLevel aLogLevel, const char *aFormat, va_list aArgs)
94 {
95 static const char kModuleNamePadding[] = "--------------";
96
97 ot::String<OPENTHREAD_CONFIG_LOG_MAX_SIZE> logString;
98
99 static_assert(sizeof(kModuleNamePadding) == kMaxLogModuleNameLength + 1, "Padding string is not correct");
100
101 #if OPENTHREAD_CONFIG_LOG_PREPEND_UPTIME
102 ot::Uptime::UptimeToString(ot::Instance::Get().Get<ot::Uptime>().GetUptime(), logString, /* aInlcudeMsec */ true);
103 logString.Append(" ");
104 #endif
105
106 #if OPENTHREAD_CONFIG_LOG_LEVEL_DYNAMIC_ENABLE
107 VerifyOrExit(Instance::GetLogLevel() >= aLogLevel);
108 #endif
109
110 #if OPENTHREAD_CONFIG_LOG_PREPEND_LEVEL
111 {
112 static const char kLevelChars[] = {
113 '-', /* kLogLevelNone */
114 'C', /* kLogLevelCrit */
115 'W', /* kLogLevelWarn */
116 'N', /* kLogLevelNote */
117 'I', /* kLogLevelInfo */
118 'D', /* kLogLevelDebg */
119 };
120
121 logString.Append("[%c] ", kLevelChars[aLogLevel]);
122 }
123 #endif
124
125 logString.Append("%.*s%s: ", kMaxLogModuleNameLength, aModuleName,
126 &kModuleNamePadding[StringLength(aModuleName, kMaxLogModuleNameLength)]);
127
128 logString.AppendVarArgs(aFormat, aArgs);
129
130 logString.Append("%s", OPENTHREAD_CONFIG_LOG_SUFFIX);
131 otPlatLog(aLogLevel, OT_LOG_REGION_CORE, "%s", logString.AsCString());
132
133 ExitNow();
134
135 exit:
136 return;
137 }
138
139 #if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
LogOnError(const char * aModuleName,Error aError,const char * aText)140 void Logger::LogOnError(const char *aModuleName, Error aError, const char *aText)
141 {
142 if (aError != kErrorNone)
143 {
144 LogAtLevel<kLogLevelWarn>(aModuleName, "Failed to %s: %s", aText, ErrorToString(aError));
145 }
146 }
147 #endif
148
149 #if OPENTHREAD_CONFIG_LOG_PKT_DUMP
150
151 template <LogLevel kLogLevel>
DumpAtLevel(const char * aModuleName,const char * aText,const void * aData,uint16_t aDataLength)152 void Logger::DumpAtLevel(const char *aModuleName, const char *aText, const void *aData, uint16_t aDataLength)
153 {
154 DumpInModule(aModuleName, kLogLevel, aText, aData, aDataLength);
155 }
156
157 // Explicit instantiations
158 template void Logger::DumpAtLevel<kLogLevelNone>(const char *aModuleName,
159 const char *aText,
160 const void *aData,
161 uint16_t aDataLength);
162 template void Logger::DumpAtLevel<kLogLevelCrit>(const char *aModuleName,
163 const char *aText,
164 const void *aData,
165 uint16_t aDataLength);
166 template void Logger::DumpAtLevel<kLogLevelWarn>(const char *aModuleName,
167 const char *aText,
168 const void *aData,
169 uint16_t aDataLength);
170 template void Logger::DumpAtLevel<kLogLevelNote>(const char *aModuleName,
171 const char *aText,
172 const void *aData,
173 uint16_t aDataLength);
174 template void Logger::DumpAtLevel<kLogLevelInfo>(const char *aModuleName,
175 const char *aText,
176 const void *aData,
177 uint16_t aDataLength);
178 template void Logger::DumpAtLevel<kLogLevelDebg>(const char *aModuleName,
179 const char *aText,
180 const void *aData,
181 uint16_t aDataLength);
182
DumpInModule(const char * aModuleName,LogLevel aLogLevel,const char * aText,const void * aData,uint16_t aDataLength)183 void Logger::DumpInModule(const char *aModuleName,
184 LogLevel aLogLevel,
185 const char *aText,
186 const void *aData,
187 uint16_t aDataLength)
188 {
189 HexDumpInfo info;
190
191 VerifyOrExit(otLoggingGetLevel() >= aLogLevel);
192
193 info.mDataBytes = reinterpret_cast<const uint8_t *>(aData);
194 info.mDataLength = aDataLength;
195 info.mTitle = aText;
196 info.mIterator = 0;
197
198 while (GenerateNextHexDumpLine(info) == kErrorNone)
199 {
200 LogInModule(aModuleName, aLogLevel, "%s", info.mLine);
201 }
202
203 exit:
204 return;
205 }
206
207 #endif // OPENTHREAD_CONFIG_LOG_PKT_DUMP
208
209 #endif // OT_SHOULD_LOG
210
GenerateNextHexDumpLine(HexDumpInfo & aInfo)211 Error GenerateNextHexDumpLine(HexDumpInfo &aInfo)
212 {
213 constexpr uint16_t kIterTableStartLine = 0;
214 constexpr uint16_t kIterFirstDataLine = NumericLimits<uint16_t>::kMax - 2;
215 constexpr uint16_t kIterTableEndLine = NumericLimits<uint16_t>::kMax - 1;
216 constexpr uint16_t kIterFinished = NumericLimits<uint16_t>::kMax;
217 constexpr uint16_t kWidth = 72;
218 constexpr uint16_t kTitleSuffixLen = sizeof("[ len=000]") - 1;
219 constexpr uint16_t kDumpBytesPerLine = 16;
220
221 Error error = kErrorNone;
222 StringWriter writer(aInfo.mLine, sizeof(aInfo.mLine));
223
224 switch (aInfo.mIterator)
225 {
226 case kIterTableStartLine:
227 {
228 uint16_t txtLen = StringLength(aInfo.mTitle, kWidth - kTitleSuffixLen) + kTitleSuffixLen;
229
230 writer.AppendCharMultipleTimes('=', static_cast<uint16_t>((kWidth - txtLen) / 2));
231 writer.Append("[%s len=%03u]", aInfo.mTitle, aInfo.mDataLength);
232 writer.AppendCharMultipleTimes('=', static_cast<uint16_t>(kWidth - txtLen - (kWidth - txtLen) / 2));
233 aInfo.mIterator = kIterFirstDataLine;
234 break;
235 }
236
237 case kIterTableEndLine:
238 writer.AppendCharMultipleTimes('-', kWidth);
239 aInfo.mIterator = kIterFinished;
240 break;
241
242 case kIterFinished:
243 error = kErrorNotFound;
244 break;
245
246 case kIterFirstDataLine:
247 aInfo.mIterator = 0;
248 OT_FALL_THROUGH;
249
250 default:
251 {
252 uint16_t startIndex = aInfo.mIterator;
253 uint16_t endIndex = aInfo.mIterator + kDumpBytesPerLine;
254
255 writer.Append("|");
256
257 for (uint16_t i = startIndex; i < endIndex; i++)
258 {
259 (i < aInfo.mDataLength) ? writer.Append(" %02X", aInfo.mDataBytes[i]) : writer.Append(" ");
260
261 if ((i % 8) == 7)
262 {
263 writer.Append(" |");
264 }
265 }
266
267 writer.Append(" ");
268
269 for (uint16_t i = startIndex; i < endIndex; i++)
270 {
271 char c = ' ';
272
273 if (i < aInfo.mDataLength)
274 {
275 uint8_t byte = aInfo.mDataBytes[i];
276
277 c = ((byte < 127) && isprint(static_cast<char>(byte))) ? static_cast<char>(byte) : '.';
278 }
279
280 writer.Append("%c", c);
281 }
282
283 writer.Append(" |");
284
285 aInfo.mIterator = endIndex;
286
287 if (aInfo.mIterator >= aInfo.mDataLength)
288 {
289 aInfo.mIterator = kIterTableEndLine;
290 }
291
292 break;
293 }
294 }
295
296 return error;
297 }
298
299 } // namespace ot
300