2023-03-28 20:08:02 +00:00
|
|
|
#include "log.h"
|
|
|
|
|
|
|
|
#include <dbghelp.h>
|
|
|
|
#include <stdbool.h>
|
|
|
|
#include <stdio.h>
|
|
|
|
#include <stdlib.h>
|
|
|
|
#include <time.h>
|
|
|
|
#pragma comment(lib, "DbgHelp.lib")
|
|
|
|
|
2023-03-30 15:15:59 +00:00
|
|
|
#include "../util/pid.h"
|
2023-03-28 20:08:02 +00:00
|
|
|
#include "config.h"
|
|
|
|
|
|
|
|
#define _LF(category, name, display) \
|
|
|
|
LOG_FACILITY lf##name = { \
|
|
|
|
.m_name = display, \
|
|
|
|
}; \
|
|
|
|
PLOG_FACILITY plf##name = &lf##name;
|
|
|
|
#include "log_facilities.def"
|
|
|
|
#undef _LF
|
|
|
|
|
2023-03-30 14:48:11 +00:00
|
|
|
static BOOL logIsMaster = FALSE;
|
|
|
|
|
2023-04-04 16:31:03 +00:00
|
|
|
CHAR logBasename[MAX_PATH + 1] = { 0 };
|
2023-03-28 20:08:02 +00:00
|
|
|
extern DWORD imageOffset;
|
|
|
|
|
|
|
|
extern BOOL(WINAPI* TrueWriteFile)(HANDLE hFile, LPCVOID lpBuffer, DWORD nNumberOfBytesToWrite,
|
|
|
|
LPDWORD lpNumberOfBytesWritten, LPOVERLAPPED lpOverlapped);
|
|
|
|
|
2023-04-04 16:31:03 +00:00
|
|
|
void MiceSetLogBasename(char* baseName) { strcpy_s(logBasename, sizeof logBasename, baseName); }
|
|
|
|
|
2023-03-28 20:08:02 +00:00
|
|
|
char _log_prelude[64];
|
|
|
|
char* log_prelude() {
|
|
|
|
time_t rawtime;
|
|
|
|
struct tm timeinfo;
|
|
|
|
|
|
|
|
time(&rawtime);
|
|
|
|
localtime_s(&timeinfo, &rawtime);
|
|
|
|
|
2023-04-04 16:31:03 +00:00
|
|
|
size_t offset = strftime(_log_prelude, sizeof _log_prelude, "[%Y/%m/%d %H:%M:%S] ", &timeinfo);
|
|
|
|
if (logBasename[0])
|
|
|
|
sprintf_s(_log_prelude + offset, sizeof _log_prelude - offset, "%s:", logBasename);
|
2023-03-28 20:08:02 +00:00
|
|
|
return _log_prelude;
|
|
|
|
}
|
|
|
|
|
|
|
|
static HANDLE log_file = INVALID_HANDLE_VALUE;
|
|
|
|
CRITICAL_SECTION logger_lock;
|
|
|
|
|
|
|
|
static char* log_colours[] = {
|
|
|
|
"", // Always
|
|
|
|
"\033[96m", // Game
|
|
|
|
"\033[91m", // Error
|
|
|
|
"\033[33m", // Warning
|
|
|
|
"\033[97m", // Info
|
|
|
|
"\033[90m", // Misc
|
|
|
|
"\033[90m", // Trace
|
|
|
|
};
|
|
|
|
static const char* COLOR_RESET = "\033[0m";
|
|
|
|
#define LOG_PREFIXES "!GEWIMT"
|
|
|
|
|
|
|
|
void logcb(LPCSTR param_1) { log_game(plfAmLog, "%s", param_1); }
|
|
|
|
void __stdcall amLogCallback(DWORD level, char* format) {
|
|
|
|
if (level == 0)
|
|
|
|
log_game(plfAmLog, "E:%s", format);
|
|
|
|
else if (level == 0)
|
|
|
|
log_game(plfAmLog, "W:%s", format);
|
|
|
|
else
|
|
|
|
log_game(plfAmLog, "I:%s", format);
|
|
|
|
}
|
|
|
|
|
|
|
|
DWORD pLogcb;
|
|
|
|
DWORD* ppLogcb;
|
|
|
|
|
2023-03-30 14:48:11 +00:00
|
|
|
HANDLE hSlot;
|
|
|
|
|
2023-03-28 20:08:02 +00:00
|
|
|
static char log_buf[1024];
|
|
|
|
int _do_log(BYTE log_level, PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
// Early-return if we have nothing to do
|
2023-03-30 14:48:11 +00:00
|
|
|
if (MiceConfig.mice.log_level < log_level) return 0;
|
2023-03-28 20:08:02 +00:00
|
|
|
|
|
|
|
// TODO: These are all horrible bodges
|
|
|
|
// if (wcscmp(exeName, L"mxnetwork.exe") == 0) {
|
|
|
|
// // *((DWORD*)(imageOffset + 0x004438e8)) = (DWORD)(&logcb);
|
|
|
|
// *((DWORD*)(imageOffset + 0x004438e8)) = 0x00000000;
|
|
|
|
// }
|
|
|
|
// if (wcscmp(exeName, L"maimai_dump_.exe") == 0) {
|
|
|
|
// *((DWORD*)(imageOffset + 0x00c820ec)) = 0x00000001;
|
|
|
|
// pLogcb = (DWORD)(&amLogCallback);
|
|
|
|
// ppLogcb = &pLogcb;
|
|
|
|
// *((DWORD***)(imageOffset + 0x00c820F4)) = &ppLogcb;
|
|
|
|
// // *((DWORD*)(imageOffset + 0x004438e8)) = (DWORD)(&logcb);
|
|
|
|
// }
|
|
|
|
|
|
|
|
char prefix = LOG_PREFIXES[log_level];
|
|
|
|
|
|
|
|
int col_len = strlen(log_colours[log_level]);
|
|
|
|
|
2023-03-30 14:48:11 +00:00
|
|
|
EnterCriticalSection(&logger_lock);
|
2023-03-28 20:08:02 +00:00
|
|
|
int log_len = snprintf(log_buf, _countof(log_buf), "%s%s%c:%s:", log_colours[log_level],
|
|
|
|
log_prelude(), prefix, facility->m_name);
|
|
|
|
log_len += vsnprintf(log_buf + log_len, _countof(log_buf) - log_len, format, args);
|
|
|
|
log_len += snprintf(log_buf + log_len, _countof(log_buf) - log_len, "%s\n", COLOR_RESET);
|
|
|
|
log_buf[_countof(log_buf) - 1] = '\0';
|
|
|
|
|
2023-03-30 14:48:11 +00:00
|
|
|
if (hSlot != INVALID_HANDLE_VALUE) {
|
|
|
|
WriteFile(hSlot, log_buf, log_len, NULL, NULL);
|
|
|
|
} else {
|
|
|
|
// This should never happen, but there's no harm being prepared in case it does
|
|
|
|
WriteFile(GetStdHandle(STD_OUTPUT_HANDLE), log_buf, log_len, NULL, NULL);
|
2023-03-28 20:08:02 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
LeaveCriticalSection(&logger_lock);
|
|
|
|
return log_len;
|
|
|
|
}
|
|
|
|
int vlog_trace(PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
return _do_log(LOG_TRACE, facility, format, args);
|
|
|
|
}
|
|
|
|
int _log_trace(PLOG_FACILITY facility, const char* format, ...) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
|
|
|
int ret = vlog_trace(facility, format, args);
|
|
|
|
va_end(args);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
int vlog_misc(PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
return _do_log(LOG_MISC, facility, format, args);
|
|
|
|
}
|
|
|
|
int _log_misc(PLOG_FACILITY facility, const char* format, ...) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
|
|
|
int ret = vlog_misc(facility, format, args);
|
|
|
|
va_end(args);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
int vlog_info(PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
return _do_log(LOG_INFO, facility, format, args);
|
|
|
|
}
|
|
|
|
int _log_info(PLOG_FACILITY facility, const char* format, ...) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
|
|
|
int ret = vlog_info(facility, format, args);
|
|
|
|
va_end(args);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
int vlog_warning(PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
return _do_log(LOG_WARNING, facility, format, args);
|
|
|
|
}
|
|
|
|
int _log_warning(PLOG_FACILITY facility, const char* format, ...) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
|
|
|
int ret = vlog_warning(facility, format, args);
|
|
|
|
va_end(args);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
int vlog_error(PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
return _do_log(LOG_ERROR, facility, format, args);
|
|
|
|
}
|
|
|
|
int _log_error(PLOG_FACILITY facility, const char* format, ...) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
|
|
|
int ret = vlog_error(facility, format, args);
|
|
|
|
va_end(args);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
int vlog_game(PLOG_FACILITY facility, const char* format, va_list args) {
|
|
|
|
return _do_log(LOG_GAME, facility, format, args);
|
|
|
|
}
|
|
|
|
int _log_game(PLOG_FACILITY facility, const char* format, ...) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
|
|
|
int ret = vlog_game(facility, format, args);
|
|
|
|
va_end(args);
|
|
|
|
return ret;
|
|
|
|
}
|
|
|
|
|
2023-03-30 15:15:59 +00:00
|
|
|
void setup_logging() {
|
2023-03-30 14:48:11 +00:00
|
|
|
char slotName[MAX_PATH + 1];
|
2023-03-30 15:15:59 +00:00
|
|
|
sprintf_s(slotName, MAX_PATH, "\\\\.\\mailslot\\micelog%d", GetOutermostMiceId());
|
2023-03-28 20:08:02 +00:00
|
|
|
|
2023-03-30 14:48:11 +00:00
|
|
|
hSlot = CreateFile(slotName, GENERIC_WRITE, FILE_SHARE_READ, NULL, OPEN_EXISTING,
|
|
|
|
FILE_ATTRIBUTE_NORMAL, NULL);
|
|
|
|
if (hSlot == INVALID_HANDLE_VALUE) {
|
|
|
|
fprintf(stderr, "Fatal: Failed to open mailslot %s", slotName);
|
|
|
|
ExitProcess(2);
|
|
|
|
}
|
2023-03-28 20:08:02 +00:00
|
|
|
|
|
|
|
InitializeCriticalSection(&logger_lock);
|
|
|
|
}
|
|
|
|
|
|
|
|
void log_stack(PLOG_FACILITY facility) {
|
|
|
|
char name[MAX_PATH * sizeof(TCHAR)];
|
|
|
|
char Storage[sizeof(IMAGEHLP_SYMBOL64) + sizeof(name)];
|
|
|
|
|
|
|
|
IMAGEHLP_SYMBOL64* symbol = (IMAGEHLP_SYMBOL64*)Storage;
|
|
|
|
CONTEXT context;
|
|
|
|
RtlCaptureContext(&context);
|
|
|
|
|
|
|
|
STACKFRAME64 stack = { 0 };
|
|
|
|
stack.AddrPC.Offset = context.Eip;
|
|
|
|
stack.AddrPC.Mode = AddrModeFlat;
|
|
|
|
stack.AddrStack.Offset = context.Esp;
|
|
|
|
stack.AddrStack.Mode = AddrModeFlat;
|
|
|
|
stack.AddrFrame.Offset = context.Ebp;
|
|
|
|
stack.AddrFrame.Mode = AddrModeFlat;
|
|
|
|
|
|
|
|
HANDLE process = GetCurrentProcess();
|
|
|
|
HANDLE thread = GetCurrentThread();
|
|
|
|
BOOL initres = SymInitialize(process, NULL, true);
|
|
|
|
for (ULONG frame = 0;; frame++) {
|
|
|
|
BOOL result = StackWalk64(IMAGE_FILE_MACHINE_I386, process, thread, &stack, &context, NULL,
|
|
|
|
SymFunctionTableAccess64, SymGetModuleBase64, NULL);
|
|
|
|
|
|
|
|
symbol->SizeOfStruct = sizeof(Storage);
|
|
|
|
symbol->MaxNameLength = sizeof(name);
|
|
|
|
|
|
|
|
DWORD64 displacement;
|
|
|
|
SymGetSymFromAddr64(process, (ULONG64)stack.AddrPC.Offset, &displacement, symbol);
|
|
|
|
UnDecorateSymbolName(symbol->Name, (PSTR)name, sizeof(name), UNDNAME_COMPLETE);
|
|
|
|
|
|
|
|
log_error(facility, "%02u called from 0x%08X STACK=0x%08X FRAME=0x%08X %s", frame,
|
|
|
|
(ULONG64)stack.AddrPC.Offset, (ULONG64)stack.AddrStack.Offset,
|
|
|
|
(ULONG64)stack.AddrFrame.Offset, symbol->Name);
|
|
|
|
|
|
|
|
if (result == FALSE) {
|
|
|
|
DWORD frameError = GetLastError();
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|