echodict/llama.cpp

1#include "common.h"2#include "log.h"3 4#include <chrono>5#include <condition_variable>6#include <cstdarg>7#include <cstdio>8#include <cstdlib>9#include <cstring>10#include <mutex>11#include <sstream>12#include <thread>13#include <vector>14 15#if defined(_WIN32)16#    include <io.h>17#    include <windows.h>18#    define isatty _isatty19#    define fileno _fileno20#else21#    include <unistd.h>22#endif // defined(_WIN32)23 24int common_log_verbosity_thold = LOG_DEFAULT_LLAMA;25 26int common_log_get_verbosity_thold(void) {27    return common_log_verbosity_thold;28}29 30void common_log_set_verbosity_thold(int verbosity) {31    common_log_verbosity_thold = verbosity;32}33 34static int64_t t_us() {35    return std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::system_clock::now().time_since_epoch()).count();36}37 38// colors39enum common_log_col : int {40    COMMON_LOG_COL_DEFAULT = 0,41    COMMON_LOG_COL_BOLD,42    COMMON_LOG_COL_RED,43    COMMON_LOG_COL_GREEN,44    COMMON_LOG_COL_YELLOW,45    COMMON_LOG_COL_BLUE,46    COMMON_LOG_COL_MAGENTA,47    COMMON_LOG_COL_CYAN,48    COMMON_LOG_COL_WHITE,49};50 51// disable colors by default52static std::vector<const char *> g_col = {53    "",54    "",55    "",56    "",57    "",58    "",59    "",60    "",61    "",62};63 64struct common_log_entry {65    enum ggml_log_level level;66 67    bool prefix;68 69    int64_t timestamp;70 71    std::vector<char> msg;72 73    // signals the worker thread to stop74    bool is_end;75 76    void print(FILE * file = nullptr) const {77        FILE * fcur = file;78        if (!fcur) {79            // stderr displays DBG messages only when their verbosity level is not higher than the threshold80            // these messages will still be logged to a file81            if (level == GGML_LOG_LEVEL_DEBUG && common_log_verbosity_thold < LOG_DEFAULT_DEBUG) {82                return;83            }84 85            fcur = stdout;86 87            if (level != GGML_LOG_LEVEL_NONE) {88                fcur = stderr;89            }90        }91 92        if (level != GGML_LOG_LEVEL_NONE && level != GGML_LOG_LEVEL_CONT && prefix) {93            if (timestamp) {94                // [M.s.ms.us]95                fprintf(fcur, "%s%d.%02d.%03d.%03d%s ",96                        g_col[COMMON_LOG_COL_BLUE],97                        (int) (timestamp / 1000000 / 60),98                        (int) (timestamp / 1000000 % 60),99                        (int) (timestamp / 1000 % 1000),100                        (int) (timestamp % 1000),101                        g_col[COMMON_LOG_COL_DEFAULT]);102            }103 104            switch (level) {105                case GGML_LOG_LEVEL_INFO:  fprintf(fcur, "%sI %s", g_col[COMMON_LOG_COL_GREEN],   g_col[COMMON_LOG_COL_DEFAULT]); break;106                case GGML_LOG_LEVEL_WARN:  fprintf(fcur, "%sW %s", g_col[COMMON_LOG_COL_MAGENTA], ""                        ); break;107                case GGML_LOG_LEVEL_ERROR: fprintf(fcur, "%sE %s", g_col[COMMON_LOG_COL_RED],     ""                        ); break;108                case GGML_LOG_LEVEL_DEBUG: fprintf(fcur, "%sD %s", g_col[COMMON_LOG_COL_YELLOW],  ""                        ); break;109                default:110                    break;111            }112        }113 114        fprintf(fcur, "%s", msg.data());115 116        if (level == GGML_LOG_LEVEL_WARN || level == GGML_LOG_LEVEL_ERROR || level == GGML_LOG_LEVEL_DEBUG) {117            fprintf(fcur, "%s", g_col[COMMON_LOG_COL_DEFAULT]);118        }119 120        fflush(fcur);121    }122};123 124struct common_log {125    // default capacity - will be expanded if needed126    common_log() : common_log(256) {}127 128    common_log(size_t capacity) {129        file = nullptr;130        prefix = false;131        timestamps = false;132        running = false;133        t_start = t_us();134 135        // initial message size - will be expanded if longer messages arrive136        entries.resize(capacity);137        for (auto & entry : entries) {138            entry.msg.resize(256);139        }140 141        head = 0;142        tail = 0;143 144        resume();145    }146 147    ~common_log() {148        pause();149        if (file) {150            fclose(file);151        }152    }153 154private:155    std::mutex mtx;156    std::thread thrd;157    std::condition_variable cv;158 159    FILE * file;160 161    bool prefix;162    bool timestamps;163    bool running;164 165    int64_t t_start;166 167    // ring buffer of entries168    std::vector<common_log_entry> entries;169    size_t head;170    size_t tail;171 172    // worker thread copies into this173    common_log_entry cur;174 175public:176    void add(enum ggml_log_level level, const char * fmt, va_list args) {177        std::lock_guard<std::mutex> lock(mtx);178 179        if (!running) {180            // discard messages while the worker thread is paused181            return;182        }183 184        auto & entry = entries[tail];185 186        {187            // cannot use args twice, so make a copy in case we need to expand the buffer188            va_list args_copy;189            va_copy(args_copy, args);190 191#if 1192            const size_t n = vsnprintf(entry.msg.data(), entry.msg.size(), fmt, args);193            if (n >= entry.msg.size()) {194                entry.msg.resize(n + 1);195                vsnprintf(entry.msg.data(), entry.msg.size(), fmt, args_copy);196            }197#else198            // hack for bolding arguments199 200            std::stringstream ss;201            for (int i = 0; fmt[i] != 0; i++) {202                if (fmt[i] == '%') {203                    ss << LOG_COL_BOLD;204                    while (fmt[i] != ' ' && fmt[i] != ')' && fmt[i] != ']' && fmt[i] != 0) ss << fmt[i++];205                    ss << LOG_COL_DEFAULT;206                    if (fmt[i] == 0) break;207                }208                ss << fmt[i];209            }210            const size_t n = vsnprintf(entry.msg.data(), entry.msg.size(), ss.str().c_str(), args);211            if (n >= entry.msg.size()) {212                entry.msg.resize(n + 1);213                vsnprintf(entry.msg.data(), entry.msg.size(), ss.str().c_str(), args_copy);214            }215#endif216            va_end(args_copy);217        }218 219        entry.level = level;220        entry.prefix = prefix;221        entry.timestamp = 0;222        if (timestamps) {223            entry.timestamp = t_us() - t_start;224        }225        entry.is_end = false;226 227        tail = (tail + 1) % entries.size();228        if (tail == head) {229            // expand the buffer230            std::vector<common_log_entry> new_entries(2*entries.size());231 232            size_t new_tail = 0;233 234            do {235                new_entries[new_tail] = std::move(entries[head]);236 237                head     = (head     + 1) % entries.size();238                new_tail = (new_tail + 1);239            } while (head != tail);240 241            head = 0;242            tail = new_tail;243 244            for (size_t i = tail; i < new_entries.size(); i++) {245                new_entries[i].msg.resize(256);246            }247 248            entries = std::move(new_entries);249        }250 251        cv.notify_one();252    }253 254    void resume() {255        std::lock_guard<std::mutex> lock(mtx);256 257        if (running) {258            return;259        }260 261        running = true;262 263        thrd = std::thread([this]() {264            while (true) {265                {266                    std::unique_lock<std::mutex> lock(mtx);267                    cv.wait(lock, [this]() { return head != tail; });268 269                    cur = entries[head];270 271                    head = (head + 1) % entries.size();272                }273 274                if (cur.is_end) {275                    break;276                }277 278                cur.print(); // stdout and stderr279 280                if (file) {281                    cur.print(file);282                }283            }284        });285    }286 287    void pause() {288        {289            std::lock_guard<std::mutex> lock(mtx);290 291            if (!running) {292                return;293            }294 295            running = false;296 297            // push an entry to signal the worker thread to stop298            {299                auto & entry = entries[tail];300                entry.is_end = true;301 302                tail = (tail + 1) % entries.size();303            }304 305            cv.notify_one();306        }307 308        thrd.join();309    }310 311    void set_file(const char * path) {312        pause();313 314        if (file) {315            fclose(file);316        }317 318        if (path) {319            file = fopen(path, "w");320        } else {321            file = nullptr;322        }323 324        resume();325    }326 327    void set_colors(bool colors) {328        pause();329 330        if (colors) {331            g_col[COMMON_LOG_COL_DEFAULT] = LOG_COL_DEFAULT;332            g_col[COMMON_LOG_COL_BOLD]    = LOG_COL_BOLD;333            g_col[COMMON_LOG_COL_RED]     = LOG_COL_RED;334            g_col[COMMON_LOG_COL_GREEN]   = LOG_COL_GREEN;335            g_col[COMMON_LOG_COL_YELLOW]  = LOG_COL_YELLOW;336            g_col[COMMON_LOG_COL_BLUE]    = LOG_COL_BLUE;337            g_col[COMMON_LOG_COL_MAGENTA] = LOG_COL_MAGENTA;338            g_col[COMMON_LOG_COL_CYAN]    = LOG_COL_CYAN;339            g_col[COMMON_LOG_COL_WHITE]   = LOG_COL_WHITE;340        } else {341            for (size_t i = 0; i < g_col.size(); i++) {342                g_col[i] = "";343            }344        }345 346        resume();347    }348 349    void set_prefix(bool prefix) {350        std::lock_guard<std::mutex> lock(mtx);351 352        this->prefix = prefix;353    }354 355    void set_timestamps(bool timestamps) {356        std::lock_guard<std::mutex> lock(mtx);357 358        this->timestamps = timestamps;359    }360};361 362//363// public API364//365 366struct common_log * common_log_init() {367    return new common_log;368}369 370struct common_log * common_log_main() {371    static struct common_log log;372    static std::once_flag    init_flag;373    std::call_once(init_flag, [&]() {374        // Set default to auto-detect colors375        log.set_colors(tty_can_use_colors());376    });377 378    return &log;379}380 381void common_log_pause(struct common_log * log) {382    log->pause();383}384 385void common_log_resume(struct common_log * log) {386    log->resume();387}388 389void common_log_free(struct common_log * log) {390    delete log;391}392 393void common_log_add(struct common_log * log, enum ggml_log_level level, const char * fmt, ...) {394    va_list args;395    va_start(args, fmt);396    log->add(level, fmt, args);397    va_end(args);398}399 400void common_log_set_file(struct common_log * log, const char * file) {401    log->set_file(file);402}403 404void common_log_set_colors(struct common_log * log, log_colors colors) {405    if (colors == LOG_COLORS_AUTO) {406        log->set_colors(tty_can_use_colors());407        return;408    }409 410    if (colors == LOG_COLORS_DISABLED) {411        log->set_colors(false);412        return;413    }414 415    GGML_ASSERT(colors == LOG_COLORS_ENABLED);416    log->set_colors(true);417}418 419void common_log_set_prefix(struct common_log * log, bool prefix) {420    log->set_prefix(prefix);421}422 423void common_log_set_timestamps(struct common_log * log, bool timestamps) {424    log->set_timestamps(timestamps);425}426 427void common_log_flush(struct common_log * log) {428    log->pause();429    log->resume();430}431 432static int common_get_verbosity(enum ggml_log_level level) {433    switch (level) {434        case GGML_LOG_LEVEL_DEBUG: return LOG_LEVEL_DEBUG;435        case GGML_LOG_LEVEL_INFO:  return LOG_LEVEL_INFO;436        case GGML_LOG_LEVEL_WARN:  return LOG_LEVEL_WARN;437        case GGML_LOG_LEVEL_ERROR: return LOG_LEVEL_ERROR;438        case GGML_LOG_LEVEL_CONT:  return LOG_LEVEL_INFO; // same as INFO439        case GGML_LOG_LEVEL_NONE:440        default:441            return LOG_LEVEL_OUTPUT;442    }443}444 445void common_log_default_callback(enum ggml_log_level level, const char * text, void * /*user_data*/) {446    auto verbosity = common_get_verbosity(level);447    if (verbosity <= common_log_verbosity_thold) {448        common_log_add(common_log_main(), level, "%s", text);449    }450}451