server: logs - unified format and --log-format option

[phymbert]

Motivation

It becomes difficult to investigate what's going on the server, especially in parallel scenario.

Also, logs are currently not outputting to the same format, making impossible for a logs parser to analyze llama.cpp server logs.

One would expect a human-readable or a JSON log format.

Changes

• introduce option --log-format FORMAT: Define the log output to FORMAT: json or text (default: json)
• Replace usage of LOG_TEE to LOG_INFO in almost all places.
• add tid, slot_id and task_id on all possible logging places
• add more verbose logs in update_slots
• tests are using text based format by default

[ggerganov]

I'm not sure what is the benefit of logging the data through json objects and have forgotten why we introduced this in the first place. It makes it difficult to read the log when running in the terminal

We should remove this and log as usual. For example:

                LOG_INFO("slot data", {
                    {"task_id",            task.id},
                    {"n_idle_slots",       n_idle_slots},
                    {"n_processing_slots", n_processing_slots}
                });

becomes:

LOG_TEE("%s: slot data - task_id = %d, n_idle_slots = %d, n_processing_slots = %d\n", __func__, task.id, n_idle_slots, n_processing_slots);

[ngxson]

@ggerganov I think it (the JSON log) was introduced because you can write like this:

                LOG_INFO("slot data", {
                    {"task_id",            task.id},
                    {"n_idle_slots",       n_idle_slots},
                    {"n_processing_slots", n_processing_slots}
                });

Then the macro will translate the call into:

LOG_TEE("%s: slot data - task_id = %d, n_idle_slots = %d, n_processing_slots = %d\n", __func__, task.id, n_idle_slots, n_processing_slots);

But unfortunately that such macro never exists in our code base.

[ggerganov]

@ggerganov I think it (the JSON log) was introduced because you can write like this:

Yeah, in the source code it looks nicer. But in the code you write it once and then in the terminal you read it hundreds of times, so it's better to look nice when you read it

[ngxson]

I've just looked into server_log(), seems like it's totally possible to "pretty print" json to something like task_id = %d, n_idle_slots = %d, n_processing_slots = %d

But that's a bit out-of-scope for this PR, I don't know @ggerganov you prefer to have the log printed out that way? I can propose that in another PR

[ggerganov]

No need. We use snprintf-style logging throughout the code base, so at the very least for consistency we should remove the json objects.

But all this is low-prio - the PR is good to merge as it is

[phymbert]

I am reverting to the draft, and I will take the time to introduce a --log-format option as it will help humans to read logs in the console. But keeping the current format as default for production systems monitoring tools which requires structured log format, json is mainly the standard.

please have a look to the new approach with --log-format

[ngxson]

Good idea, but I'd prefer to have --log-format to be text by default. I don't think json is preferable, except in the case the log is forwarded to SOC platform like grafanas for example.

Thank you for the hard work, don't forget to take time to relax because it's weekend.

[phymbert]

Good idea, but I'd prefer to have --log-format to be text by default. I don't think json is preferable, except in the case the log is forwarded to SOC platform like grafanas for example.

Thank you for the hard work, don't forget to take time to relax because it's weekend.

I would propose to merge this first version, which at the beggining only aims to switch all to the same JSON format. We can introduce colors, output based on level and better C++ code later on.
@ngxson If you are OK with latest change on the text format. I will merge, thanks for your nice reviews

[ngxson]

Yeah it's LGTM. Thanks!