log : add CONT level for continuing previous log entry (ggml-org#9610)

ggerganov · dsx1986 · commit cc79499b22d2 · 2024-10-29T10:30:38.000-07:00
diff --git a/common/log.cpp b/common/log.cpp
@@ -82,7 +82,7 @@ struct gpt_log_entry {
             }
         }
 
-        if (level != GGML_LOG_LEVEL_NONE && prefix) {
+        if (level != GGML_LOG_LEVEL_NONE && level != GGML_LOG_LEVEL_CONT && prefix) {
             if (timestamp) {
                 // [M.s.ms.us]
                 fprintf(fcur, "%s%d.%02d.%03d.%03d%s ",
diff --git a/common/log.h b/common/log.h
@@ -83,8 +83,10 @@ void gpt_log_set_timestamps(struct gpt_log * log,       bool   timestamps); // w
 #define LOG_WRN(...) LOG_TMPL(GGML_LOG_LEVEL_WARN,  0,                 __VA_ARGS__)
 #define LOG_ERR(...) LOG_TMPL(GGML_LOG_LEVEL_ERROR, 0,                 __VA_ARGS__)
 #define LOG_DBG(...) LOG_TMPL(GGML_LOG_LEVEL_DEBUG, LOG_DEFAULT_DEBUG, __VA_ARGS__)
+#define LOG_CNT(...) LOG_TMPL(GGML_LOG_LEVEL_CONT,  0,                 __VA_ARGS__)
 
 #define LOG_INFV(verbosity, ...) LOG_TMPL(GGML_LOG_LEVEL_INFO,  verbosity, __VA_ARGS__)
 #define LOG_WRNV(verbosity, ...) LOG_TMPL(GGML_LOG_LEVEL_WARN,  verbosity, __VA_ARGS__)
 #define LOG_ERRV(verbosity, ...) LOG_TMPL(GGML_LOG_LEVEL_ERROR, verbosity, __VA_ARGS__)
 #define LOG_DBGV(verbosity, ...) LOG_TMPL(GGML_LOG_LEVEL_DEBUG, verbosity, __VA_ARGS__)
+#define LOG_CNTV(verbosity, ...) LOG_TMPL(GGML_LOG_LEVEL_CONT,  verbosity, __VA_ARGS__)
diff --git a/examples/infill/infill.cpp b/examples/infill/infill.cpp
@@ -263,9 +263,9 @@ int main(int argc, char ** argv) {
         if (params.n_keep > 0) {
         LOG_INF("%s: static prompt based on n_keep: '", __func__);
             for (int i = 0; i < params.n_keep; i++) {
-                LOG("%s", llama_token_to_piece(ctx, embd_inp[i]).c_str());
+                LOG_CNT("%s", llama_token_to_piece(ctx, embd_inp[i]).c_str());
             }
-            LOG("'\n");
+            LOG_CNT("'\n");
         }
         LOG_INF("\n");
     }
@@ -306,8 +306,8 @@ int main(int argc, char ** argv) {
 
     LOG_INF("generate: n_ctx = %d, n_batch = %d, n_predict = %d, n_keep = %d\n", n_ctx, params.n_batch, params.n_predict, params.n_keep);
 
-    LOG("\n");
-    LOG("\n#####  Infill mode  #####\n\n");
+    LOG_INF("\n");
+    LOG_INF("\n#####  Infill mode  #####\n\n");
     if (params.interactive) {
         const char *control_message;
         if (params.multiline_input) {
@@ -318,11 +318,11 @@ int main(int argc, char ** argv) {
                               " - To return control without starting a new line, end your input with '/'.\n"
                               " - If you want to submit another line, end your input with '\\'.\n";
         }
-        LOG("== Running in interactive mode. ==\n");
+        LOG_INF("== Running in interactive mode. ==\n");
 #if defined (__unix__) || (defined (__APPLE__) && defined (__MACH__)) || defined (_WIN32)
-        LOG(       " - Press Ctrl+C to interject at any time.\n");
+        LOG_INF(       " - Press Ctrl+C to interject at any time.\n");
 #endif
-        LOG(       "%s\n", control_message);
+        LOG_INF(       "%s\n", control_message);
 
         is_interacting = params.interactive_first;
     }
diff --git a/examples/main/main.cpp b/examples/main/main.cpp
@@ -385,9 +385,9 @@ int main(int argc, char ** argv) {
         if (params.n_keep > add_bos) {
             LOG_INF("%s: static prompt based on n_keep: '", __func__);
             for (int i = 0; i < params.n_keep; i++) {
-                LOG("%s", llama_token_to_piece(ctx, embd_inp[i]).c_str());
+                LOG_CNT("%s", llama_token_to_piece(ctx, embd_inp[i]).c_str());
             }
-            LOG("'\n");
+            LOG_CNT("'\n");
         }
         LOG_INF("\n");
     }
@@ -409,40 +409,40 @@ int main(int argc, char ** argv) {
     }
 
     if (params.interactive) {
-        LOG("%s: interactive mode on.\n", __func__);
+        LOG_INF("%s: interactive mode on.\n", __func__);
 
         if (!params.antiprompt.empty()) {
             for (const auto & antiprompt : params.antiprompt) {
-                LOG("Reverse prompt: '%s'\n", antiprompt.c_str());
+                LOG_INF("Reverse prompt: '%s'\n", antiprompt.c_str());
                 if (params.verbose_prompt) {
                     auto tmp = ::llama_tokenize(ctx, antiprompt, false, true);
                     for (int i = 0; i < (int) tmp.size(); i++) {
-                        LOG("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());
+                        LOG_INF("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());
                     }
                 }
             }
         }
 
         if (params.input_prefix_bos) {
-            LOG("Input prefix with BOS\n");
+            LOG_INF("Input prefix with BOS\n");
         }
 
         if (!params.input_prefix.empty()) {
-            LOG("Input prefix: '%s'\n", params.input_prefix.c_str());
+            LOG_INF("Input prefix: '%s'\n", params.input_prefix.c_str());
             if (params.verbose_prompt) {
                 auto tmp = ::llama_tokenize(ctx, params.input_prefix, true, true);
                 for (int i = 0; i < (int) tmp.size(); i++) {
-                    LOG("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());
+                    LOG_INF("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());
                 }
             }
         }
 
         if (!params.input_suffix.empty()) {
-            LOG("Input suffix: '%s'\n", params.input_suffix.c_str());
+            LOG_INF("Input suffix: '%s'\n", params.input_suffix.c_str());
             if (params.verbose_prompt) {
                 auto tmp = ::llama_tokenize(ctx, params.input_suffix, false, true);
                 for (int i = 0; i < (int) tmp.size(); i++) {
-                    LOG("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());
+                    LOG_INF("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());
                 }
             }
         }
@@ -474,7 +474,7 @@ int main(int argc, char ** argv) {
       //GGML_ASSERT(n_ctx >= n_ctx_train * ga_n && "n_ctx must be at least n_ctx_train * grp_attn_n"); // NOLINT
         LOG_INF("self-extend: n_ctx_train = %d, grp_attn_n = %d, grp_attn_w = %d\n", n_ctx_train, ga_n, ga_w);
     }
-    LOG("\n");
+    LOG_INF("\n");
 
     if (params.interactive) {
         const char * control_message;
@@ -486,11 +486,11 @@ int main(int argc, char ** argv) {
                               " - To return control without starting a new line, end your input with '/'.\n"
                               " - If you want to submit another line, end your input with '\\'.\n";
         }
-        LOG("== Running in interactive mode. ==\n");
+        LOG_INF("== Running in interactive mode. ==\n");
 #if defined (__unix__) || (defined (__APPLE__) && defined (__MACH__)) || defined (_WIN32)
-        LOG(       " - Press Ctrl+C to interject at any time.\n");
+        LOG_INF(       " - Press Ctrl+C to interject at any time.\n");
 #endif
-        LOG(       "%s\n", control_message);
+        LOG_INF(       "%s\n", control_message);
 
         is_interacting = params.interactive_first;
     }
diff --git a/ggml/include/ggml.h b/ggml/include/ggml.h
@@ -570,6 +570,7 @@ extern "C" {
         GGML_LOG_LEVEL_WARN  = 2,
         GGML_LOG_LEVEL_ERROR = 3,
         GGML_LOG_LEVEL_DEBUG = 4,
+        GGML_LOG_LEVEL_CONT  = 5, // continue previous log
     };
 
     // this tensor...
diff --git a/src/llama-impl.h b/src/llama-impl.h
@@ -28,6 +28,8 @@ void llama_log_callback_default(ggml_log_level level, const char * text, void *
 #define LLAMA_LOG_INFO(...)  llama_log_internal(GGML_LOG_LEVEL_INFO , __VA_ARGS__)
 #define LLAMA_LOG_WARN(...)  llama_log_internal(GGML_LOG_LEVEL_WARN , __VA_ARGS__)
 #define LLAMA_LOG_ERROR(...) llama_log_internal(GGML_LOG_LEVEL_ERROR, __VA_ARGS__)
+#define LLAMA_LOG_DEBUG(...) llama_log_internal(GGML_LOG_LEVEL_DEBUG, __VA_ARGS__)
+#define LLAMA_LOG_CONT(...)  llama_log_internal(GGML_LOG_LEVEL_CONT , __VA_ARGS__)
 
 //
 // helpers
diff --git a/src/llama.cpp b/src/llama.cpp
@@ -18671,9 +18671,9 @@ struct llama_model * llama_load_model_from_file(
             unsigned percentage = (unsigned) (100 * progress);
             while (percentage > *cur_percentage_p) {
                 *cur_percentage_p = percentage;
-                LLAMA_LOG(".");
+                LLAMA_LOG_CONT(".");
                 if (percentage >= 100) {
-                    LLAMA_LOG("\n");
+                    LLAMA_LOG_CONT("\n");
                 }
             }
             return true;

Original file line number	Diff line number	Diff line change
`@@ -82,7 +82,7 @@ struct gpt_log_entry {`
`82`	`82`	`}`
`83`	`83`	`}`
`84`	`84`
`85`		`- if (level != GGML_LOG_LEVEL_NONE && prefix) {`
	`85`	`+ if (level != GGML_LOG_LEVEL_NONE && level != GGML_LOG_LEVEL_CONT && prefix) {`
`86`	`86`	`if (timestamp) {`
`87`	`87`	`// [M.s.ms.us]`
`88`	`88`	`fprintf(fcur, "%s%d.%02d.%03d.%03d%s ",`
Original file line number	Diff line number	Diff line change
`@@ -385,9 +385,9 @@ int main(int argc, char ** argv) {`
`385`	`385`	`if (params.n_keep > add_bos) {`
`386`	`386`	`LOG_INF("%s: static prompt based on n_keep: '", __func__);`
`387`	`387`	`for (int i = 0; i < params.n_keep; i++) {`
`388`		`- LOG("%s", llama_token_to_piece(ctx, embd_inp[i]).c_str());`
	`388`	`+ LOG_CNT("%s", llama_token_to_piece(ctx, embd_inp[i]).c_str());`
`389`	`389`	`}`
`390`		`- LOG("'\n");`
	`390`	`+ LOG_CNT("'\n");`
`391`	`391`	`}`
`392`	`392`	`LOG_INF("\n");`
`393`	`393`	`}`
`@@ -409,40 +409,40 @@ int main(int argc, char ** argv) {`
`409`	`409`	`}`
`410`	`410`
`411`	`411`	`if (params.interactive) {`
`412`		`- LOG("%s: interactive mode on.\n", __func__);`
	`412`	`+ LOG_INF("%s: interactive mode on.\n", __func__);`
`413`	`413`
`414`	`414`	`if (!params.antiprompt.empty()) {`
`415`	`415`	`for (const auto & antiprompt : params.antiprompt) {`
`416`		`- LOG("Reverse prompt: '%s'\n", antiprompt.c_str());`
	`416`	`+ LOG_INF("Reverse prompt: '%s'\n", antiprompt.c_str());`
`417`	`417`	`if (params.verbose_prompt) {`
`418`	`418`	`auto tmp = ::llama_tokenize(ctx, antiprompt, false, true);`
`419`	`419`	`for (int i = 0; i < (int) tmp.size(); i++) {`
`420`		`- LOG("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());`
	`420`	`+ LOG_INF("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());`
`421`	`421`	`}`
`422`	`422`	`}`
`423`	`423`	`}`
`424`	`424`	`}`
`425`	`425`
`426`	`426`	`if (params.input_prefix_bos) {`
`427`		`- LOG("Input prefix with BOS\n");`
	`427`	`+ LOG_INF("Input prefix with BOS\n");`
`428`	`428`	`}`
`429`	`429`
`430`	`430`	`if (!params.input_prefix.empty()) {`
`431`		`- LOG("Input prefix: '%s'\n", params.input_prefix.c_str());`
	`431`	`+ LOG_INF("Input prefix: '%s'\n", params.input_prefix.c_str());`
`432`	`432`	`if (params.verbose_prompt) {`
`433`	`433`	`auto tmp = ::llama_tokenize(ctx, params.input_prefix, true, true);`
`434`	`434`	`for (int i = 0; i < (int) tmp.size(); i++) {`
`435`		`- LOG("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());`
	`435`	`+ LOG_INF("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());`
`436`	`436`	`}`
`437`	`437`	`}`
`438`	`438`	`}`
`439`	`439`
`440`	`440`	`if (!params.input_suffix.empty()) {`
`441`		`- LOG("Input suffix: '%s'\n", params.input_suffix.c_str());`
	`441`	`+ LOG_INF("Input suffix: '%s'\n", params.input_suffix.c_str());`
`442`	`442`	`if (params.verbose_prompt) {`
`443`	`443`	`auto tmp = ::llama_tokenize(ctx, params.input_suffix, false, true);`
`444`	`444`	`for (int i = 0; i < (int) tmp.size(); i++) {`
`445`		`- LOG("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());`
	`445`	`+ LOG_INF("%6d -> '%s'\n", tmp[i], llama_token_to_piece(ctx, tmp[i]).c_str());`
`446`	`446`	`}`
`447`	`447`	`}`
`448`	`448`	`}`
`@@ -474,7 +474,7 @@ int main(int argc, char ** argv) {`
`474`	`474`	`//GGML_ASSERT(n_ctx >= n_ctx_train * ga_n && "n_ctx must be at least n_ctx_train * grp_attn_n"); // NOLINT`
`475`	`475`	`LOG_INF("self-extend: n_ctx_train = %d, grp_attn_n = %d, grp_attn_w = %d\n", n_ctx_train, ga_n, ga_w);`
`476`	`476`	`}`
`477`		`- LOG("\n");`
	`477`	`+ LOG_INF("\n");`
`478`	`478`
`479`	`479`	`if (params.interactive) {`
`480`	`480`	`const char * control_message;`
`@@ -486,11 +486,11 @@ int main(int argc, char ** argv) {`
`486`	`486`	`" - To return control without starting a new line, end your input with '/'.\n"`
`487`	`487`	`" - If you want to submit another line, end your input with '\\'.\n";`
`488`	`488`	`}`
`489`		`- LOG("== Running in interactive mode. ==\n");`
	`489`	`+ LOG_INF("== Running in interactive mode. ==\n");`
`490`	`490`	`#if defined (__unix__) \|\| (defined (__APPLE__) && defined (__MACH__)) \|\| defined (_WIN32)`
`491`		`- LOG( " - Press Ctrl+C to interject at any time.\n");`
	`491`	`+ LOG_INF( " - Press Ctrl+C to interject at any time.\n");`
`492`	`492`	`#endif`
`493`		`- LOG( "%s\n", control_message);`
	`493`	`+ LOG_INF( "%s\n", control_message);`
`494`	`494`
`495`	`495`	`is_interacting = params.interactive_first;`
`496`	`496`	`}`
Original file line number	Diff line number	Diff line change
`@@ -18671,9 +18671,9 @@ struct llama_model * llama_load_model_from_file(`
`18671`	`18671`	`unsigned percentage = (unsigned) (100 * progress);`
`18672`	`18672`	`while (percentage > *cur_percentage_p) {`
`18673`	`18673`	`*cur_percentage_p = percentage;`
`18674`		`- LLAMA_LOG(".");`
	`18674`	`+ LLAMA_LOG_CONT(".");`
`18675`	`18675`	`if (percentage >= 100) {`
`18676`		`- LLAMA_LOG("\n");`
	`18676`	`+ LLAMA_LOG_CONT("\n");`
`18677`	`18677`	`}`
`18678`	`18678`	`}`
`18679`	`18679`	`return true;`