KBaba7/llama.cpp

1#include "log.h"2 3#include <condition_variable>4#include <cstdarg>5#include <cstdio>6#include <mutex>7#include <sstream>8#include <thread>9#include <vector>10 11int common_log_verbosity_thold = LOG_DEFAULT_LLAMA;12 13void common_log_set_verbosity_thold(int verbosity) {14    common_log_verbosity_thold = verbosity;15}16 17static int64_t t_us() {18    return std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::system_clock::now().time_since_epoch()).count();19}20 21// colors22enum common_log_col : int {23    COMMON_LOG_COL_DEFAULT = 0,24    COMMON_LOG_COL_BOLD,25    COMMON_LOG_COL_RED,26    COMMON_LOG_COL_GREEN,27    COMMON_LOG_COL_YELLOW,28    COMMON_LOG_COL_BLUE,29    COMMON_LOG_COL_MAGENTA,30    COMMON_LOG_COL_CYAN,31    COMMON_LOG_COL_WHITE,32};33 34// disable colors by default35static std::vector<const char *> g_col = {36    "",37    "",38    "",39    "",40    "",41    "",42    "",43    "",44    "",45};46 47struct common_log_entry {48    enum ggml_log_level level;49 50    bool prefix;51 52    int64_t timestamp;53 54    std::vector<char> msg;55 56    // signals the worker thread to stop57    bool is_end;58 59    void print(FILE * file = nullptr) const {60        FILE * fcur = file;61        if (!fcur) {62            // stderr displays DBG messages only when their verbosity level is not higher than the threshold63            // these messages will still be logged to a file64            if (level == GGML_LOG_LEVEL_DEBUG && common_log_verbosity_thold < LOG_DEFAULT_DEBUG) {65                return;66            }67 68            fcur = stdout;69 70            if (level != GGML_LOG_LEVEL_NONE) {71                fcur = stderr;72            }73        }74 75        if (level != GGML_LOG_LEVEL_NONE && level != GGML_LOG_LEVEL_CONT && prefix) {76            if (timestamp) {77                // [M.s.ms.us]78                fprintf(fcur, "%s%d.%02d.%03d.%03d%s ",79                        g_col[COMMON_LOG_COL_BLUE],80                        (int) (timestamp / 1000000 / 60),81                        (int) (timestamp / 1000000 % 60),82                        (int) (timestamp / 1000 % 1000),83                        (int) (timestamp % 1000),84                        g_col[COMMON_LOG_COL_DEFAULT]);85            }86 87            switch (level) {88                case GGML_LOG_LEVEL_INFO:  fprintf(fcur, "%sI %s", g_col[COMMON_LOG_COL_GREEN],   g_col[COMMON_LOG_COL_DEFAULT]); break;89                case GGML_LOG_LEVEL_WARN:  fprintf(fcur, "%sW %s", g_col[COMMON_LOG_COL_MAGENTA], ""                        ); break;90                case GGML_LOG_LEVEL_ERROR: fprintf(fcur, "%sE %s", g_col[COMMON_LOG_COL_RED],     ""                        ); break;91                case GGML_LOG_LEVEL_DEBUG: fprintf(fcur, "%sD %s", g_col[COMMON_LOG_COL_YELLOW],  ""                        ); break;92                default:93                    break;94            }95        }96 97        fprintf(fcur, "%s", msg.data());98 99        if (level == GGML_LOG_LEVEL_WARN || level == GGML_LOG_LEVEL_ERROR || level == GGML_LOG_LEVEL_DEBUG) {100            fprintf(fcur, "%s", g_col[COMMON_LOG_COL_DEFAULT]);101        }102 103        fflush(fcur);104    }105};106 107struct common_log {108    // default capacity - will be expanded if needed109    common_log() : common_log(256) {}110 111    common_log(size_t capacity) {112        file = nullptr;113        prefix = false;114        timestamps = false;115        running = false;116        t_start = t_us();117 118        // initial message size - will be expanded if longer messages arrive119        entries.resize(capacity);120        for (auto & entry : entries) {121            entry.msg.resize(256);122        }123 124        head = 0;125        tail = 0;126 127        resume();128    }129 130    ~common_log() {131        pause();132        if (file) {133            fclose(file);134        }135    }136 137private:138    std::mutex mtx;139    std::thread thrd;140    std::condition_variable cv;141 142    FILE * file;143 144    bool prefix;145    bool timestamps;146    bool running;147 148    int64_t t_start;149 150    // ring buffer of entries151    std::vector<common_log_entry> entries;152    size_t head;153    size_t tail;154 155    // worker thread copies into this156    common_log_entry cur;157 158public:159    void add(enum ggml_log_level level, const char * fmt, va_list args) {160        std::lock_guard<std::mutex> lock(mtx);161 162        if (!running) {163            // discard messages while the worker thread is paused164            return;165        }166 167        auto & entry = entries[tail];168 169        {170            // cannot use args twice, so make a copy in case we need to expand the buffer171            va_list args_copy;172            va_copy(args_copy, args);173 174#if 1175            const size_t n = vsnprintf(entry.msg.data(), entry.msg.size(), fmt, args);176            if (n >= entry.msg.size()) {177                entry.msg.resize(n + 1);178                vsnprintf(entry.msg.data(), entry.msg.size(), fmt, args_copy);179            }180#else181            // hack for bolding arguments182 183            std::stringstream ss;184            for (int i = 0; fmt[i] != 0; i++) {185                if (fmt[i] == '%') {186                    ss << LOG_COL_BOLD;187                    while (fmt[i] != ' ' && fmt[i] != ')' && fmt[i] != ']' && fmt[i] != 0) ss << fmt[i++];188                    ss << LOG_COL_DEFAULT;189                    if (fmt[i] == 0) break;190                }191                ss << fmt[i];192            }193            const size_t n = vsnprintf(entry.msg.data(), entry.msg.size(), ss.str().c_str(), args);194            if (n >= entry.msg.size()) {195                entry.msg.resize(n + 1);196                vsnprintf(entry.msg.data(), entry.msg.size(), ss.str().c_str(), args_copy);197            }198#endif199            va_end(args_copy);200        }201 202        entry.level = level;203        entry.prefix = prefix;204        entry.timestamp = 0;205        if (timestamps) {206            entry.timestamp = t_us() - t_start;207        }208        entry.is_end = false;209 210        tail = (tail + 1) % entries.size();211        if (tail == head) {212            // expand the buffer213            std::vector<common_log_entry> new_entries(2*entries.size());214 215            size_t new_tail = 0;216 217            do {218                new_entries[new_tail] = std::move(entries[head]);219 220                head     = (head     + 1) % entries.size();221                new_tail = (new_tail + 1);222            } while (head != tail);223 224            head = 0;225            tail = new_tail;226 227            for (size_t i = tail; i < new_entries.size(); i++) {228                new_entries[i].msg.resize(256);229            }230 231            entries = std::move(new_entries);232        }233 234        cv.notify_one();235    }236 237    void resume() {238        std::lock_guard<std::mutex> lock(mtx);239 240        if (running) {241            return;242        }243 244        running = true;245 246        thrd = std::thread([this]() {247            while (true) {248                {249                    std::unique_lock<std::mutex> lock(mtx);250                    cv.wait(lock, [this]() { return head != tail; });251 252                    cur = entries[head];253 254                    head = (head + 1) % entries.size();255                }256 257                if (cur.is_end) {258                    break;259                }260 261                cur.print(); // stdout and stderr262 263                if (file) {264                    cur.print(file);265                }266            }267        });268    }269 270    void pause() {271        {272            std::lock_guard<std::mutex> lock(mtx);273 274            if (!running) {275                return;276            }277 278            running = false;279 280            // push an entry to signal the worker thread to stop281            {282                auto & entry = entries[tail];283                entry.is_end = true;284 285                tail = (tail + 1) % entries.size();286            }287 288            cv.notify_one();289        }290 291        thrd.join();292    }293 294    void set_file(const char * path) {295        pause();296 297        if (file) {298            fclose(file);299        }300 301        if (path) {302            file = fopen(path, "w");303        } else {304            file = nullptr;305        }306 307        resume();308    }309 310    void set_colors(bool colors) {311        pause();312 313        if (colors) {314            g_col[COMMON_LOG_COL_DEFAULT] = LOG_COL_DEFAULT;315            g_col[COMMON_LOG_COL_BOLD]    = LOG_COL_BOLD;316            g_col[COMMON_LOG_COL_RED]     = LOG_COL_RED;317            g_col[COMMON_LOG_COL_GREEN]   = LOG_COL_GREEN;318            g_col[COMMON_LOG_COL_YELLOW]  = LOG_COL_YELLOW;319            g_col[COMMON_LOG_COL_BLUE]    = LOG_COL_BLUE;320            g_col[COMMON_LOG_COL_MAGENTA] = LOG_COL_MAGENTA;321            g_col[COMMON_LOG_COL_CYAN]    = LOG_COL_CYAN;322            g_col[COMMON_LOG_COL_WHITE]   = LOG_COL_WHITE;323        } else {324            for (size_t i = 0; i < g_col.size(); i++) {325                g_col[i] = "";326            }327        }328 329        resume();330    }331 332    void set_prefix(bool prefix) {333        std::lock_guard<std::mutex> lock(mtx);334 335        this->prefix = prefix;336    }337 338    void set_timestamps(bool timestamps) {339        std::lock_guard<std::mutex> lock(mtx);340 341        this->timestamps = timestamps;342    }343};344 345//346// public API347//348 349struct common_log * common_log_init() {350    return new common_log;351}352 353struct common_log * common_log_main() {354    static struct common_log log;355 356    return &log;357}358 359void common_log_pause(struct common_log * log) {360    log->pause();361}362 363void common_log_resume(struct common_log * log) {364    log->resume();365}366 367void common_log_free(struct common_log * log) {368    delete log;369}370 371void common_log_add(struct common_log * log, enum ggml_log_level level, const char * fmt, ...) {372    va_list args;373    va_start(args, fmt);374    log->add(level, fmt, args);375    va_end(args);376}377 378void common_log_set_file(struct common_log * log, const char * file) {379    log->set_file(file);380}381 382void common_log_set_colors(struct common_log * log, bool colors) {383    log->set_colors(colors);384}385 386void common_log_set_prefix(struct common_log * log, bool prefix) {387    log->set_prefix(prefix);388}389 390void common_log_set_timestamps(struct common_log * log, bool timestamps) {391    log->set_timestamps(timestamps);392}393