Logging.cpp 9.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430
  1. /*
  2. * Logging.cpp
  3. * -----------
  4. * Purpose: General logging
  5. * Notes : (currently none)
  6. * Authors: OpenMPT Devs
  7. * The OpenMPT source code is released under the BSD license. Read LICENSE for more details.
  8. */
  9. #include "stdafx.h"
  10. #include "Logging.h"
  11. #include "mpt/io/base.hpp"
  12. #include "mpt/io/io.hpp"
  13. #include "mpt/io/io_stdstream.hpp"
  14. #include "mptFileIO.h"
  15. #if defined(MODPLUG_TRACKER)
  16. #include <atomic>
  17. #endif
  18. #include "version.h"
  19. #include <iostream>
  20. #include <cstdarg>
  21. #include <cstring>
  22. #include <stdarg.h>
  23. OPENMPT_NAMESPACE_BEGIN
  24. namespace mpt
  25. {
  26. namespace log
  27. {
  28. #if !defined(MPT_LOG_GLOBAL_LEVEL_STATIC)
  29. #if defined(MPT_LOG_GLOBAL_LEVEL)
  30. int GlobalLogLevel = static_cast<int>(MPT_LOG_GLOBAL_LEVEL);
  31. #else
  32. int GlobalLogLevel = static_cast<int>(LogDebug);
  33. #endif
  34. #endif
  35. #if defined(MODPLUG_TRACKER) && !defined(MPT_LOG_IS_DISABLED)
  36. bool FileEnabled = false;
  37. bool DebuggerEnabled = true;
  38. bool ConsoleEnabled = false;
  39. static char g_FacilitySolo[1024] = {0};
  40. static char g_FacilityBlocked[1024] = {0};
  41. void SetFacilities(const std::string &solo, const std::string &blocked)
  42. {
  43. std::strcpy(g_FacilitySolo, solo.c_str());
  44. std::strcpy(g_FacilityBlocked, blocked.c_str());
  45. }
  46. bool IsFacilityActive(const char *facility) noexcept
  47. {
  48. if(facility)
  49. {
  50. if(std::strlen(g_FacilitySolo) > 0)
  51. {
  52. if(std::strcmp(facility, g_FacilitySolo) != 0)
  53. {
  54. return false;
  55. }
  56. }
  57. if(std::strlen(g_FacilityBlocked) > 0)
  58. {
  59. if(std::strcmp(facility, g_FacilitySolo) == 0)
  60. {
  61. return false;
  62. }
  63. }
  64. }
  65. return true;
  66. }
  67. #endif
  68. void GlobalLogger::SendLogMessage(const mpt::source_location &loc, LogLevel level, const char *facility, const mpt::ustring &text) const
  69. {
  70. #ifdef MPT_LOG_IS_DISABLED
  71. MPT_UNREFERENCED_PARAMETER(loc);
  72. MPT_UNREFERENCED_PARAMETER(level);
  73. MPT_UNREFERENCED_PARAMETER(facility);
  74. MPT_UNREFERENCED_PARAMETER(text);
  75. #else // !MPT_LOG_IS_DISABLED
  76. MPT_MAYBE_CONSTANT_IF(mpt::log::GlobalLogLevel < level)
  77. {
  78. return;
  79. }
  80. #if defined(MODPLUG_TRACKER)
  81. if(!IsFacilityActive(facility))
  82. {
  83. return;
  84. }
  85. #else // !MODPLUG_TRACKER
  86. MPT_UNREFERENCED_PARAMETER(facility);
  87. #endif // MODPLUG_TRACKER
  88. // remove eol if already present and add log level prefix
  89. const mpt::ustring message = LogLevelToString(level) + U_(": ") + mpt::trim_right(text, U_("\r\n"));
  90. const mpt::ustring file = mpt::ToUnicode(mpt::CharsetSource, loc.file_name() ? loc.file_name() : "");
  91. const mpt::ustring function = mpt::ToUnicode(mpt::CharsetSource, loc.function_name() ? loc.function_name() : "");
  92. const mpt::ustring line = mpt::ufmt::dec(loc.line());
  93. #if defined(MODPLUG_TRACKER) && !defined(MPT_BUILD_WINESUPPORT)
  94. #if MPT_OS_WINDOWS
  95. static uint64 s_lastlogtime = 0;
  96. uint64 cur = mpt::Date::ANSI::Now();
  97. uint64 diff = cur/10000 - s_lastlogtime;
  98. s_lastlogtime = cur/10000;
  99. #else
  100. uint64 cur = 0;
  101. uint64 diff = 0;
  102. #endif
  103. if(mpt::log::FileEnabled)
  104. {
  105. static std::optional<mpt::ofstream> s_logfile;
  106. if(!s_logfile)
  107. {
  108. s_logfile.emplace(P_("mptrack.log"), std::ios::app);
  109. }
  110. if(s_logfile)
  111. {
  112. mpt::IO::WriteText(*s_logfile, mpt::ToCharset(mpt::CharsetLogfile, MPT_UFORMAT("{}+{} {}({}): {} [{}]\n")
  113. ( mpt::Date::ANSI::ToUString(cur)
  114. , mpt::ufmt::right(6, mpt::ufmt::dec(diff))
  115. , file
  116. , line
  117. , message
  118. , function
  119. )));
  120. mpt::IO::Flush(*s_logfile);
  121. }
  122. }
  123. if(mpt::log::DebuggerEnabled)
  124. {
  125. OutputDebugStringW(mpt::ToWide(MPT_UFORMAT("{}({}): +{} {} [{}]\n")
  126. ( file
  127. , line
  128. , mpt::ufmt::right(6, mpt::ufmt::dec(diff))
  129. , message
  130. , function
  131. )).c_str());
  132. }
  133. if(mpt::log::ConsoleEnabled)
  134. {
  135. static bool consoleInited = false;
  136. if(!consoleInited)
  137. {
  138. AllocConsole();
  139. consoleInited = true;
  140. }
  141. std::wstring consoletext = mpt::ToWide(message) + L"\r\n";
  142. DWORD dummy = 0;
  143. WriteConsoleW(GetStdHandle(STD_OUTPUT_HANDLE), consoletext.c_str(), mpt::saturate_cast<DWORD>(consoletext.length()), &dummy, NULL);
  144. }
  145. #elif defined(MODPLUG_TRACKER) && defined(MPT_BUILD_WINESUPPORT)
  146. std::clog
  147. << "NativeSupport: "
  148. << mpt::ToCharset(mpt::CharsetStdIO, file) << "(" << mpt::ToCharset(mpt::CharsetStdIO, line) << ")" << ": "
  149. << mpt::ToCharset(mpt::CharsetStdIO, message)
  150. << " [" << mpt::ToCharset(mpt::CharsetStdIO, function) << "]"
  151. << std::endl;
  152. #else // !MODPLUG_TRACKER
  153. std::clog
  154. << "libopenmpt: "
  155. << mpt::ToCharset(mpt::CharsetStdIO, file) << "(" << mpt::ToCharset(mpt::CharsetStdIO, line) << ")" << ": "
  156. << mpt::ToCharset(mpt::CharsetStdIO, message)
  157. << " [" << mpt::ToCharset(mpt::CharsetStdIO, function) << "]"
  158. << std::endl;
  159. #endif // MODPLUG_TRACKER
  160. #endif // MPT_LOG_IS_DISABLED
  161. }
  162. #if defined(MODPLUG_TRACKER)
  163. namespace Trace {
  164. #if MPT_OS_WINDOWS
  165. // Debugging functionality will use simple globals.
  166. std::atomic<bool> g_Enabled{false};
  167. static bool g_Sealed = false;
  168. struct Entry {
  169. uint32 Index;
  170. uint32 ThreadId;
  171. uint64 Timestamp;
  172. const char * Function;
  173. const char * File;
  174. int Line;
  175. Direction Direction;
  176. };
  177. static MPT_FORCEINLINE bool operator < (const Entry &a, const Entry &b) noexcept
  178. {
  179. /*
  180. return false
  181. || (a.Timestamp < b.Timestamp)
  182. || (a.ThreadID < b.ThreadID)
  183. || (a.File < b.File)
  184. || (a.Line < b.Line)
  185. || (a.Function < b.Function)
  186. ;
  187. */
  188. return false
  189. || (a.Index < b.Index)
  190. ;
  191. }
  192. static std::vector<mpt::log::Trace::Entry> Entries;
  193. static std::atomic<uint32> NextIndex(0);
  194. static uint32 ThreadIdGUI = 0;
  195. static uint32 ThreadIdAudio = 0;
  196. static uint32 ThreadIdNotify = 0;
  197. static uint32 ThreadIdWatchdir = 0;
  198. void Enable(std::size_t numEntries)
  199. {
  200. if(g_Sealed)
  201. {
  202. return;
  203. }
  204. Entries.clear();
  205. Entries.resize(numEntries);
  206. NextIndex.store(0);
  207. g_Enabled = (numEntries > 0);
  208. }
  209. void Disable()
  210. {
  211. if(g_Sealed)
  212. {
  213. return;
  214. }
  215. g_Enabled = false;
  216. }
  217. MPT_NOINLINE void Trace(const mpt::source_location & loc, Direction direction) noexcept
  218. {
  219. // This will get called in realtime contexts and hot paths.
  220. // No blocking allowed here.
  221. const uint32 index = NextIndex.fetch_add(1);
  222. const std::size_t numEntries = Entries.size();
  223. #if 1
  224. LARGE_INTEGER time;
  225. time.QuadPart = 0;
  226. QueryPerformanceCounter(&time);
  227. const uint64 timestamp = time.QuadPart;
  228. #else
  229. FILETIME time = FILETIME();
  230. GetSystemTimeAsFileTime(&time);
  231. const uint64 timestamp = (static_cast<uint64>(time.dwHighDateTime) << 32) | (static_cast<uint64>(time.dwLowDateTime) << 0);
  232. #endif
  233. const uint32 threadid = static_cast<uint32>(GetCurrentThreadId());
  234. mpt::log::Trace::Entry & entry = Entries[index % numEntries];
  235. entry.Index = index;
  236. entry.ThreadId = threadid;
  237. entry.Timestamp = timestamp;
  238. entry.Function = loc.function_name();
  239. entry.File = loc.file_name();
  240. entry.Line = loc.line();
  241. entry.Direction = direction;
  242. }
  243. void Seal()
  244. {
  245. if(!g_Enabled)
  246. {
  247. return;
  248. }
  249. g_Enabled = false;
  250. g_Sealed = true;
  251. uint32 count = NextIndex.fetch_add(0);
  252. if(count < Entries.size())
  253. {
  254. Entries.resize(count);
  255. }
  256. }
  257. bool Dump(const mpt::PathString &filename)
  258. {
  259. if(!g_Sealed)
  260. {
  261. return false;
  262. }
  263. LARGE_INTEGER qpcNow;
  264. qpcNow.QuadPart = 0;
  265. QueryPerformanceCounter(&qpcNow);
  266. uint64 ftNow = mpt::Date::ANSI::Now();
  267. // sort according to index in case of overflows
  268. std::stable_sort(Entries.begin(), Entries.end());
  269. mpt::ofstream f(filename);
  270. f << "Build: OpenMPT " << mpt::ToCharset(mpt::CharsetLogfile, Build::GetVersionStringExtended()) << std::endl;
  271. bool qpcValid = false;
  272. LARGE_INTEGER qpcFreq;
  273. qpcFreq.QuadPart = 0;
  274. QueryPerformanceFrequency(&qpcFreq);
  275. if(qpcFreq.QuadPart > 0)
  276. {
  277. qpcValid = true;
  278. }
  279. f << "Dump: " << mpt::ToCharset(mpt::CharsetLogfile, mpt::Date::ANSI::ToUString(ftNow)) << std::endl;
  280. f << "Captured events: " << Entries.size() << std::endl;
  281. if(qpcValid && (Entries.size() > 0))
  282. {
  283. double period = static_cast<double>(Entries[Entries.size() - 1].Timestamp - Entries[0].Timestamp) / static_cast<double>(qpcFreq.QuadPart);
  284. double eventsPerSecond = Entries.size() / period;
  285. f << "Period [s]: " << mpt::afmt::fix(period) << std::endl;
  286. f << "Events/second: " << mpt::afmt::fix(eventsPerSecond) << std::endl;
  287. }
  288. for(auto &entry : Entries)
  289. {
  290. if(!entry.Function) entry.Function = "";
  291. if(!entry.File) entry.File = "";
  292. std::string time;
  293. if(qpcValid)
  294. {
  295. time = mpt::ToCharset(mpt::CharsetLogfile, mpt::Date::ANSI::ToUString( ftNow - static_cast<int64>( static_cast<double>(qpcNow.QuadPart - entry.Timestamp) * (10000000.0 / static_cast<double>(qpcFreq.QuadPart) ) ) ) );
  296. } else
  297. {
  298. time = MPT_AFORMAT("0x{}")(mpt::afmt::hex0<16>(entry.Timestamp));
  299. }
  300. f << time;
  301. if(entry.ThreadId == ThreadIdGUI)
  302. {
  303. f << " -----GUI ";
  304. } else if(entry.ThreadId == ThreadIdAudio)
  305. {
  306. f << " ---Audio ";
  307. } else if(entry.ThreadId == ThreadIdNotify)
  308. {
  309. f << " --Notify ";
  310. } else if(entry.ThreadId == ThreadIdWatchdir)
  311. {
  312. f << " WatchDir ";
  313. } else
  314. {
  315. f << " " << mpt::afmt::hex0<8>(entry.ThreadId) << " ";
  316. }
  317. f << (entry.Direction == mpt::log::Trace::Direction::Enter ? ">" : entry.Direction == mpt::log::Trace::Direction::Leave ? "<" : " ") << " ";
  318. f << entry.File << "(" << entry.Line << "): " << entry.Function;
  319. f << std::endl;
  320. }
  321. return true;
  322. }
  323. void SetThreadId(mpt::log::Trace::ThreadKind kind, uint32 id)
  324. {
  325. if(id == 0)
  326. {
  327. return;
  328. }
  329. switch(kind)
  330. {
  331. case ThreadKindGUI:
  332. ThreadIdGUI = id;
  333. break;
  334. case ThreadKindAudio:
  335. ThreadIdAudio = id;
  336. break;
  337. case ThreadKindNotify:
  338. ThreadIdNotify = id;
  339. break;
  340. case ThreadKindWatchdir:
  341. ThreadIdWatchdir = id;
  342. break;
  343. }
  344. }
  345. uint32 GetThreadId(mpt::log::Trace::ThreadKind kind)
  346. {
  347. uint32 result = 0;
  348. switch(kind)
  349. {
  350. case ThreadKindGUI:
  351. result = ThreadIdGUI;
  352. break;
  353. case ThreadKindAudio:
  354. result = ThreadIdAudio;
  355. break;
  356. case ThreadKindNotify:
  357. result = ThreadIdNotify;
  358. break;
  359. case ThreadKindWatchdir:
  360. result = ThreadIdWatchdir;
  361. break;
  362. }
  363. return result;
  364. }
  365. #endif // MPT_OS_WINDOWS
  366. } // namespace Trace
  367. #endif // MODPLUG_TRACKER
  368. } // namespace log
  369. } // namespace mpt
  370. OPENMPT_NAMESPACE_END