log.h: make generating separate log files optional.

[staviq]

(cc44877#commitcomment-130881609)

Adds --log-new, when specified, reverts to original behavior of creating separate file.ID.log log files each run.
Adds --log-append, when specified, opens log file in append mode.

[KerfuffleV2]

I can't say much about the code but I 100% approve adding this feature. I hate how currently it's very difficult to predict what the log file will actually be called. (I'll test this when I get a chance.)

By the way, it would be nice if --log-disable wasn't an error when compiled without logging.

[staviq]

By the way, it would be nice if --log-disable wasn't an error when compiled without logging.

That sounds like a good idea, it would make it easier to switch between builds with the same exact command line parameters.

I'm gonna do that in a separate PR, this one is ready and I don't want to complicate it.

[KerfuffleV2]

Hate to say it, but I think this may have broken something. LOG_TEE doesn't seem to produce output with --log-disable. Like a jerk, I didn't get around to testing this before it was merged but now I'm here to whine!

[staviq]

@KerfuffleV2
Unless I missed something, that's how it was before, and yes, that's a bit weird behavior which I overlooked initially, but nobody complained and it made output even cleaner with logs disabled, so i left it like that.

Only compiling with logs disabled, converts LOG_TEE to normal fprintfs, to simulate behavior prior to implementation of logs.

The cause of this is here, both print to log and print to screen checks if LOG_TARGET is disabled:

llama.cpp/common/log.h

Lines 263 to 272 in d606905

	if (LOG_TARGET != nullptr) \
	{ \
	fprintf(LOG_TARGET, LOG_TIMESTAMP_FMT LOG_FLF_FMT str "%s" LOG_TIMESTAMP_VAL LOG_FLF_VAL, __VA_ARGS__); \
	fflush(LOG_TARGET); \
	} \
	if (LOG_TARGET != nullptr && LOG_TARGET != stdout && LOG_TARGET != stderr && LOG_TEE_TARGET != nullptr) \
	{ \
	fprintf(LOG_TEE_TARGET, LOG_TEE_TIMESTAMP_FMT LOG_TEE_FLF_FMT str "%s" LOG_TEE_TIMESTAMP_VAL LOG_TEE_FLF_VAL, __VA_ARGS__); \
	fflush(LOG_TEE_TARGET); \
	} \

A simple fix would be to remove LOG_TARGET != nullptr from the second if

But everything depends on whether this is to be considered a bug or not.

EDIT:

Would having --log-disable together with --log-disable-file help ( disable all log prints, vs disable only prints to file ) ?

[KerfuffleV2]

Unless I missed something, that's how it was before

I don't know... You might be right. I hate to say something negative, especially since I've had nothing but positive interactions with you but... I kind of hate the logging system. Every time I stop compiling with it disabled I run into problems.

Would having --log-disable together with --log-disable-file

Ah, not really. I want to see the log messages, I just don't want random files created automatically.

Actually, these latest problems are from trying to use it in my simple-inference thing. My thinking was that this is the logging/output facility provided for llama.cpp, I should probably use it in my llama.cpp example. It seems weird to just use all raw printf when that exists.

I think the problem is that it doesn't really work like other logging systems. With most log systems you have various levels like: DEBUG, INFO, NOTICE, WARNING, ERROR, CRITICAL. You produce log messages with a level associated and then there are consumers, like the file output, the console output, etc where you set the level you want to see. So if I turn on logging to file, I might set the level to DEBUG so there's a record of everything if I've trying to pin down problems. On the other hand, for console output, I'd probably want to set it to INFO or NOTICE.

Then the app can produce the log messages, they get presented in a relatively nice was as appropriate for where they're going, like with level colors or whatever for the console, etc. Then you basically never have to use printf in your app and just rely on the log facility to do the reasonable thing.

But here, I don't really see a way to use the system. LOG just doesn't go to console at all. LOG_TEE only goes to the console sometimes. After rambling all this time (sorry, brain is already asleep) I guess you mean add a new --log-disable-file option that makes logging only go to console? I guess that works, but I feel like the most reasonable behavior (without major changes) is --log-disable does the same as just compiling with LLAMA_DISABLE_LOGS. Heh, this is another reason to dislike the cmake option: Can't even disable logs!

[staviq]

@KerfuffleV2
I actually tried to rewrite logging into something more "modern" and universal, but I got overwhelmed by scope creep, and I could never tell if features will actually end up being used at all or will become unnecessary bloat so I never finished it. It's in #3219.

You should be able to disable logs at compile time, just for your example, by defining LOG_DISABLE_LOGS before including "common"

This will make your example, and only your example, always compile as if LLAMA_DISABLE_LOGS is used, without having to set flags for make or cmake.

#define LOG_DISABLE_LOGS
#include "common.h"

[KerfuffleV2]

@staviq I apologize, I really shouldn't have written that post. I guess the filter part of my brain that keeps me from being a jerk had already gone to sleep. You can probably tell I'm a bit frustrated with it, but I wouldn't normally write something like that.

but I got overwhelmed by scope creep

I definitely know that feeling. I don't think it really has to be super complicated or have huge scope. I don't know if it helps, but I can give you an idea of how I think it could look and make a scope:

Just something that allows logging with the levels I mentioned. The levels can be an enum so they're ordered, allowing for stuff like if (level >= LOG_ERROR) to match ERROR and CRITICAL. For console, >= WARNING would probably go to stderr or the equivalent. I don't think adding multiple file targets really makes it much harder (and it can be useful to something like send everything to debug.log, send normal messages to blah.log) but that's probably not really a critical feature.

In my opinion, anything the program wants to print out that would be a line of text - so with a newline at the end would go through the log facility. There are some exceptions like printing out tokens as they're generated or printing a prompt for user input.

The API for using it usually looks something like LOG(level, format_or_message) with some convenient aliases like LOG_INFO(format_or_message) that just do LOG(LOG_LEVEL_INFO, format_or_message), etc.

If you really wanted to be fancy you could also have a way to log, but only to non-console destinations. So like in the case of prompting the user for input, there could also be a Prompting user for input log message that doesn't get displayed in addition to the normal prompt. Bells and whistles like that or being able to specify extra log destinations are nice to have, but not that important compared to the basic functionality.

I'm not trying to tell you what to do or anything, just sharing my opinions about how it could look just in case it might be helpful to you in some way.

It's in #3219.

I think I might even have seen that, but from the description it sounded like internal stuff. Unfortunately, I never got around to trying it out.

This will make your example, and only your example, always compile as if

I might as well just be using printf if I'm doing that. :) I don't dislike the idea of logging in general or anything like that.

[staviq]

@staviq I apologize, I really shouldn't have written that post. I guess the filter part of my brain that keeps me from being a jerk had already gone to sleep. You can probably tell I'm a bit frustrated with it, but I wouldn't normally write something like that.

Many people have "this" and they intuitively understand. I'd tell you not to worry too much about it, but the specifics of "this" are usually such that you will worry anyway :)

Your ideas are very helpful, and I will come back to log improvements PR at some point, especially that other parts of the project started using logs, and some sort of use case baseline is now established.

My original idea about improving logs already overlaps with your suggestions, and they are very appreciated either way.