OVR_Log.cpp 18 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578
  1. /************************************************************************************
  2. Filename : OVR_Log.cpp
  3. Content : Logging support
  4. Created : September 19, 2012
  5. Notes :
  6. Copyright : Copyright 2014 Oculus VR, LLC All Rights reserved.
  7. Licensed under the Oculus VR Rift SDK License Version 3.2 (the "License");
  8. you may not use the Oculus VR Rift SDK except in compliance with the License,
  9. which is provided at the time of installation or download, or which
  10. otherwise accompanies this software in either electronic or hard copy form.
  11. You may obtain a copy of the License at
  12. http://www.oculusvr.com/licenses/LICENSE-3.2
  13. Unless required by applicable law or agreed to in writing, the Oculus VR SDK
  14. distributed under the License is distributed on an "AS IS" BASIS,
  15. WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  16. See the License for the specific language governing permissions and
  17. limitations under the License.
  18. ************************************************************************************/
  19. #include "OVR_Log.h"
  20. #include "OVR_Std.h"
  21. #include <stdarg.h>
  22. #include <stdio.h>
  23. #include <stdlib.h>
  24. #include <time.h>
  25. #include "OVR_System.h"
  26. #include "OVR_DebugHelp.h"
  27. #include <Util/Util_SystemGUI.h>
  28. #include <Tracing/Tracing.h>
  29. #if defined(OVR_OS_MS) && !defined(OVR_OS_MS_MOBILE)
  30. #include "OVR_Win32_IncludeWindows.h"
  31. #elif defined(OVR_OS_ANDROID)
  32. #include <android/log.h>
  33. #elif defined(OVR_OS_LINUX) || defined(OVR_OS_MAC) || defined(OVR_OS_UNIX)
  34. #include <syslog.h>
  35. #include <errno.h>
  36. typedef int errno_t;
  37. errno_t gmtime_s(struct tm* tm, const time_t* timer)
  38. {
  39. if (nullptr == gmtime_r(timer, tm)) {
  40. return errno;
  41. }
  42. return 0;
  43. }
  44. #endif
  45. //-----------------------------------------------------------------------------------
  46. // ***** LogSubject
  47. static bool LogSubject_IsReady = false;
  48. class LogSubject : public OVR::SystemSingletonBase<LogSubject>
  49. {
  50. OVR_DECLARE_SINGLETON(LogSubject);
  51. public:
  52. void AddListener(OVR::CallbackListener<OVR::Log::LogHandler> *listener)
  53. {
  54. OVR::Lock::Locker locker(&SubjectLock);
  55. Subject.AddListener(listener);
  56. }
  57. void Call(const char* message, OVR::LogMessageType type)
  58. {
  59. OVR::Lock::Locker locker(&SubjectLock);
  60. Subject.Call(message, type);
  61. }
  62. protected:
  63. virtual void OnThreadDestroy(); // Listen to thread shutdown event
  64. OVR::CallbackEmitter<OVR::Log::LogHandler> Subject;
  65. // This lock is needed because AddListener() and Call() can happen on different
  66. // threads but CallbackEmitter is not thread-safe.
  67. OVR::Lock SubjectLock;
  68. };
  69. LogSubject::LogSubject()
  70. {
  71. LogSubject_IsReady = true;
  72. // Must be at end of function
  73. PushDestroyCallbacks();
  74. }
  75. LogSubject::~LogSubject()
  76. {
  77. }
  78. void LogSubject::OnThreadDestroy()
  79. {
  80. LogSubject_IsReady = false;
  81. }
  82. void LogSubject::OnSystemDestroy()
  83. {
  84. delete this;
  85. }
  86. OVR_DEFINE_SINGLETON(LogSubject);
  87. namespace OVR {
  88. // Global Log pointer.
  89. Log* OVR_GlobalLog = nullptr;
  90. Log::CAPICallback OVR_CAPICallback = nullptr;
  91. uintptr_t OVR_CAPICallbackUserData = 0;
  92. //-----------------------------------------------------------------------------------
  93. // ***** Log Implementation
  94. Log::Log(unsigned logMask, bool defaultLogEnabled) :
  95. LoggingMask(logMask),
  96. DefaultLogEnabled(defaultLogEnabled)
  97. {
  98. #ifdef OVR_OS_WIN32
  99. hEventSource = ::RegisterEventSourceW(nullptr, OVR_SYSLOG_NAME);
  100. OVR_ASSERT(hEventSource != nullptr);
  101. #endif
  102. }
  103. Log::~Log()
  104. {
  105. #ifdef OVR_OS_WIN32
  106. if (hEventSource)
  107. {
  108. ::DeregisterEventSource(hEventSource);
  109. }
  110. #endif
  111. // Clear out global log
  112. if (this == OVR_GlobalLog)
  113. {
  114. // TBD: perhaps we should ASSERT if this happens before system shutdown?
  115. OVR_GlobalLog = 0;
  116. }
  117. }
  118. void Log::SetCAPICallback(CAPICallback callback, uintptr_t userData)
  119. {
  120. if (!OVR::System::IsInitialized())
  121. {
  122. OVR_CAPICallback = callback;
  123. OVR_CAPICallbackUserData = userData;
  124. }
  125. }
  126. void Log::AddLogObserver(CallbackListener<LogHandler>* listener)
  127. {
  128. if (OVR::System::IsInitialized() && LogSubject_IsReady)
  129. {
  130. LogSubject::GetInstance()->AddListener(listener);
  131. }
  132. }
  133. static void RouteLogOutput(const char* message, LogMessageType messageType)
  134. {
  135. int level = int(LogLevel_Debug);
  136. if (Log::IsDebugMessage(messageType))
  137. {
  138. TraceLogDebug(message);
  139. }
  140. else if (messageType == OVR::Log_Error)
  141. {
  142. level = int(LogLevel_Error);
  143. TraceLogError(message);
  144. }
  145. else
  146. {
  147. level = int(LogLevel_Info);
  148. TraceLogInfo(message);
  149. }
  150. if (OVR_CAPICallback)
  151. OVR_CAPICallback(OVR_CAPICallbackUserData, level, message);
  152. LogSubject::GetInstance()->Call(message, messageType);
  153. }
  154. void Log::LogMessageVargInt(LogMessageType messageType, const char* fmt, va_list argList)
  155. {
  156. if (OVR::System::IsInitialized())
  157. {
  158. // Invoke subject
  159. char buffer[MaxLogBufferMessageSize];
  160. char* pBuffer = buffer;
  161. char* pAllocated = NULL;
  162. #if !defined(OVR_CC_MSVC) // Non-Microsoft compilers require you to save a copy of the va_list.
  163. va_list argListSaved;
  164. va_copy(argListSaved, argList);
  165. #endif
  166. int result = FormatLog(pBuffer, MaxLogBufferMessageSize, Log_Text, fmt, argList);
  167. if(result >= MaxLogBufferMessageSize) // If there was insufficient capacity...
  168. {
  169. // We assume C++ exceptions are disabled.
  170. // FormatLog will handle the case that pAllocated is NULL.
  171. pAllocated = new char [result + 1];
  172. // We cannot use OVR_ALLOC() for this allocation because the logging subsystem exists
  173. // outside of the rest of LibOVR so that it can be used to log events from anywhere.
  174. pBuffer = pAllocated;
  175. #if !defined(OVR_CC_MSVC)
  176. va_end(argList); // The caller owns argList and will call va_end on it.
  177. va_copy(argList, argListSaved);
  178. #endif
  179. FormatLog(pBuffer, (size_t)result + 1, Log_Text, fmt, argList);
  180. }
  181. RouteLogOutput(pBuffer, messageType);
  182. delete[] pAllocated;
  183. }
  184. }
  185. void Log::LogMessageVarg(LogMessageType messageType, const char* fmt, va_list argList)
  186. {
  187. if (!DefaultLogEnabled || ((messageType & LoggingMask) == 0))
  188. return;
  189. #ifndef OVR_BUILD_DEBUG
  190. if (IsDebugMessage(messageType))
  191. return;
  192. #endif
  193. char buffer[MaxLogBufferMessageSize];
  194. char* pBuffer = buffer;
  195. char* pAllocated = nullptr;
  196. #if !defined(OVR_CC_MSVC) // Non-Microsoft compilers require you to save a copy of the va_list.
  197. va_list argListSaved;
  198. va_copy(argListSaved, argList);
  199. #endif
  200. int result = FormatLog(pBuffer, MaxLogBufferMessageSize, messageType, fmt, argList);
  201. if(result >= MaxLogBufferMessageSize) // If there was insufficient capacity...
  202. {
  203. // We assume C++ exceptions are disabled.
  204. // FormatLog will handle the case that pAllocated is NULL.
  205. pAllocated = (char*)malloc(result + 1);
  206. // We cannot use OVR_ALLOC() for this allocation because the logging subsystem exists
  207. // outside of the rest of LibOVR so that it can be used to log events from anywhere.
  208. // We cannot use new/delete either because we wrap that.
  209. pBuffer = pAllocated;
  210. #if !defined(OVR_CC_MSVC)
  211. va_end(argList); // The caller owns argList and will call va_end on it.
  212. va_copy(argList, argListSaved);
  213. #endif
  214. FormatLog(pBuffer, (size_t)result + 1, messageType, fmt, argList);
  215. }
  216. DefaultLogOutput(pBuffer, messageType, result);
  217. free(pAllocated);
  218. }
  219. void OVR::Log::LogMessage(LogMessageType messageType, const char* pfmt, ...)
  220. {
  221. va_list argList;
  222. va_start(argList, pfmt);
  223. LogMessageVarg(messageType, pfmt, argList);
  224. va_end(argList);
  225. }
  226. // Return behavior is the same as ISO C vsnprintf: returns the required strlen of buffer (which will
  227. // be >= bufferSize if bufferSize is insufficient) or returns a negative value because the input was bad.
  228. int Log::FormatLog(char* buffer, size_t bufferSize, LogMessageType messageType,
  229. const char* fmt, va_list argList)
  230. {
  231. const char bareMinString[] = "01/01/15_08:00:00: Assert: \n";
  232. OVR_UNUSED(bareMinString);
  233. OVR_ASSERT(buffer && (bufferSize >= sizeof(bareMinString)));
  234. if(!buffer || (bufferSize < sizeof(bareMinString)))
  235. return -1;
  236. int addNewline = 1;
  237. int prefixLength = 0;
  238. // Prepend short timestamp to the message
  239. time_t timer;
  240. time(&timer);
  241. if (timer != -1)
  242. {
  243. tm timeData;
  244. errno_t err = gmtime_s(&timeData, &timer);
  245. if (err == 0)
  246. {
  247. // We're guaranteed to have enough space in the buffer because of
  248. // the minimum size check at the top of this function (so any
  249. // bytesWritten > 0 is a success case here).
  250. int bytesWritten = OVR_snprintf(buffer, bufferSize, "%02i/%02i/%02i %02i:%02i:%02i: ",
  251. timeData.tm_mon+1, timeData.tm_mday,
  252. timeData.tm_year % 100,
  253. timeData.tm_hour, timeData.tm_min, timeData.tm_sec);
  254. if (bytesWritten > 0)
  255. {
  256. prefixLength = bytesWritten;
  257. }
  258. }
  259. }
  260. switch(messageType)
  261. {
  262. case Log_Error: OVR_strcpy(buffer+prefixLength, bufferSize-prefixLength, "Error: "); prefixLength += 7; break;
  263. case Log_Debug: OVR_strcpy(buffer+prefixLength, bufferSize-prefixLength, "Debug: "); prefixLength += 7; break;
  264. case Log_Assert: OVR_strcpy(buffer+prefixLength, bufferSize-prefixLength, "Assert: "); prefixLength += 8; break;
  265. case Log_Text: buffer[prefixLength] = 0; addNewline = 0; break;
  266. case Log_DebugText: buffer[prefixLength] = 0; addNewline = 0; break;
  267. default: buffer[prefixLength] = 0; addNewline = 0; break;
  268. }
  269. char* buffer2 = buffer + prefixLength;
  270. size_t size2 = bufferSize - (size_t)prefixLength;
  271. int messageLength = OVR_vsnprintf(buffer2, size2, fmt, argList);
  272. if (addNewline)
  273. {
  274. if (messageLength < 0) // If there was a format error...
  275. {
  276. // To consider: append <format error> to the buffer here.
  277. buffer2[0] = '\n'; // We are guaranteed to have capacity for this.
  278. buffer2[1] = '\0';
  279. }
  280. else
  281. {
  282. size_t bufferUsed = messageLength;
  283. if (bufferUsed > size2)
  284. bufferUsed = size2;
  285. if ((bufferUsed == 0) || (buffer2[bufferUsed - 1] != '\n')) // If there isn't already a trailing '\n' ...
  286. {
  287. // If the printed string used all of the capacity or required more than the capacity,
  288. // Chop the output by one character so we can append the \n safely.
  289. int messageEnd = (messageLength >= (int)(size2 - 1)) ? (int)(size2 - 2) : messageLength;
  290. buffer2[messageEnd + 0] = '\n';
  291. buffer2[messageEnd + 1] = '\0';
  292. }
  293. }
  294. }
  295. if (messageLength >= 0) // If the format was OK...
  296. return prefixLength + messageLength + addNewline; // Return the required strlen of buffer.
  297. return messageLength; // Else we cannot know what the required strlen is and return the error to the caller.
  298. }
  299. void Log::DefaultLogOutput(const char* formattedText, LogMessageType messageType, int bufferSize)
  300. {
  301. std::wstring wideText = UTF8StringToUCSString(formattedText, bufferSize);
  302. const wchar_t* wideBuff = wideText.c_str();
  303. OVR_UNUSED(wideBuff);
  304. #if defined(OVR_OS_WIN32)
  305. auto endOfDatestamp = wideText.find(L": ", 11);
  306. ::OutputDebugStringW(wideBuff + (endOfDatestamp != std::wstring::npos ? (endOfDatestamp + 2) : 0));
  307. fputs(formattedText, stdout);
  308. #elif defined(OVR_OS_MS) // Any other Microsoft OSs
  309. ::OutputDebugStringW(wideBuff);
  310. #elif defined(OVR_OS_ANDROID)
  311. // To do: use bufferSize to deal with the case that Android has a limited output length.
  312. __android_log_write(ANDROID_LOG_INFO, "OVR", formattedText);
  313. #elif defined(OVR_OS_MAC)
  314. syslog(LOG_INFO, "%s", formattedText);
  315. fputs(formattedText, stdout);
  316. #else
  317. fputs(formattedText, stdout);
  318. #endif
  319. if (messageType == Log_Error)
  320. {
  321. #if defined(OVR_OS_WIN32)
  322. if (!ReportEventW(hEventSource, EVENTLOG_ERROR_TYPE, 0, 0, NULL, 1, 0, &wideBuff, NULL))
  323. {
  324. OVR_ASSERT(false);
  325. }
  326. #elif defined(OVR_OS_MS) // Any other Microsoft OSs
  327. // TBD
  328. #elif defined(OVR_OS_ANDROID)
  329. // TBD
  330. #elif defined(OVR_OS_MAC) || defined(OVR_OS_LINUX)
  331. syslog(LOG_ERR, "%s", formattedText);
  332. #else
  333. // TBD
  334. #endif
  335. }
  336. }
  337. //static
  338. void Log::SetGlobalLog(Log *log)
  339. {
  340. OVR_GlobalLog = log;
  341. }
  342. //static
  343. Log* Log::GetGlobalLog()
  344. {
  345. // No global log by default?
  346. // if (!OVR_GlobalLog)
  347. // OVR_GlobalLog = GetDefaultLog();
  348. return OVR_GlobalLog;
  349. }
  350. //static
  351. Log* Log::GetDefaultLog()
  352. {
  353. // Create default log pointer statically so that it can be used
  354. // even during startup.
  355. static Log defaultLog;
  356. return &defaultLog;
  357. }
  358. //-----------------------------------------------------------------------------------
  359. // ***** Global Logging functions
  360. #if !defined(OVR_CC_MSVC)
  361. // The reason for va_copy is because you can't use va_start twice on Linux
  362. #define OVR_LOG_FUNCTION_IMPL(Name) \
  363. void Log##Name(const char* fmt, ...) \
  364. { \
  365. if (OVR_GlobalLog) \
  366. { \
  367. va_list argList1; \
  368. va_start(argList1, fmt); \
  369. va_list argList2; \
  370. va_copy(argList2, argList1); \
  371. OVR_GlobalLog->LogMessageVargInt(Log_##Name, fmt, argList2); \
  372. va_end(argList2); \
  373. OVR_GlobalLog->LogMessageVarg(Log_##Name, fmt, argList1); \
  374. va_end(argList1); \
  375. } \
  376. }
  377. #else
  378. #define OVR_LOG_FUNCTION_IMPL(Name) \
  379. void Log##Name(const char* fmt, ...) \
  380. { \
  381. if (OVR_GlobalLog) \
  382. { \
  383. va_list argList1; \
  384. va_start(argList1, fmt); \
  385. OVR_GlobalLog->LogMessageVargInt(Log_##Name, fmt, argList1); \
  386. OVR_GlobalLog->LogMessageVarg(Log_##Name, fmt, argList1); \
  387. va_end(argList1); \
  388. } \
  389. }
  390. #endif // #if !defined(OVR_OS_WIN32)
  391. OVR_LOG_FUNCTION_IMPL(Text)
  392. OVR_LOG_FUNCTION_IMPL(Error)
  393. #ifdef OVR_BUILD_DEBUG
  394. OVR_LOG_FUNCTION_IMPL(DebugText)
  395. OVR_LOG_FUNCTION_IMPL(Debug)
  396. OVR_LOG_FUNCTION_IMPL(Assert)
  397. #endif
  398. void OVR_Fail_F(const char* format, ...)
  399. {
  400. char message[512];
  401. va_list argList;
  402. va_start(argList, format);
  403. OVR_vsnprintf(message, sizeof(message), format, argList);
  404. va_end(argList);
  405. OVR_FAIL_M(message);
  406. }
  407. // Assertion handler support
  408. // To consider: Move this to an OVR_Types.cpp or OVR_Assert.cpp source file.
  409. static OVRAssertionHandler sOVRAssertionHandler = OVR::DefaultAssertionHandler;
  410. static intptr_t sOVRAssertionHandlerUserParameter = 0;
  411. OVRAssertionHandler GetAssertionHandler(intptr_t* userParameter)
  412. {
  413. if(userParameter)
  414. *userParameter = sOVRAssertionHandlerUserParameter;
  415. return sOVRAssertionHandler;
  416. }
  417. void SetAssertionHandler(OVRAssertionHandler assertionHandler, intptr_t userParameter)
  418. {
  419. sOVRAssertionHandler = assertionHandler;
  420. sOVRAssertionHandlerUserParameter = userParameter;
  421. }
  422. intptr_t DefaultAssertionHandler(intptr_t /*userParameter*/, const char* title, const char* message)
  423. {
  424. if(OVRIsDebuggerPresent())
  425. {
  426. OVR_DEBUG_BREAK;
  427. }
  428. else
  429. {
  430. OVR_UNUSED(title);
  431. OVR_UNUSED(message);
  432. #if defined(OVR_BUILD_DEBUG)
  433. if(Allocator::GetInstance()) // The code below currently depends on having a valid Allocator.
  434. {
  435. // Print a stack trace of all threads.
  436. OVR::String s;
  437. OVR::String threadListOutput;
  438. static OVR::SymbolLookup symbolLookup;
  439. s = "Failure: ";
  440. s += message;
  441. if(symbolLookup.Initialize() && symbolLookup.ReportThreadCallstack(threadListOutput, 4)) // This '4' is there to skip our internal handling and retrieve starting at the assertion location (our caller) only.
  442. {
  443. // threadListOutput has newlines that are merely \n, whereas Windows MessageBox wants \r\n newlines. So we insert \r in front of all \n.
  444. for(size_t i = 0, iEnd = threadListOutput.GetSize(); i < iEnd; i++)
  445. {
  446. if(threadListOutput[i] == '\n')
  447. {
  448. threadListOutput.Insert("\r", i, 1);
  449. ++i;
  450. ++iEnd;
  451. }
  452. }
  453. s += "\r\n\r\n";
  454. s += threadListOutput;
  455. }
  456. OVR::Util::DisplayMessageBox(title, s.ToCStr());
  457. }
  458. else
  459. {
  460. // See above.
  461. OVR::Util::DisplayMessageBox(title, message);
  462. }
  463. #else
  464. OVR::Util::DisplayMessageBox(title, message);
  465. #endif
  466. }
  467. return 0;
  468. }
  469. bool IsAutomationRunning()
  470. {
  471. #if defined(OVR_OS_WIN32)
  472. // We use the OS GetEnvironmentVariable function as opposed to getenv, as that
  473. // is process-wide as opposed to being tied to the current C runtime library.
  474. return GetEnvironmentVariableW(L"OvrAutomationRunning", NULL, 0) > 0;
  475. #else
  476. return getenv("OvrAutomationRunning") != nullptr;
  477. #endif
  478. }
  479. } // OVR