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