1 //
2 // Copyright 2002 The ANGLE Project Authors. All rights reserved.
3 // Use of this source code is governed by a BSD-style license that can be
4 // found in the LICENSE file.
5 //
6
7 // debug.cpp: Debugging utilities.
8
9 #include "common/debug.h"
10
11 #include <stdarg.h>
12
13 #include <array>
14 #include <cstdio>
15 #include <cstring>
16 #include <fstream>
17 #include <ostream>
18 #include <vector>
19
20 #if defined(ANGLE_PLATFORM_ANDROID)
21 # include <android/log.h>
22 #endif
23
24 #if defined(ANGLE_PLATFORM_APPLE)
25 # include <os/log.h>
26 #endif
27
28 #if defined(ANGLE_PLATFORM_WINDOWS)
29 # include <windows.h>
30 #endif
31
32 #include "anglebase/no_destructor.h"
33 #include "common/Optional.h"
34 #include "common/angleutils.h"
35 #include "common/entry_points_enum_autogen.h"
36 #include "common/system_utils.h"
37
38 namespace gl
39 {
40
41 namespace
42 {
43
44 DebugAnnotator *g_debugAnnotator = nullptr;
45
46 std::mutex *g_debugMutex = nullptr;
47
48 constexpr std::array<const char *, LOG_NUM_SEVERITIES> g_logSeverityNames = {
49 {"EVENT", "INFO", "WARN", "ERR", "FATAL"}};
50
LogSeverityName(int severity)51 constexpr const char *LogSeverityName(int severity)
52 {
53 return (severity >= 0 && severity < LOG_NUM_SEVERITIES) ? g_logSeverityNames[severity]
54 : "UNKNOWN";
55 }
56
ShouldCreateLogMessage(LogSeverity severity)57 bool ShouldCreateLogMessage(LogSeverity severity)
58 {
59 #if defined(ANGLE_TRACE_ENABLED)
60 return true;
61 #elif defined(ANGLE_ENABLE_ASSERTS)
62 return severity == LOG_FATAL || severity == LOG_ERR || severity == LOG_WARN;
63 #else
64 return severity == LOG_FATAL || severity == LOG_ERR;
65 #endif
66 }
67
68 } // namespace
69
70 namespace priv
71 {
72
ShouldCreatePlatformLogMessage(LogSeverity severity)73 bool ShouldCreatePlatformLogMessage(LogSeverity severity)
74 {
75 #if defined(ANGLE_TRACE_ENABLED)
76 return true;
77 #else
78 return severity != LOG_EVENT;
79 #endif
80 }
81
82 // This is never instantiated, it's just used for EAT_STREAM_PARAMETERS to an object of the correct
83 // type on the LHS of the unused part of the ternary operator.
84 std::ostream *gSwallowStream;
85 } // namespace priv
86
DebugAnnotationsActive(const gl::Context * context)87 bool DebugAnnotationsActive(const gl::Context *context)
88 {
89 #if defined(ANGLE_ENABLE_DEBUG_ANNOTATIONS) || defined(ANGLE_ENABLE_DEBUG_TRACE)
90 return g_debugAnnotator != nullptr && g_debugAnnotator->getStatus(context);
91 #else
92 return false;
93 #endif
94 }
95
ShouldBeginScopedEvent(const gl::Context * context)96 bool ShouldBeginScopedEvent(const gl::Context *context)
97 {
98 #if defined(ANGLE_ENABLE_ANNOTATOR_RUN_TIME_CHECKS)
99 return DebugAnnotationsActive(context);
100 #else
101 return true;
102 #endif // defined(ANGLE_ENABLE_ANNOTATOR_RUN_TIME_CHECKS)
103 }
104
DebugAnnotationsInitialized()105 bool DebugAnnotationsInitialized()
106 {
107 return g_debugAnnotator != nullptr;
108 }
109
InitializeDebugAnnotations(DebugAnnotator * debugAnnotator)110 void InitializeDebugAnnotations(DebugAnnotator *debugAnnotator)
111 {
112 UninitializeDebugAnnotations();
113 g_debugAnnotator = debugAnnotator;
114 }
115
UninitializeDebugAnnotations()116 void UninitializeDebugAnnotations()
117 {
118 // Pointer is not managed.
119 g_debugAnnotator = nullptr;
120 }
121
InitializeDebugMutexIfNeeded()122 void InitializeDebugMutexIfNeeded()
123 {
124 if (g_debugMutex == nullptr)
125 {
126 g_debugMutex = new std::mutex();
127 }
128 }
129
GetDebugMutex()130 std::mutex &GetDebugMutex()
131 {
132 ASSERT(g_debugMutex);
133 return *g_debugMutex;
134 }
135
ScopedPerfEventHelper(gl::Context * context,angle::EntryPoint entryPoint)136 ScopedPerfEventHelper::ScopedPerfEventHelper(gl::Context *context, angle::EntryPoint entryPoint)
137 : mContext(context), mEntryPoint(entryPoint), mFunctionName(nullptr), mCalledBeginEvent(false)
138 {}
139
~ScopedPerfEventHelper()140 ScopedPerfEventHelper::~ScopedPerfEventHelper()
141 {
142 // EGL_Initialize() and EGL_Terminate() can change g_debugAnnotator. Must check the value of
143 // g_debugAnnotator and whether ScopedPerfEventHelper::begin() initiated a begine that must be
144 // ended now.
145 if (DebugAnnotationsInitialized() && mCalledBeginEvent)
146 {
147 g_debugAnnotator->endEvent(mContext, mFunctionName, mEntryPoint);
148 }
149 }
150
begin(const char * format,...)151 void ScopedPerfEventHelper::begin(const char *format, ...)
152 {
153 mFunctionName = GetEntryPointName(mEntryPoint);
154
155 va_list vararg;
156 va_start(vararg, format);
157
158 std::vector<char> buffer;
159 size_t len = FormatStringIntoVector(format, vararg, buffer);
160 va_end(vararg);
161
162 ANGLE_LOG(EVENT) << std::string(&buffer[0], len);
163 if (DebugAnnotationsInitialized())
164 {
165 mCalledBeginEvent = true;
166 g_debugAnnotator->beginEvent(mContext, mEntryPoint, mFunctionName, buffer.data());
167 }
168 }
169
LogMessage(const char * file,const char * function,int line,LogSeverity severity)170 LogMessage::LogMessage(const char *file, const char *function, int line, LogSeverity severity)
171 : mFile(file), mFunction(function), mLine(line), mSeverity(severity)
172 {
173 // INFO() and EVENT() do not require additional function(line) info.
174 if (mSeverity > LOG_INFO)
175 {
176 const char *slash = std::max(strrchr(mFile, '/'), strrchr(mFile, '\\'));
177 mStream << (slash ? (slash + 1) : mFile) << ":" << mLine << " (" << mFunction << "): ";
178 }
179 }
180
~LogMessage()181 LogMessage::~LogMessage()
182 {
183 {
184 std::unique_lock<std::mutex> lock;
185 if (g_debugMutex != nullptr)
186 {
187 lock = std::unique_lock<std::mutex>(*g_debugMutex);
188 }
189
190 if (DebugAnnotationsInitialized() && (mSeverity > LOG_INFO))
191 {
192 g_debugAnnotator->logMessage(*this);
193 }
194 else
195 {
196 Trace(getSeverity(), getMessage().c_str());
197 }
198 }
199
200 if (mSeverity == LOG_FATAL)
201 {
202 if (angle::IsDebuggerAttached())
203 {
204 angle::BreakDebugger();
205 }
206 else
207 {
208 ANGLE_CRASH();
209 }
210 }
211 }
212
Trace(LogSeverity severity,const char * message)213 void Trace(LogSeverity severity, const char *message)
214 {
215 if (!ShouldCreateLogMessage(severity))
216 {
217 return;
218 }
219
220 std::string str(message);
221
222 if (DebugAnnotationsActive(/*context=*/nullptr))
223 {
224
225 switch (severity)
226 {
227 case LOG_EVENT:
228 // Debugging logging done in ScopedPerfEventHelper
229 break;
230 default:
231 g_debugAnnotator->setMarker(/*context=*/nullptr, message);
232 break;
233 }
234 }
235
236 if (severity == LOG_FATAL || severity == LOG_ERR || severity == LOG_WARN ||
237 #if defined(ANGLE_ENABLE_TRACE_ANDROID_LOGCAT) || defined(ANGLE_ENABLE_TRACE_EVENTS)
238 severity == LOG_EVENT ||
239 #endif
240 severity == LOG_INFO)
241 {
242 #if defined(ANGLE_PLATFORM_ANDROID)
243 android_LogPriority android_priority = ANDROID_LOG_ERROR;
244 switch (severity)
245 {
246 case LOG_INFO:
247 case LOG_EVENT:
248 android_priority = ANDROID_LOG_INFO;
249 break;
250 case LOG_WARN:
251 android_priority = ANDROID_LOG_WARN;
252 break;
253 case LOG_ERR:
254 android_priority = ANDROID_LOG_ERROR;
255 break;
256 case LOG_FATAL:
257 android_priority = ANDROID_LOG_FATAL;
258 break;
259 default:
260 UNREACHABLE();
261 }
262 __android_log_print(android_priority, "ANGLE", "%s: %s\n", LogSeverityName(severity),
263 str.c_str());
264 // Note: we also log to stdout/stderr below.
265 #endif
266
267 #if defined(ANGLE_PLATFORM_APPLE)
268 if (__builtin_available(macOS 10.12, iOS 10.0, *))
269 {
270 os_log_type_t apple_log_type = OS_LOG_TYPE_DEFAULT;
271 switch (severity)
272 {
273 case LOG_INFO:
274 case LOG_EVENT:
275 apple_log_type = OS_LOG_TYPE_INFO;
276 break;
277 case LOG_WARN:
278 apple_log_type = OS_LOG_TYPE_DEFAULT;
279 break;
280 case LOG_ERR:
281 apple_log_type = OS_LOG_TYPE_ERROR;
282 break;
283 case LOG_FATAL:
284 // OS_LOG_TYPE_FAULT is too severe - grabs the entire process tree.
285 apple_log_type = OS_LOG_TYPE_ERROR;
286 break;
287 default:
288 UNREACHABLE();
289 }
290 os_log_with_type(OS_LOG_DEFAULT, apple_log_type, "ANGLE: %s: %s\n",
291 LogSeverityName(severity), str.c_str());
292 }
293 #else
294 // Note: we use fprintf because <iostream> includes static initializers.
295 fprintf((severity >= LOG_WARN) ? stderr : stdout, "%s: %s\n", LogSeverityName(severity),
296 str.c_str());
297 #endif
298 }
299
300 #if defined(ANGLE_PLATFORM_WINDOWS) && \
301 (defined(ANGLE_ENABLE_DEBUG_TRACE_TO_DEBUGGER) || !defined(NDEBUG))
302 # if !defined(ANGLE_ENABLE_DEBUG_TRACE_TO_DEBUGGER)
303 if (severity >= LOG_ERR)
304 # endif // !defined(ANGLE_ENABLE_DEBUG_TRACE_TO_DEBUGGER)
305 {
306 OutputDebugStringA(str.c_str());
307 OutputDebugStringA("\n");
308 }
309 #endif
310
311 #if defined(ANGLE_ENABLE_DEBUG_TRACE)
312 # if defined(NDEBUG)
313 if (severity == LOG_EVENT || severity == LOG_WARN || severity == LOG_INFO)
314 {
315 return;
316 }
317 # endif // defined(NDEBUG)
318 static angle::base::NoDestructor<std::ofstream> file(TRACE_OUTPUT_FILE, std::ofstream::app);
319 if (file->good())
320 {
321 if (severity > LOG_EVENT)
322 {
323 *file << LogSeverityName(severity) << ": ";
324 }
325 *file << str << "\n";
326 file->flush();
327 }
328 #endif // defined(ANGLE_ENABLE_DEBUG_TRACE)
329 }
330
getSeverity() const331 LogSeverity LogMessage::getSeverity() const
332 {
333 return mSeverity;
334 }
335
getMessage() const336 std::string LogMessage::getMessage() const
337 {
338 return mStream.str();
339 }
340
341 #if defined(ANGLE_PLATFORM_WINDOWS)
FmtHR(HRESULT value)342 priv::FmtHexHelper<HRESULT, char> FmtHR(HRESULT value)
343 {
344 return priv::FmtHexHelper<HRESULT, char>("HRESULT: ", value);
345 }
346
FmtErr(DWORD value)347 priv::FmtHexHelper<DWORD, char> FmtErr(DWORD value)
348 {
349 return priv::FmtHexHelper<DWORD, char>("error: ", value);
350 }
351 #endif // defined(ANGLE_PLATFORM_WINDOWS)
352
353 } // namespace gl
354