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