Felipe97/llama-cpp-compiled
01.1k
1#include "common.h"2#include "log.h"3#include "json.h"4 5#include <chrono>6#include <condition_variable>7#include <cstdarg>8#include <cstdio>9#include <cstdlib>10#include <cstring>11#include <mutex>12#include <sstream>13#include <thread>14#include <vector>15#include <algorithm>16 17#if defined(_WIN32)18# define WIN32_LEAN_AND_MEAN19# ifndef NOMINMAX20# define NOMINMAX21# endif22# include <io.h>23# include <windows.h>24# define isatty _isatty25# define fileno _fileno26#else27# include <unistd.h>28#endif // defined(_WIN32)29 30int common_log_verbosity_thold = LOG_DEFAULT_LLAMA;31 32int common_log_get_verbosity_thold(void) {33 return common_log_verbosity_thold;34}35 36void common_log_set_verbosity_thold(int verbosity) {37 common_log_verbosity_thold = verbosity;38}39 40static bool common_log_jsonl = false;41 42bool common_log_get_jsonl(void) {43 return common_log_jsonl;44}45 46void common_log_set_jsonl(bool jsonl) {47 common_log_jsonl = jsonl;48}49 50static int64_t t_us() {51 return std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::system_clock::now().time_since_epoch()).count();52}53 54// colors55enum common_log_col : int {56 COMMON_LOG_COL_DEFAULT = 0,57 COMMON_LOG_COL_BOLD,58 COMMON_LOG_COL_RED,59 COMMON_LOG_COL_GREEN,60 COMMON_LOG_COL_YELLOW,61 COMMON_LOG_COL_BLUE,62 COMMON_LOG_COL_MAGENTA,63 COMMON_LOG_COL_CYAN,64 COMMON_LOG_COL_WHITE,65};66 67// disable colors by default68static const char* g_col[] = {69 "",70 "",71 "",72 "",73 "",74 "",75 "",76 "",77 "",78};79 80static const char * level_str(enum ggml_log_level level) {81 switch (level) {82 case GGML_LOG_LEVEL_DEBUG: return "debug";83 case GGML_LOG_LEVEL_INFO: return "info";84 case GGML_LOG_LEVEL_WARN: return "warn";85 case GGML_LOG_LEVEL_ERROR: return "error";86 case GGML_LOG_LEVEL_CONT: return "cont";87 default: return "none";88 }89}90 91struct common_log_entry {92 enum ggml_log_level level {GGML_LOG_LEVEL_INFO};93 94 std::vector<char> msg;95 96 int64_t timestamp { 0 };97 bool is_end { false }; // signals the worker thread to stop98 bool prefix { false };99 bool jsonl { false };100 bool is_json { false }; // msg already holds a serialized JSON object101 102 common_log_entry(size_t size = 256) : msg(size) { }103 104 void print(FILE * file = nullptr) const {105 FILE * fcur = file;106 if (!fcur) {107 // stderr displays DBG messages only when their verbosity level is not higher than the threshold108 // these messages will still be logged to a file109 if (level == GGML_LOG_LEVEL_DEBUG && common_log_verbosity_thold < LOG_DEFAULT_DEBUG) {110 return;111 }112 113 fcur = stdout;114 115 if (level != GGML_LOG_LEVEL_NONE && !jsonl) {116 fcur = stderr;117 }118 }119 120 if (jsonl) {121 if (is_json) {122 fprintf(fcur, "%s\n", msg.data());123 fflush(fcur);124 return;125 }126 127 common_json obj = {128 {"type", "log"},129 {"time", timestamp},130 {"level", level_str(level)},131 {"msg", msg.data()},132 };133 fprintf(fcur, "%s\n", obj.dump_safe().c_str());134 fflush(fcur);135 return;136 }137 138 if (level != GGML_LOG_LEVEL_NONE && level != GGML_LOG_LEVEL_CONT && prefix) {139 if (timestamp) {140 // [M.s.ms.us]141 fprintf(fcur, "%s%d.%02d.%03d.%03d%s ",142 g_col[COMMON_LOG_COL_BLUE],143 (int) (timestamp / 1000000 / 60),144 (int) (timestamp / 1000000 % 60),145 (int) (timestamp / 1000 % 1000),146 (int) (timestamp % 1000),147 g_col[COMMON_LOG_COL_DEFAULT]);148 }149 150 switch (level) {151 case GGML_LOG_LEVEL_INFO: fprintf(fcur, "%sI %s", g_col[COMMON_LOG_COL_GREEN], g_col[COMMON_LOG_COL_DEFAULT]); break;152 case GGML_LOG_LEVEL_WARN: fprintf(fcur, "%sW %s", g_col[COMMON_LOG_COL_MAGENTA], "" ); break;153 case GGML_LOG_LEVEL_ERROR: fprintf(fcur, "%sE %s", g_col[COMMON_LOG_COL_RED], "" ); break;154 case GGML_LOG_LEVEL_DEBUG: fprintf(fcur, "%sD %s", g_col[COMMON_LOG_COL_YELLOW], "" ); break;155 default:156 break;157 }158 }159 160 fprintf(fcur, "%s", msg.data());161 162 if (level == GGML_LOG_LEVEL_WARN || level == GGML_LOG_LEVEL_ERROR || level == GGML_LOG_LEVEL_DEBUG) {163 fprintf(fcur, "%s", g_col[COMMON_LOG_COL_DEFAULT]);164 }165 166 fflush(fcur);167 }168};169 170struct common_log {171 // default capacity172 common_log(size_t capacity = 512) {173 file = nullptr;174 prefix = false;175 timestamps = false;176 running = false;177 t_start = t_us();178 179 queue.resize(capacity, common_log_entry(256));180 head = 0;181 tail = 0;182 183 resume();184 }185 186 ~common_log() {187 pause();188 if (file) {189 fclose(file);190 }191 }192 193private:194 std::mutex mtx;195 std::thread thrd;196 std::condition_variable cv_new; // new entry197 std::condition_variable cv_full; // wait on full198 199 FILE * file;200 201 bool prefix;202 bool timestamps;203 bool running;204 205 int64_t t_start;206 207 // queue of entries208 std::vector<common_log_entry> queue;209 size_t head;210 size_t tail;211 212 bool print_entry(const common_log_entry & e) const {213 if (e.is_end) return true;214 215 e.print();216 if (file) {217 e.print(file);218 }219 return false;220 }221 222 bool flush_queue(size_t start_head, size_t end_tail, size_t & out_head) const {223 bool stop = false;224 size_t h = start_head;225 while (h != end_tail && !stop) {226 stop = print_entry(queue[h]);227 h = (h + 1) % queue.size();228 }229 out_head = h;230 return stop;231 }232 233public:234 bool is_full() const {235 return ((tail + 1) % queue.size()) == head;236 }237 238 bool is_empty() const {239 return head == tail;240 }241 242 void add(enum ggml_log_level level, const char * fmt, va_list args) {243 std::unique_lock<std::mutex> lock(mtx);244 245 // block if the queue is full246 cv_full.wait(lock, [this]() { return !running || !is_full(); });247 248 if (!running) {249 // discard messages while the worker thread is paused250 return;251 }252 253 auto & entry = queue[tail];254 255 {256 // cannot use args twice, so make a copy in case we need to expand the buffer257 va_list args_copy;258 va_copy(args_copy, args);259 260#if 1261 const size_t n = vsnprintf(entry.msg.data(), entry.msg.size(), fmt, args);262 if (n >= entry.msg.size()) {263 entry.msg.resize(n + 1);264 vsnprintf(entry.msg.data(), entry.msg.size(), fmt, args_copy);265 }266#else267 // hack for bolding arguments268 269 std::stringstream ss;270 for (int i = 0; fmt[i] != 0; i++) {271 if (fmt[i] == '%') {272 ss << LOG_COL_BOLD;273 while (fmt[i] != ' ' && fmt[i] != ')' && fmt[i] != ']' && fmt[i] != 0) ss << fmt[i++];274 ss << LOG_COL_DEFAULT;275 if (fmt[i] == 0) break;276 }277 ss << fmt[i];278 }279 const size_t n = vsnprintf(entry.msg.data(), entry.msg.size(), ss.str().c_str(), args);280 if (n >= entry.msg.size()) {281 entry.msg.resize(n + 1);282 vsnprintf(entry.msg.data(), entry.msg.size(), ss.str().c_str(), args_copy);283 }284#endif285 va_end(args_copy);286 }287 288 entry.is_end = false;289 entry.level = level;290 entry.prefix = prefix;291 entry.jsonl = common_log_jsonl;292 entry.is_json = false;293 entry.timestamp = 0;294 if (timestamps) {295 entry.timestamp = t_us() - t_start;296 }297 298 tail = (tail + 1) % queue.size();299 cv_new.notify_one();300 }301 302 void add_json(const char * type, const common_json & obj) {303 const common_json full = {304 {"type", type},305 {"data", obj},306 };307 308 const std::string text = full.dump_safe();309 310 std::unique_lock<std::mutex> lock(mtx);311 312 // block if the queue is full313 cv_full.wait(lock, [this]() { return !running || !is_full(); });314 315 if (!running) {316 // discard messages while the worker thread is paused317 return;318 }319 320 auto & entry = queue[tail];321 322 if (entry.msg.size() < text.size() + 1) {323 entry.msg.resize(text.size() + 1);324 }325 memcpy(entry.msg.data(), text.c_str(), text.size() + 1);326 327 entry.is_end = false;328 entry.level = GGML_LOG_LEVEL_NONE;329 entry.prefix = false;330 entry.jsonl = true;331 entry.is_json = true;332 entry.timestamp = 0;333 334 tail = (tail + 1) % queue.size();335 cv_new.notify_one();336 }337 338 void resume() {339 std::lock_guard<std::mutex> lock(mtx);340 341 if (running) {342 return;343 }344 345 running = true;346 347 thrd = std::thread([this]() {348 while (true) {349 std::unique_lock<std::mutex> lock(mtx);350 cv_new.wait(lock, [this]() { return !is_empty(); });351 352 size_t cached_head = head;353 size_t cached_tail = tail;354 355 lock.unlock(); // drop the lock during flush356 357 size_t next_head;358 bool stop = flush_queue(cached_head, cached_tail, next_head);359 360 lock.lock();361 head = next_head;362 cv_full.notify_all();363 364 if (stop) {365 break;366 }367 }368 });369 }370 371 void pause() {372 {373 std::lock_guard<std::mutex> lock(mtx);374 375 if (!running) {376 return;377 }378 379 running = false;380 381 // push an entry to signal the worker thread to stop382 auto & entry = queue[tail];383 entry.is_end = true;384 tail = (tail + 1) % queue.size();385 386 // wakeup everyone387 cv_new.notify_one();388 cv_full.notify_all();389 }390 391 thrd.join();392 }393 394 void set_file(const char * path) {395 pause();396 397 if (file) {398 fclose(file);399 }400 401 if (path) {402 file = fopen(path, "w");403 } else {404 file = nullptr;405 }406 407 resume();408 }409 410 void set_colors(bool colors) {411 pause();412 413 if (colors) {414 g_col[COMMON_LOG_COL_DEFAULT] = LOG_COL_DEFAULT;415 g_col[COMMON_LOG_COL_BOLD] = LOG_COL_BOLD;416 g_col[COMMON_LOG_COL_RED] = LOG_COL_RED;417 g_col[COMMON_LOG_COL_GREEN] = LOG_COL_GREEN;418 g_col[COMMON_LOG_COL_YELLOW] = LOG_COL_YELLOW;419 g_col[COMMON_LOG_COL_BLUE] = LOG_COL_BLUE;420 g_col[COMMON_LOG_COL_MAGENTA] = LOG_COL_MAGENTA;421 g_col[COMMON_LOG_COL_CYAN] = LOG_COL_CYAN;422 g_col[COMMON_LOG_COL_WHITE] = LOG_COL_WHITE;423 } else {424 for (size_t i = 0; i < std::size(g_col); i++) {425 g_col[i] = "";426 }427 }428 429 resume();430 }431 432 void set_prefix(bool prefix) {433 std::lock_guard<std::mutex> lock(mtx);434 435 this->prefix = prefix;436 }437 438 void set_timestamps(bool timestamps) {439 std::lock_guard<std::mutex> lock(mtx);440 441 this->timestamps = timestamps;442 }443};444 445//446// public API447//448 449struct common_log * common_log_init() {450 return new common_log;451}452 453struct common_log * common_log_main() {454 // We intentionally leak (i.e. do not delete) the logger singleton because455 // common_log destructor called at DLL teardown phase will cause hanging on Windows.456 // OS will release resources anyway so it should not be a significant issue,457 // though this design may cause logs to be lost if not flushed before the program exits.458 // Refer to https://github.com/ggml-org/llama.cpp/issues/22142 for details.459 static struct common_log * log;460 static std::once_flag init_flag;461 std::call_once(init_flag, [&]() {462 log = new common_log;463 // Set default to auto-detect colors464 log->set_colors(tty_can_use_colors());465 });466 467 return log;468}469 470void common_log_pause(struct common_log * log) {471 log->pause();472}473 474void common_log_resume(struct common_log * log) {475 log->resume();476}477 478void common_log_free(struct common_log * log) {479 delete log;480}481 482void common_log_add(struct common_log * log, enum ggml_log_level level, const char * fmt, ...) {483 va_list args;484 va_start(args, fmt);485 log->add(level, fmt, args);486 va_end(args);487}488 489void common_log_add_json(struct common_log * log, const char * type, const common_json & obj) {490 if (!common_log_jsonl) {491 return;492 }493 494 log->add_json(type, obj);495}496 497void common_log_set_file(struct common_log * log, const char * file) {498 log->set_file(file);499}500 501void common_log_set_colors(struct common_log * log, log_colors colors) {502 if (colors == LOG_COLORS_AUTO) {503 log->set_colors(tty_can_use_colors());504 return;505 }506 507 if (colors == LOG_COLORS_DISABLED) {508 log->set_colors(false);509 return;510 }511 512 GGML_ASSERT(colors == LOG_COLORS_ENABLED);513 log->set_colors(true);514}515 516void common_log_set_prefix(struct common_log * log, bool prefix) {517 log->set_prefix(prefix);518}519 520void common_log_set_timestamps(struct common_log * log, bool timestamps) {521 log->set_timestamps(timestamps);522}523 524void common_log_flush(struct common_log * log) {525 log->pause();526 log->resume();527}528 529int common_log_get_verbosity(enum ggml_log_level level) {530 switch (level) {531 case GGML_LOG_LEVEL_DEBUG: return LOG_LEVEL_DEBUG;532 case GGML_LOG_LEVEL_INFO: return LOG_LEVEL_TRACE;533 case GGML_LOG_LEVEL_WARN: return LOG_LEVEL_WARN;534 case GGML_LOG_LEVEL_ERROR: return LOG_LEVEL_ERROR;535 case GGML_LOG_LEVEL_CONT: return LOG_LEVEL_TRACE;536 case GGML_LOG_LEVEL_NONE:537 default:538 return LOG_LEVEL_OUTPUT;539 }540}541 542void common_log_default_callback(enum ggml_log_level level, const char * text, void * /*user_data*/) {543 auto verbosity = common_log_get_verbosity(level);544 if (verbosity <= common_log_verbosity_thold) {545 common_log_add(common_log_main(), level, "%s", text);546 }547}548