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 OPENTHREAD_CONFIG_LOG_PKT_DUMP
140 
141 template <LogLevel kLogLevel>
DumpAtLevel(const char * aModuleName,const char * aText,const void * aData,uint16_t aDataLength)142 void Logger::DumpAtLevel(const char *aModuleName, const char *aText, const void *aData, uint16_t aDataLength)
143 {
144     DumpInModule(aModuleName, kLogLevel, aText, aData, aDataLength);
145 }
146 
147 // Explicit instantiations
148 template void Logger::DumpAtLevel<kLogLevelNone>(const char *aModuleName,
149                                                  const char *aText,
150                                                  const void *aData,
151                                                  uint16_t    aDataLength);
152 template void Logger::DumpAtLevel<kLogLevelCrit>(const char *aModuleName,
153                                                  const char *aText,
154                                                  const void *aData,
155                                                  uint16_t    aDataLength);
156 template void Logger::DumpAtLevel<kLogLevelWarn>(const char *aModuleName,
157                                                  const char *aText,
158                                                  const void *aData,
159                                                  uint16_t    aDataLength);
160 template void Logger::DumpAtLevel<kLogLevelNote>(const char *aModuleName,
161                                                  const char *aText,
162                                                  const void *aData,
163                                                  uint16_t    aDataLength);
164 template void Logger::DumpAtLevel<kLogLevelInfo>(const char *aModuleName,
165                                                  const char *aText,
166                                                  const void *aData,
167                                                  uint16_t    aDataLength);
168 template void Logger::DumpAtLevel<kLogLevelDebg>(const char *aModuleName,
169                                                  const char *aText,
170                                                  const void *aData,
171                                                  uint16_t    aDataLength);
172 
DumpInModule(const char * aModuleName,LogLevel aLogLevel,const char * aText,const void * aData,uint16_t aDataLength)173 void Logger::DumpInModule(const char *aModuleName,
174                           LogLevel    aLogLevel,
175                           const char *aText,
176                           const void *aData,
177                           uint16_t    aDataLength)
178 {
179     HexDumpInfo info;
180 
181     VerifyOrExit(otLoggingGetLevel() >= aLogLevel);
182 
183     info.mDataBytes  = reinterpret_cast<const uint8_t *>(aData);
184     info.mDataLength = aDataLength;
185     info.mTitle      = aText;
186     info.mIterator   = 0;
187 
188     while (GenerateNextHexDumpLine(info) == kErrorNone)
189     {
190         LogInModule(aModuleName, aLogLevel, "%s", info.mLine);
191     }
192 
193 exit:
194     return;
195 }
196 
197 #endif // OPENTHREAD_CONFIG_LOG_PKT_DUMP
198 
199 #endif // OT_SHOULD_LOG
200 
GenerateNextHexDumpLine(HexDumpInfo & aInfo)201 Error GenerateNextHexDumpLine(HexDumpInfo &aInfo)
202 {
203     constexpr uint16_t kIterTableStartLine = 0;
204     constexpr uint16_t kIterFirstDataLine  = NumericLimits<uint16_t>::kMax - 2;
205     constexpr uint16_t kIterTableEndLine   = NumericLimits<uint16_t>::kMax - 1;
206     constexpr uint16_t kIterFinished       = NumericLimits<uint16_t>::kMax;
207     constexpr uint16_t kWidth              = 72;
208     constexpr uint16_t kTitleSuffixLen     = sizeof("[ len=000]") - 1;
209     constexpr uint16_t kDumpBytesPerLine   = 16;
210 
211     Error        error = kErrorNone;
212     StringWriter writer(aInfo.mLine, sizeof(aInfo.mLine));
213 
214     switch (aInfo.mIterator)
215     {
216     case kIterTableStartLine:
217     {
218         uint16_t txtLen = StringLength(aInfo.mTitle, kWidth - kTitleSuffixLen) + kTitleSuffixLen;
219 
220         writer.AppendCharMultipleTimes('=', static_cast<uint16_t>((kWidth - txtLen) / 2));
221         writer.Append("[%s len=%03u]", aInfo.mTitle, aInfo.mDataLength);
222         writer.AppendCharMultipleTimes('=', static_cast<uint16_t>(kWidth - txtLen - (kWidth - txtLen) / 2));
223         aInfo.mIterator = kIterFirstDataLine;
224         break;
225     }
226 
227     case kIterTableEndLine:
228         writer.AppendCharMultipleTimes('-', kWidth);
229         aInfo.mIterator = kIterFinished;
230         break;
231 
232     case kIterFinished:
233         error = kErrorNotFound;
234         break;
235 
236     case kIterFirstDataLine:
237         aInfo.mIterator = 0;
238         OT_FALL_THROUGH;
239 
240     default:
241     {
242         uint16_t startIndex = aInfo.mIterator;
243         uint16_t endIndex   = aInfo.mIterator + kDumpBytesPerLine;
244 
245         writer.Append("|");
246 
247         for (uint16_t i = startIndex; i < endIndex; i++)
248         {
249             (i < aInfo.mDataLength) ? writer.Append(" %02X", aInfo.mDataBytes[i]) : writer.Append("   ");
250 
251             if ((i % 8) == 7)
252             {
253                 writer.Append(" |");
254             }
255         }
256 
257         writer.Append(" ");
258 
259         for (uint16_t i = startIndex; i < endIndex; i++)
260         {
261             char c = ' ';
262 
263             if (i < aInfo.mDataLength)
264             {
265                 uint8_t byte = aInfo.mDataBytes[i];
266 
267                 c = ((byte < 127) && isprint(static_cast<char>(byte))) ? static_cast<char>(byte) : '.';
268             }
269 
270             writer.Append("%c", c);
271         }
272 
273         writer.Append(" |");
274 
275         aInfo.mIterator = endIndex;
276 
277         if (aInfo.mIterator >= aInfo.mDataLength)
278         {
279             aInfo.mIterator = kIterTableEndLine;
280         }
281 
282         break;
283     }
284     }
285 
286     return error;
287 }
288 
289 } // namespace ot
290