9
3

Log.cpp 16 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615
  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. //if we have no logs to write, we're done
  183. if ((logq = pending_head.next) == &pending_tail)
  184. {
  185. mlogqs.releasewritelock();
  186. return;
  187. }
  188. while (logq != &pending_tail) {
  189. if (log_type_info[logq->log_type].console) {
  190. SetConsoleColor(FOREGROUND_WHITE_BOLD);
  191. printf("%s ", logq->date);
  192. SetConsoleColor(log_type_info[logq->log_type].color);
  193. printf("%s ", log_type_info[logq->log_type].display_name);
  194. SetConsoleColor(FOREGROUND_WHITE_BOLD);
  195. printf("%-10s: ", logq->name);
  196. SetConsoleColor(log_type_info[logq->log_type].color);
  197. printf("%s\n", logq->text);
  198. SetConsoleColor(-1);
  199. fflush(stdout);
  200. }
  201. if (log_type_info[logq->log_type].logfile) {
  202. f = OpenLogFile();
  203. if (f != stderr || (f == stderr && !log_type_info[logq->log_type].console)) {
  204. fprintf(f, "%s %s %s: %s\n", logq->date, log_type_info[logq->log_type].display_name, logq->name, logq->text);
  205. fflush(f);
  206. if (f != stderr)
  207. fclose(f);
  208. }
  209. }
  210. #if defined WORLD
  211. if (log_type_info[logq->log_type].client) {
  212. // eventually output logging to the client who "subscribed" to the logger
  213. // in-game, they type:
  214. // /logsys add WORLD__DEBUG 5
  215. // to watch world debug loggers of level 5 or less
  216. }
  217. #endif
  218. tmp = logq;
  219. logq = logq->next;
  220. mlogqs.releasewritelock();
  221. free(tmp->text);
  222. free(tmp);
  223. }
  224. }
  225. ThreadReturnType LogLoop(void *args) {
  226. while (looping) {
  227. WriteQueuedLogs(LOGS_PER_CYCLE);
  228. Sleep(LOG_CYCLE);
  229. }
  230. THREAD_RETURN(NULL);
  231. }
  232. void LogStart() {
  233. if (start_called)
  234. return;
  235. //initialize the doubly linked list
  236. head.prev = NULL;
  237. head.next = &tail;
  238. tail.prev = &head;
  239. tail.next = NULL;
  240. mlogqs.SetName("logqueue");
  241. looping = true;
  242. #ifdef _WIN32
  243. _beginthread(LogLoop, 0, NULL);
  244. #else
  245. pthread_t thread;
  246. pthread_create(&thread, NULL, LogLoop, NULL);
  247. pthread_detach(thread);
  248. #endif
  249. start_called = true;
  250. }
  251. void LogStop() {
  252. looping = false;
  253. WriteQueuedLogs(-1);
  254. start_called = false;
  255. }
  256. static void LogQueueAdd(LogType log_type, char *text, int len, const char *cat_text = NULL) {
  257. logq_t *logq;
  258. struct tm *tm;
  259. time_t now;
  260. if ((logq = (logq_t *)calloc(1, sizeof(logq_t))) == NULL) {
  261. free(text);
  262. fprintf(stderr, "%s: %u: Unable to allocate %zu bytes\n", __FUNCTION__, __LINE__, sizeof(logq_t));
  263. return;
  264. }
  265. if ((logq->text = (char *)calloc(len + 1, sizeof(char))) == NULL) {
  266. free(text);
  267. free(logq);
  268. fprintf(stderr, "%s: %u: Unable to allocate %i bytes\n", __FUNCTION__, __LINE__, len + 1);
  269. return;
  270. }
  271. now = time(NULL);
  272. tm = localtime(&now);
  273. logq->log_type = log_type;
  274. snprintf(logq->date, DATE_MAX + 1, "%02i:%02i:%02i", tm->tm_hour, tm->tm_min, tm->tm_sec);
  275. strncpy(logq->name, cat_text == NULL || cat_text[0] == '\0' ? log_type_info[log_type].name : cat_text, LOG_NAME_MAX);
  276. strncpy(logq->text, text, len);
  277. free(text);
  278. if (!start_called)
  279. LogStart();
  280. //insert at the end
  281. mlogqs.writelock();
  282. tail.prev->next = logq;
  283. logq->prev = tail.prev;
  284. logq->next = &tail;
  285. tail.prev = logq;
  286. ++num_logqs;
  287. mlogqs.releasewritelock();
  288. }
  289. int8 GetLoggerLevel(LogType type)
  290. {
  291. return log_type_info[type].level;
  292. }
  293. // JA: horrific hack for Parser, since queued logging keeps crashing between parses.
  294. #ifndef PARSER
  295. void LogWrite(LogType type, int8 log_level, const char *cat_text, const char *fmt, ...) {
  296. int count, size = 64;
  297. char *buf;
  298. va_list ap;
  299. // if there is no formatting, or the logger is DISABLED
  300. // or the log_level param exceeds the minimum allowed value, abort logwrite
  301. if (!log_type_info[type].enabled || (log_level > 0 && log_type_info[type].level < log_level))
  302. return;
  303. while (true) {
  304. if ((buf = (char *)malloc(size)) == NULL) {
  305. fprintf(stderr, "%s: %i: Unable to allocate %i bytes\n", __FUNCTION__, __LINE__, size);
  306. return;
  307. }
  308. va_start(ap, fmt);
  309. count = vsnprintf(buf, size, fmt, ap);
  310. va_end(ap);
  311. if (count > -1 && count < size)
  312. break;
  313. free(buf);
  314. if (count > 1)
  315. size = count + 1;
  316. else
  317. size *= 2;
  318. }
  319. LogQueueAdd(type, buf, count, cat_text);
  320. }
  321. #else
  322. void LogWrite(LogType type, int8 log_level, const char *cat_text, const char *format, ...)
  323. {
  324. // if there is no formatting, or the logger is DISABLED
  325. // or the log_level param exceeds the minimum allowed value, abort logwrite
  326. if ( !format || !log_type_info[type].enabled || (log_level > 0 && log_type_info[type].level < log_level) )
  327. return;
  328. time_t clock;
  329. struct tm *tm;
  330. char buffer[LOG_BUFFER_SIZE], date[32];
  331. va_list args;
  332. FILE *f;
  333. size_t cat_text_len = 0;
  334. memset(buffer, 0, sizeof(buffer));
  335. memset(date, 0, sizeof(date));
  336. va_start(args, format);
  337. vsnprintf(buffer, sizeof(buffer) - 1, format, args);
  338. va_end(args);
  339. time(&clock);
  340. tm = localtime(&clock);
  341. snprintf(date, sizeof(date)-1, "%02d:%02d:%02d", tm->tm_hour, tm->tm_min, tm->tm_sec);
  342. // DateString(date, sizeof(date));
  343. cat_text_len = strlen(cat_text);
  344. //if( strlen(cat_text) == 0 ) // cat_text was blank
  345. // cat_text = (char*)log_type_info[type].name;
  346. /* write to the log file? */
  347. if (log_type_info[type].logfile)
  348. {
  349. char exename[200] = "";
  350. #ifdef LOGIN
  351. snprintf(exename, sizeof(exename), "login");
  352. #endif
  353. #ifdef WORLD
  354. snprintf(exename, sizeof(exename), "world");
  355. #endif
  356. #ifdef PARSER
  357. snprintf(exename, sizeof(exename), "parser");
  358. #endif
  359. #ifdef PATCHER
  360. snprintf(exename, sizeof(exename), "patcher");
  361. #endif
  362. char filename[200], log_header[200] = "";
  363. #ifndef NO_PIDLOG
  364. 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());
  365. #else
  366. snprintf(filename, sizeof(filename)-1, "logs/%04d-%02d-%02d_eq2%s.log", tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday, exename);
  367. #endif
  368. f=fopen(filename, "r");
  369. if( !f )
  370. snprintf(log_header, sizeof(log_header), "===[ New log '%s' started ]===\n\n", filename);
  371. else
  372. fclose (f);
  373. f = fopen(filename, "a");
  374. if (f) {
  375. if( strlen(log_header) > 0 )
  376. fprintf(f, "%s\n", log_header);
  377. fprintf(f, "%s %s %s: %s\n", date, log_type_info[type].display_name, cat_text, buffer);
  378. fclose(f);
  379. }
  380. }
  381. /* write to the console? */
  382. if (log_type_info[type].console)
  383. {
  384. #ifdef _WIN32
  385. 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);
  386. #else
  387. 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);
  388. #endif
  389. }
  390. }
  391. void
  392. ColorizeLog(int color, char *date, const char *display_name, const char *category, string buffer)
  393. {
  394. #ifdef _WIN32
  395. HANDLE console = GetStdHandle(STD_OUTPUT_HANDLE);
  396. if (console == INVALID_HANDLE_VALUE) {
  397. printf("%s %s %s: %s\n", date, display_name, category, buffer);
  398. return;
  399. }
  400. printf("%s ", date);
  401. SetConsoleTextAttribute(console, color);
  402. printf("%s ", display_name);
  403. SetConsoleTextAttribute(console, FOREGROUND_WHITE_BOLD);
  404. printf("%s: ", category);
  405. SetConsoleTextAttribute(console, color);
  406. printf("%s\n", buffer.c_str());
  407. SetConsoleTextAttribute(console, FOREGROUND_WHITE);
  408. #endif
  409. }
  410. #endif
  411. LogTypeStatus *
  412. GetLogTypeStatus(const char *category, const char *type) {
  413. char combined[256];
  414. int i;
  415. memset(combined, 0, sizeof(combined));
  416. snprintf(combined, sizeof(combined) - 1, "%s__%s", category, type);
  417. for (i = 0; i < NUMBER_OF_LOG_TYPES; i++) {
  418. if (strcasecmp(log_type_info[i].name, combined) == 0)
  419. return &log_type_info[i];
  420. }
  421. return &log_type_info[NUMBER_OF_LOG_TYPES];
  422. }
  423. void
  424. ProcessLogConfig(XMLNode node) {
  425. int i;
  426. const char *category, *type, *level, *color, *enabled, *logs;
  427. LogTypeStatus *lfs;
  428. XMLNode child;
  429. category = node.getAttribute("Category");
  430. if (!category) {
  431. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Config missing a Category");
  432. return;
  433. }
  434. for (i = 0; i < node.nChildNode("ConfigType"); i++) {
  435. child = node.getChildNode("ConfigType", i);
  436. type = child.getAttribute("Type");
  437. if (!type) {
  438. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Config missing a Type");
  439. continue;
  440. }
  441. lfs = GetLogTypeStatus(category, type);
  442. level = child.getAttribute("Level");
  443. enabled = child.getAttribute("Enabled");
  444. color = child.getAttribute("Color");
  445. logs = child.getAttribute("Logs");
  446. if (!logs) {
  447. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Config missing 'Logs' attribute to specify which log(s) to write to");
  448. continue;
  449. }
  450. if (!IsNumber(logs)) {
  451. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Attribute 'Logs' must be a number. See LogTypes.h for the valid types.");
  452. continue;
  453. }
  454. if (enabled) {
  455. if (!strcasecmp("true", enabled) || !strcasecmp("on", enabled))
  456. lfs->enabled = true;
  457. else if (!strcasecmp("false", enabled) || !strcasecmp("off", enabled))
  458. lfs->enabled = false;
  459. else
  460. 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);
  461. }
  462. if (IsNumber(level))
  463. lfs->level = atoi(level);
  464. else
  465. lfs->level = 0;
  466. if (color) {
  467. if (IsNumber(color))
  468. lfs->color = atoi(color);
  469. else if (!strcasecmp("White", color))
  470. lfs->color = FOREGROUND_WHITE;
  471. else if (!strcasecmp("Green", color))
  472. lfs->color = FOREGROUND_GREEN;
  473. else if (!strcasecmp("Yellow", color))
  474. lfs->color = FOREGROUND_YELLOW;
  475. else if (!strcasecmp("Red", color))
  476. lfs->color = FOREGROUND_RED;
  477. else if (!strcasecmp("Blue", color))
  478. lfs->color = FOREGROUND_BLUE;
  479. else if (!strcasecmp("Cyan", color))
  480. lfs->color = FOREGROUND_CYAN;
  481. else if (!strcasecmp("Magenta", color))
  482. lfs->color = FOREGROUND_MAGENTA;
  483. else if (!strcasecmp("WhiteBold", color))
  484. lfs->color = FOREGROUND_WHITE_BOLD;
  485. else if (!strcasecmp("GreenBold", color))
  486. lfs->color = FOREGROUND_GREEN_BOLD;
  487. else if (!strcasecmp("YellowBold", color))
  488. lfs->color = FOREGROUND_YELLOW_BOLD;
  489. else if (!strcasecmp("RedBold", color))
  490. lfs->color = FOREGROUND_RED_BOLD;
  491. else if (!strcasecmp("BlueBold", color))
  492. lfs->color = FOREGROUND_BLUE_BOLD;
  493. else if (!strcasecmp("CyanBold", color))
  494. lfs->color = FOREGROUND_CYAN_BOLD;
  495. else if (!strcasecmp("MagentaBold", color))
  496. lfs->color = FOREGROUND_MAGENTA_BOLD;
  497. else
  498. LogWrite(MISC__WARNING, 0, "Misc", "Error parsing log config. Log setting 'Color' has invalid value '%s'", color);
  499. }
  500. // JA: something was wrong here, lfs->logfile or console always was true, even if bit was off. Will ask Scatman about it someday.
  501. lfs->logfile = (atoi(logs) & LOG_LOGFILE);
  502. lfs->console = (atoi(logs) & LOG_CONSOLE);
  503. lfs->client = (atoi(logs) & LOG_CLIENT);
  504. }
  505. }
  506. bool
  507. LogParseConfigs() {
  508. XMLNode main_node;
  509. int i;
  510. main_node = XMLNode::openFileHelper("log_config.xml", "EQ2EmuLogConfigs");
  511. if (main_node.isEmpty()) {
  512. LogWrite(MISC__WARNING, 0, "Misc", "Unable to parse the file 'log_config.xml' or it does not exist. Default values will be used");
  513. return false;
  514. }
  515. for (i = 0; i < main_node.nChildNode("LogConfig"); i++)
  516. ProcessLogConfig(main_node.getChildNode("LogConfig", i));
  517. return true;
  518. }