9
3

Log.cpp 16 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612
  1. /*
  2. EQ2Emulator: Everquest II Server Emulator
  3. Copyright (C) 2007 EQ2EMulator Development Team (http://www.eq2emulator.net)
  4. This file is part of EQ2Emulator.
  5. EQ2Emulator is free software: you can redistribute it and/or modify
  6. it under the terms of the GNU General Public License as published by
  7. the Free Software Foundation, either version 3 of the License, or
  8. (at your option) any later version.
  9. EQ2Emulator is distributed in the hope that it will be useful,
  10. but WITHOUT ANY WARRANTY; without even the implied warranty of
  11. MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  12. GNU General Public License for more details.
  13. You should have received a copy of the GNU General Public License
  14. along with EQ2Emulator. If not, see <http://www.gnu.org/licenses/>.
  15. */
  16. #include "Log.h"
  17. #include "xmlParser.h"
  18. #include "types.h"
  19. #include <stdlib.h>
  20. #include <stdio.h>
  21. #include <stdarg.h>
  22. #include <string.h>
  23. #include <errno.h>
  24. #include <time.h>
  25. #include <sys/stat.h>
  26. #include "../WorldServer/World.h"
  27. #include "../WorldServer/client.h"
  28. #include "../WorldServer/zoneserver.h"
  29. extern ZoneList zone_list;
  30. #ifdef _WIN32
  31. #include <process.h>
  32. #ifndef snprintf
  33. #define snprintf sprintf_s
  34. #endif
  35. #include <WinSock2.h>
  36. #include <Windows.h>
  37. #else
  38. #endif
  39. #define LOG_CATEGORY(category) #category,
  40. const char *log_category_names[NUMBER_OF_LOG_CATEGORIES] = {
  41. #include "LogTypes.h"
  42. };
  43. #define LOG_TYPE(category, type, level, color, enabled, logfile, console, client, str) { level, color, enabled, logfile, console, client, LOG_ ##category, #category "__" #type, ( strlen(str)>0 ) ? str : #category "__" #type },
  44. static LogTypeStatus real_log_type_info[NUMBER_OF_LOG_TYPES+1] =
  45. {
  46. #include "LogTypes.h"
  47. { 0, 0, false, false, false, false, NUMBER_OF_LOG_CATEGORIES, "BAD TYPE", "Bad Name" } /* dummy trailing record */
  48. };
  49. LogTypeStatus *log_type_info = real_log_type_info;
  50. //make these rules?
  51. #define LOG_CYCLE 100 //milliseconds between each batch of log writes
  52. #define LOGS_PER_CYCLE 50 //amount of logs to write per cycle
  53. #define LOG_DIR "logs"
  54. #if defined LOGIN
  55. #define EXE_NAME "login"
  56. #elif defined WORLD
  57. #define EXE_NAME "world"
  58. #elif defined PARSER
  59. #define EXE_NAME "parser"
  60. #elif defined PATCHER
  61. #define EXE_NAME "patcher"
  62. #else
  63. #define EXE_NAME "whatprogyourunning"
  64. #endif
  65. #define DATE_MAX 8
  66. #define LOG_NAME_MAX 32
  67. struct logq_t {
  68. LogType log_type;
  69. char date[DATE_MAX + 1];
  70. char name[LOG_NAME_MAX + 1];
  71. char *text;
  72. struct logq_t *next;
  73. struct logq_t *prev;
  74. };
  75. //doubly linked list of logs
  76. static logq_t head;
  77. static logq_t tail;
  78. static int num_logqs = 0;
  79. static Mutex mlogqs;
  80. //loop until....
  81. static bool looping = false;
  82. //because our code has LogWrite's before main(), make sure any of those do the
  83. //call to LogStart if it hasn't been called already...
  84. static bool start_called = false;
  85. static void SetConsoleColor(int color) {
  86. #ifdef _WIN32
  87. HANDLE handle = GetStdHandle(STD_OUTPUT_HANDLE);
  88. if (handle == NULL || handle == INVALID_HANDLE_VALUE)
  89. return;
  90. #endif
  91. switch (color) {
  92. case FOREGROUND_WHITE:
  93. case FOREGROUND_WHITE_BOLD:
  94. case FOREGROUND_RED:
  95. case FOREGROUND_RED_BOLD:
  96. case FOREGROUND_GREEN:
  97. case FOREGROUND_GREEN_BOLD:
  98. case FOREGROUND_BLUE:
  99. case FOREGROUND_BLUE_BOLD:
  100. case FOREGROUND_YELLOW:
  101. case FOREGROUND_YELLOW_BOLD:
  102. case FOREGROUND_CYAN:
  103. case FOREGROUND_CYAN_BOLD:
  104. case FOREGROUND_MAGENTA:
  105. case FOREGROUND_MAGENTA_BOLD:
  106. #ifdef _WIN32
  107. SetConsoleTextAttribute(handle, color);
  108. #else
  109. printf("\033[%i;%i;40m", color > 100 ? 1 : 0, color > 100 ? color - 100 : color);
  110. #endif
  111. break;
  112. default:
  113. #ifdef _WIN32
  114. SetConsoleTextAttribute(handle, FOREGROUND_WHITE_BOLD);
  115. #else
  116. printf("\033[0;37;40m");
  117. #endif
  118. break;
  119. }
  120. }
  121. static FILE * OpenLogFile() {
  122. char file[FILENAME_MAX + 1];
  123. struct stat st;
  124. struct tm *tm;
  125. time_t now;
  126. FILE *f;
  127. now = time(NULL);
  128. tm = localtime(&now);
  129. //make sure the logs directory exists
  130. if (stat(LOG_DIR, &st) != 0) {
  131. #ifdef _WIN32
  132. if (!CreateDirectory(LOG_DIR, NULL)) {
  133. fprintf(stderr, "Unable to create directory '%s'\n", LOG_DIR);
  134. return stderr;
  135. }
  136. #else
  137. if (mkdir(LOG_DIR, S_IRWXU | S_IRWXG | S_IROTH | S_IXOTH) != 0) {
  138. fprintf(stderr, "Unable to create direcotry '%s': %s\n", LOG_DIR, strerror(errno));
  139. return stderr;
  140. }
  141. #endif
  142. }
  143. #ifdef NO_PIDLOG
  144. snprintf(file, FILENAME_MAX, LOG_DIR"/%04i-%02i-%02i_eq2" EXE_NAME ".log", tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday);
  145. #else
  146. snprintf(file, FILENAME_MAX, LOG_DIR"/%04i-%02i-%02i_eq2" EXE_NAME "_%04i.log", tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday, getpid());
  147. #endif
  148. if ((f = fopen(file, "a")) == NULL) {
  149. fprintf(stderr, "Could not open '%s' for writing: %s\n", file, strerror(errno));
  150. return stderr;
  151. }
  152. return f;
  153. }
  154. static void WriteQueuedLogs(int count) {
  155. logq_t pending_head, pending_tail, *logq, *tmp;
  156. int i = 0;
  157. FILE *f;
  158. pending_head.next = &pending_tail;
  159. pending_tail.prev = &pending_head;
  160. //loop through our queued logs and store at most `count` logs into a temporary list
  161. //since io functions are expensive, we'll write from a temporary list so we don't hold the
  162. //write lock of the main list for a long period of time
  163. mlogqs.writelock();
  164. logq = head.next;
  165. while (head.next != &tail) {
  166. //first remove the log from the master list
  167. logq = head.next;
  168. logq->next->prev = &head;
  169. head.next = logq->next;
  170. //now insert it into the temporary list
  171. tmp = pending_tail.prev;
  172. tmp->next = logq;
  173. logq->prev = tmp;
  174. logq->next = &pending_tail;
  175. pending_tail.prev = logq;
  176. --num_logqs;
  177. logq = logq->next;
  178. //if we have a limit, check it
  179. if (count > 0 && ++i == count)
  180. break;
  181. }
  182. mlogqs.releasewritelock();
  183. //if we have no logs to write, we're done
  184. if ((logq = pending_head.next) == &pending_tail)
  185. return;
  186. while (logq != &pending_tail) {
  187. if (log_type_info[logq->log_type].console) {
  188. SetConsoleColor(FOREGROUND_WHITE_BOLD);
  189. printf("%s ", logq->date);
  190. SetConsoleColor(log_type_info[logq->log_type].color);
  191. printf("%s ", log_type_info[logq->log_type].display_name);
  192. SetConsoleColor(FOREGROUND_WHITE_BOLD);
  193. printf("%-10s: ", logq->name);
  194. SetConsoleColor(log_type_info[logq->log_type].color);
  195. printf("%s\n", logq->text);
  196. SetConsoleColor(-1);
  197. fflush(stdout);
  198. }
  199. if (log_type_info[logq->log_type].logfile) {
  200. f = OpenLogFile();
  201. if (f != stderr || (f == stderr && !log_type_info[logq->log_type].console)) {
  202. fprintf(f, "%s %s %s: %s\n", logq->date, log_type_info[logq->log_type].display_name, logq->name, logq->text);
  203. fflush(f);
  204. if (f != stderr)
  205. fclose(f);
  206. }
  207. }
  208. #if defined WORLD
  209. if (log_type_info[logq->log_type].client) {
  210. // eventually output logging to the client who "subscribed" to the logger
  211. // in-game, they type:
  212. // /logsys add WORLD__DEBUG 5
  213. // to watch world debug loggers of level 5 or less
  214. }
  215. #endif
  216. tmp = logq;
  217. logq = logq->next;
  218. free(tmp->text);
  219. free(tmp);
  220. }
  221. }
  222. ThreadReturnType LogLoop(void *args) {
  223. while (looping) {
  224. WriteQueuedLogs(LOGS_PER_CYCLE);
  225. Sleep(LOG_CYCLE);
  226. }
  227. THREAD_RETURN(NULL);
  228. }
  229. void LogStart() {
  230. if (start_called)
  231. return;
  232. //initialize the doubly linked list
  233. head.prev = NULL;
  234. head.next = &tail;
  235. tail.prev = &head;
  236. tail.next = NULL;
  237. mlogqs.SetName("logqueue");
  238. looping = true;
  239. #ifdef _WIN32
  240. _beginthread(LogLoop, 0, NULL);
  241. #else
  242. pthread_t thread;
  243. pthread_create(&thread, NULL, LogLoop, NULL);
  244. pthread_detach(thread);
  245. #endif
  246. start_called = true;
  247. }
  248. void LogStop() {
  249. looping = false;
  250. WriteQueuedLogs(-1);
  251. start_called = false;
  252. }
  253. static void LogQueueAdd(LogType log_type, char *text, int len, const char *cat_text = NULL) {
  254. logq_t *logq;
  255. struct tm *tm;
  256. time_t now;
  257. if ((logq = (logq_t *)calloc(1, sizeof(logq_t))) == NULL) {
  258. free(text);
  259. fprintf(stderr, "%s: %u: Unable to allocate %zu bytes\n", __FUNCTION__, __LINE__, sizeof(logq_t));
  260. return;
  261. }
  262. if ((logq->text = (char *)calloc(len + 1, sizeof(char))) == NULL) {
  263. free(text);
  264. free(logq);
  265. fprintf(stderr, "%s: %u: Unable to allocate %i bytes\n", __FUNCTION__, __LINE__, len + 1);
  266. return;
  267. }
  268. now = time(NULL);
  269. tm = localtime(&now);
  270. logq->log_type = log_type;
  271. snprintf(logq->date, DATE_MAX + 1, "%02i:%02i:%02i", tm->tm_hour, tm->tm_min, tm->tm_sec);
  272. strncpy(logq->name, cat_text == NULL || cat_text[0] == '\0' ? log_type_info[log_type].name : cat_text, LOG_NAME_MAX);
  273. strncpy(logq->text, text, len);
  274. free(text);
  275. if (!start_called)
  276. LogStart();
  277. //insert at the end
  278. mlogqs.writelock();
  279. tail.prev->next = logq;
  280. logq->prev = tail.prev;
  281. logq->next = &tail;
  282. tail.prev = logq;
  283. ++num_logqs;
  284. mlogqs.releasewritelock();
  285. }
  286. int8 GetLoggerLevel(LogType type)
  287. {
  288. return log_type_info[type].level;
  289. }
  290. // JA: horrific hack for Parser, since queued logging keeps crashing between parses.
  291. #ifndef PARSER
  292. void LogWrite(LogType type, int8 log_level, const char *cat_text, const char *fmt, ...) {
  293. int count, size = 64;
  294. char *buf;
  295. va_list ap;
  296. // if there is no formatting, or the logger is DISABLED
  297. // or the log_level param exceeds the minimum allowed value, abort logwrite
  298. if (!log_type_info[type].enabled || (log_level > 0 && log_type_info[type].level < log_level))
  299. return;
  300. while (true) {
  301. if ((buf = (char *)malloc(size)) == NULL) {
  302. fprintf(stderr, "%s: %i: Unable to allocate %i bytes\n", __FUNCTION__, __LINE__, size);
  303. return;
  304. }
  305. va_start(ap, fmt);
  306. count = vsnprintf(buf, size, fmt, ap);
  307. va_end(ap);
  308. if (count > -1 && count < size)
  309. break;
  310. free(buf);
  311. if (count > 1)
  312. size = count + 1;
  313. else
  314. size *= 2;
  315. }
  316. LogQueueAdd(type, buf, count, cat_text);
  317. }
  318. #else
  319. void LogWrite(LogType type, int8 log_level, const char *cat_text, const char *format, ...)
  320. {
  321. // if there is no formatting, or the logger is DISABLED
  322. // or the log_level param exceeds the minimum allowed value, abort logwrite
  323. if ( !format || !log_type_info[type].enabled || (log_level > 0 && log_type_info[type].level < log_level) )
  324. return;
  325. time_t clock;
  326. struct tm *tm;
  327. char buffer[LOG_BUFFER_SIZE], date[32];
  328. va_list args;
  329. FILE *f;
  330. size_t cat_text_len = 0;
  331. memset(buffer, 0, sizeof(buffer));
  332. memset(date, 0, sizeof(date));
  333. va_start(args, format);
  334. vsnprintf(buffer, sizeof(buffer) - 1, format, args);
  335. va_end(args);
  336. time(&clock);
  337. tm = localtime(&clock);
  338. snprintf(date, sizeof(date)-1, "%02d:%02d:%02d", tm->tm_hour, tm->tm_min, tm->tm_sec);
  339. // DateString(date, sizeof(date));
  340. cat_text_len = strlen(cat_text);
  341. //if( strlen(cat_text) == 0 ) // cat_text was blank
  342. // cat_text = (char*)log_type_info[type].name;
  343. /* write to the log file? */
  344. if (log_type_info[type].logfile)
  345. {
  346. char exename[200] = "";
  347. #ifdef LOGIN
  348. snprintf(exename, sizeof(exename), "login");
  349. #endif
  350. #ifdef WORLD
  351. snprintf(exename, sizeof(exename), "world");
  352. #endif
  353. #ifdef PARSER
  354. snprintf(exename, sizeof(exename), "parser");
  355. #endif
  356. #ifdef PATCHER
  357. snprintf(exename, sizeof(exename), "patcher");
  358. #endif
  359. char filename[200], log_header[200] = "";
  360. #ifndef NO_PIDLOG
  361. snprintf(filename, sizeof(filename)-1, "logs/%04d-%02d-%02d_eq2%s_%04i.log", tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday, exename, getpid());
  362. #else
  363. snprintf(filename, sizeof(filename)-1, "logs/%04d-%02d-%02d_eq2%s.log", tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday, exename);
  364. #endif
  365. f=fopen(filename, "r");
  366. if( !f )
  367. snprintf(log_header, sizeof(log_header), "===[ New log '%s' started ]===\n\n", filename);
  368. else
  369. fclose (f);
  370. f = fopen(filename, "a");
  371. if (f) {
  372. if( strlen(log_header) > 0 )
  373. fprintf(f, "%s\n", log_header);
  374. fprintf(f, "%s %s %s: %s\n", date, log_type_info[type].display_name, cat_text, buffer);
  375. fclose(f);
  376. }
  377. }
  378. /* write to the console? */
  379. if (log_type_info[type].console)
  380. {
  381. #ifdef _WIN32
  382. ColorizeLog(log_type_info[type].color, date, log_type_info[type].display_name, cat_text_len == 0 ? log_type_info[type].name : cat_text, (string)buffer);
  383. #else
  384. printf("%s %s %s: %s\n", date, log_type_info[type].display_name, cat_text_len == 0 ? log_type_info[type].name : cat_text, buffer);
  385. #endif
  386. }
  387. }
  388. void
  389. ColorizeLog(int color, char *date, const char *display_name, const char *category, string buffer)
  390. {
  391. #ifdef _WIN32
  392. HANDLE console = GetStdHandle(STD_OUTPUT_HANDLE);
  393. if (console == INVALID_HANDLE_VALUE) {
  394. printf("%s %s %s: %s\n", date, display_name, category, buffer);
  395. return;
  396. }
  397. printf("%s ", date);
  398. SetConsoleTextAttribute(console, color);
  399. printf("%s ", display_name);
  400. SetConsoleTextAttribute(console, FOREGROUND_WHITE_BOLD);
  401. printf("%s: ", category);
  402. SetConsoleTextAttribute(console, color);
  403. printf("%s\n", buffer.c_str());
  404. SetConsoleTextAttribute(console, FOREGROUND_WHITE);
  405. #endif
  406. }
  407. #endif
  408. LogTypeStatus *
  409. GetLogTypeStatus(const char *category, const char *type) {
  410. char combined[256];
  411. int i;
  412. memset(combined, 0, sizeof(combined));
  413. snprintf(combined, sizeof(combined) - 1, "%s__%s", category, type);
  414. for (i = 0; i < NUMBER_OF_LOG_TYPES; i++) {
  415. if (strcasecmp(log_type_info[i].name, combined) == 0)
  416. return &log_type_info[i];
  417. }
  418. return &log_type_info[NUMBER_OF_LOG_TYPES];
  419. }
  420. void
  421. ProcessLogConfig(XMLNode node) {
  422. int i;
  423. const char *category, *type, *level, *color, *enabled, *logs;
  424. LogTypeStatus *lfs;
  425. XMLNode child;
  426. category = node.getAttribute("Category");
  427. if (!category) {
  428. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Config missing a Category");
  429. return;
  430. }
  431. for (i = 0; i < node.nChildNode("ConfigType"); i++) {
  432. child = node.getChildNode("ConfigType", i);
  433. type = child.getAttribute("Type");
  434. if (!type) {
  435. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Config missing a Type");
  436. continue;
  437. }
  438. lfs = GetLogTypeStatus(category, type);
  439. level = child.getAttribute("Level");
  440. enabled = child.getAttribute("Enabled");
  441. color = child.getAttribute("Color");
  442. logs = child.getAttribute("Logs");
  443. if (!logs) {
  444. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Config missing 'Logs' attribute to specify which log(s) to write to");
  445. continue;
  446. }
  447. if (!IsNumber(logs)) {
  448. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Attribute 'Logs' must be a number. See LogTypes.h for the valid types.");
  449. continue;
  450. }
  451. if (enabled) {
  452. if (!strcasecmp("true", enabled) || !strcasecmp("on", enabled))
  453. lfs->enabled = true;
  454. else if (!strcasecmp("false", enabled) || !strcasecmp("off", enabled))
  455. lfs->enabled = false;
  456. else
  457. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Log setting 'Enabled' has invalid value '%s'. 'true'/'on' or 'false'/'off' are valid values", enabled);
  458. }
  459. if (IsNumber(level))
  460. lfs->level = atoi(level);
  461. else
  462. lfs->level = 0;
  463. if (color) {
  464. if (IsNumber(color))
  465. lfs->color = atoi(color);
  466. else if (!strcasecmp("White", color))
  467. lfs->color = FOREGROUND_WHITE;
  468. else if (!strcasecmp("Green", color))
  469. lfs->color = FOREGROUND_GREEN;
  470. else if (!strcasecmp("Yellow", color))
  471. lfs->color = FOREGROUND_YELLOW;
  472. else if (!strcasecmp("Red", color))
  473. lfs->color = FOREGROUND_RED;
  474. else if (!strcasecmp("Blue", color))
  475. lfs->color = FOREGROUND_BLUE;
  476. else if (!strcasecmp("Cyan", color))
  477. lfs->color = FOREGROUND_CYAN;
  478. else if (!strcasecmp("Magenta", color))
  479. lfs->color = FOREGROUND_MAGENTA;
  480. else if (!strcasecmp("WhiteBold", color))
  481. lfs->color = FOREGROUND_WHITE_BOLD;
  482. else if (!strcasecmp("GreenBold", color))
  483. lfs->color = FOREGROUND_GREEN_BOLD;
  484. else if (!strcasecmp("YellowBold", color))
  485. lfs->color = FOREGROUND_YELLOW_BOLD;
  486. else if (!strcasecmp("RedBold", color))
  487. lfs->color = FOREGROUND_RED_BOLD;
  488. else if (!strcasecmp("BlueBold", color))
  489. lfs->color = FOREGROUND_BLUE_BOLD;
  490. else if (!strcasecmp("CyanBold", color))
  491. lfs->color = FOREGROUND_CYAN_BOLD;
  492. else if (!strcasecmp("MagentaBold", color))
  493. lfs->color = FOREGROUND_MAGENTA_BOLD;
  494. else
  495. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Log setting 'Color' has invalid value '%s'", color);
  496. }
  497. // JA: something was wrong here, lfs->logfile or console always was true, even if bit was off. Will ask Scatman about it someday.
  498. lfs->logfile = (atoi(logs) & LOG_LOGFILE);
  499. lfs->console = (atoi(logs) & LOG_CONSOLE);
  500. lfs->client = (atoi(logs) & LOG_CLIENT);
  501. }
  502. }
  503. bool
  504. LogParseConfigs() {
  505. XMLNode main_node;
  506. int i;
  507. main_node = XMLNode::openFileHelper("log_config.xml", "EQ2EmuLogConfigs");
  508. if (main_node.isEmpty()) {
  509. LogWrite(MISC__WARNING, 0, "Misc", "Unable to parse the file 'log_config.xml' or it does not exist. Default values will be used");
  510. return false;
  511. }
  512. for (i = 0; i < main_node.nChildNode("LogConfig"); i++)
  513. ProcessLogConfig(main_node.getChildNode("LogConfig", i));
  514. return true;
  515. }