-
In the past, we've noticed that the current logging/reporting mechanism through sf::err() may not be flexible enough, e.g. here (http://en.sfml-dev.org/forums/index.php?topic=17888.msg128442#msg128442) or here (http://en.sfml-dev.org/forums/index.php?topic=17888.msg137042#msg137042).
Possible features that can be discussed:
- Division into different severity levels: error, warning, info, debug
- Filtering (by level, or even module/functionality-wise)
- Choosing the output streams (not only std::cerr)
- Meta-information: time, source file, line
- Ideally zero performance overhead for loggers disabled at compile time
For example, I could imagine a macro which creates an object with overloaded operator<<, that logs messages according to the current log configuration. Having a macro allows the collection of above-mentioned meta-information and complete away-optimization for statically disabled loggers.
SFML_LOG_E("An error with number " << 77)
Note that this thread is not about error handling, but logging. Whether to use boolean return types or exceptions is therefore not the topic here.
-
In the future (SFML 3), detailed information about errors will be delivered through the new error reporting system (which will not be discussed here), for example exceptions. So what does this leave for the logging system itself? Developer warnings, mainly (for example, "an OpenGL call failed ..."). So do we really need to build a sophisticated logging system? Information that developers will want to catch/redirect are those given in case of error, ie. those not given by the logging system.
So... as a starting point, I think we should clarify the scope of this feature. To be sure that we won't over-engineer it ;)
-
Developer warnings, mainly (for example, "an OpenGL call failed ..."). So do we really need to build a sophisticated logging system? Information that developers will want to catch/redirect are those given in case of error, ie. those not given by the logging system.
This is true for trivial systems, but if you have a more complex system, you will usually need a bit more context information in order to efficiently track bugs down than most libraries can and do provide through their error reporting mechanism. Of course you can always utilize a step by step debugger, but the typical enduser doesn't have one and step by step debugging is quite time consuming, so a decent log can spare you time.
- Division into different severity levels: error, warning, info, debug
- Filtering (by level, or even module/functionality-wise)
- Choosing the output streams (not only std::cerr)
- Meta-information: time, source file, line
- Ideally zero performance overhead for loggers disabled at compile time
I think that disabling the log system at compile time isn't that useful, because as a dev/library user you want the ability to read the debug information anyways and as an enduser you probably won't be able to provide useful context information without it as already stated. So I believe it is much more useful to implement a configurable almost zero overhead runtime filtering.
Furthermore I think 3. is far to unspecific; I propose to implement an API that works like so:
#include <SFML/System/Log.hpp>
void logEntryProcessor(void *userData, sf::Log::Channel channel, sf::Log::Level level, const std::string &message)
{
// inject into some log framework or log directly to file/cerr/cout/etc.
}
int main( )
{
sf::Log::Manager::setCustomLogEntryProcessor(&logEntryProcessor, NULL);
// any further log message will be processed by logEntryProcessor
}
This only requires the filtering and logEntryProcessor to be threadsafe. The former could easily be realised through atomics and the latter can use a mutex/async work queue/etc. The default log entry processor doesn't have to be more complicated than just outputting the metadata and the message to std::cerr (or sf::err if you don't want to break current redirection systems), because the preferred backend is strongly user dependent and it's easy for the user to integrate the SFML log with his preferred backend.
Time information is almost always unnecessary and if it is necessary the user can easily add it with a custom log processor method. File and line information are mostly unnecessary too (the log system shouldn't be abused as error reporting system), but since this is more common and can't be done with a custom log processor I would provide an additional macro for this like so:
#define SFML_LI __FILE__ << ":" << __LINE__ << ": " <<
sfLogNetErr(SFML_LI "the acutal error message as usual" << someStreamableVar);
For example, I could imagine a macro which creates an object with overloaded operator<<, that logs messages according to the current log configuration. Having a macro allows the collection of above-mentioned meta-information and complete away-optimization for statically disabled loggers.
SFML_LOG_E("An error with number " << 77)
I propose std::ostream and friends (or more precisly std::ostringstream), because they can serve all your needs or can be easily extended to do so, no need to reinvent the wheel. SFML_LOG_E contradicts the naming conventions (http://www.sfml-dev.org/style.php#naming-conventions); I propose sfLogErr or sfLogSysErr instead which do comply to the naming conventions and are less tedious to type.
Edit: I believe that SFML doesn't need a next generation log system, it just needs to be easy to integrate SFML into one of the various existing ones.
-
Laurent is probably right, we should aim for something simple. Introducing dedicated classes for channels, levels, entry processors, log managers, thread safety etc. makes things overly complicated. SFML shouldn't aim to be a logging library.
Maybe we should ask ourselves, where does the current system lack? Logging is something that is more useful to SFML developers and contributors than to average end-users. And if the focus lies on internal use, an API in the conventional way may not even make sense... The currently only use of having sf::err() public is to allow redirection to different output sinks.
Disabling logs statically is useful, because a real-time multimedia library has to run fast, and I definitely don't want to force logging overhead on people who don't need it. Runtime filtering can never be as fast because you need to evaluate expressions that are passed to the logger, and if they're not used, this evaluation is a waste of time.
You're right about the naming convention. glCheck() and alCheck() are currently the only function-style macros, and maybe it's not ideal that they look like functions.
-
How about using a single class/interface similar to how SFML's stream classes work?
class LogHandler : NonCopyable {
public:
virtual onError(const sf::String &message) {}
virtual onWarning(const sf::String &message) {}
virtual onInformation(const sf::String &message) {}
virtual onDebug(const sf::String &message) {}
}
These would then be called by stream operators depending the used instance, e.g. what's returned by sf::err().
-
@Mario: So you would add an API to specify global log handlers, like the following?
sf::Log::addHandler(myHandler);
Also, I think these functions should take an additional parameter with the metadata (small struct). Or even only one function with parameter that contains all the information.
class LogHandler
{
public:
struct Entry
{
Level level; // enum
String file;
unsigned int line;
String message;
};
virtual void onLogEntry(const Entry& e) = 0;
};
-
Disabling logs statically is useful, because a real-time multimedia library has to run fast, and I definitely don't want to force logging overhead on people who don't need it. Runtime filtering can never be as fast because you need to evaluate expressions that are passed to the logger, and if they're not used, this evaluation is a waste of time.
Runtime filtering (at least with my implementation) takes one function call, one map<int, int> (a very small one which could be optimized away for standard channels) lookup and two integer comparisons, so it should be faster than the current sf::err() approach. Combined with the current logging habits the performance impact is almost unmeasurable. Anyways we can simply introduce a CMake switch for removing logging from the release builds, this is quite easy to implement.
Laurent is probably right, we should aim for something simple. Introducing dedicated classes for channels, levels, entry processors, log managers, thread safety etc. makes things overly complicated. SFML shouldn't aim to be a logging library.
Maybe we should ask ourselves, where does the current system lack? Logging is something that is more useful to SFML developers and contributors than to average end-users. And if the focus lies on internal use, an API in the conventional way may not even make sense... The currently only use of having sf::err() public is to allow redirection to different output sinks.
Channel and Level are structs for type safety reasons as recommended by Scott Meyers Effective C++ and won't probably be used directly except for additional channel macro definitions. Furthermore there is no entry processor class, any function can serve as one which is the simplest possible solution in order to provide a properly redirectable message system. Neither there is a notable Manager class, it's just there in order to initialize the map at startup. If the log entry classification is already too much for you, you can scale the approach down to a simple sfLog() macro, removing the need for the Channel, Level, LogManager "classes", but providing a method to either remove the messages at compile time or to disable them at runtime using a global bool variable and of course it would allow redirection at log entry level opposed to the current redirection possibility at stream level.
Apart from that I think that my proof of concept can be easily adapted (probably within an hour) to satisfy your initially specified requirements and as already stated it is really simple to use, small and more efficient than the current sf::err() approach.
EDIT: I'm talking about this (https://github.com/SFML/SFML/pull/998) proof of concept.
If we can settle on an approach which allows for easy message level redirection, I will voluntarely replace sf::err() with the new Solution throughout the SFML libraries.
-
Runtime filtering (at least with my implementation) takes one function call, one map<int, int> (a very small one which could be optimized away for standard channels) lookup and two integer comparisons, so it should be faster than the current sf::err() approach.
The requirement however is not "faster than sf::err()" (which is only used in error cases, where performance is usually not critical), but "fast", or even better "zero overhead when not used".
Combined with the current logging habits the performance impact is almost unmeasurable.
That depends strongly on the code path. Already an if statement in the wrong place can be measurable. And if we want to stay flexible, we should avoid unneeded constraints.
Anyways we can simply introduce a CMake switch for removing logging from the release builds, this is quite easy to implement.
Yes, and then we can as well let the user specify the log levels for Debug and Release. Macros are needed anyway. The problem is that this then leads to incompatible SFML distributions, so we have to come up with meaningful defaults that 99% of the people use.
Channel and Level are structs for type safety reasons as recommended by Scott Meyers Effective C++.
Why not enums? Why Channel at all?
any function can serve as one which is the simplest possible solution in order to provide a properly redirectable message system.
That's true, I'm not sure if we should prefer function pointers with void* over a class with virtual functions. Functions don't need memory management, but only as long as you don't pass an object via void*.
But I agree that simple "entry processing" can make sense, e.g. with a global function or an interface similar to the one shown in my last post.
Apart from that I think that my proof of concept can be easily adapted (probably within an hour) to satisfy your initially specified requirements and as already stated it is really simple to use, small and more efficient than the current sf::err() approach.
I know. The implementation is not the problem, the design and scope is. So let's not be overzealous... Such things need careful thought (especially if they become part of the API), unless we want to redesign everything in the next version again, and only very few people have given their opinion so far. Furthermore, logging is not the top priority right now ;)
-
That depends strongly on the code path. Already an if statement in the wrong place can be measurable. And if we want to stay flexible, we shouldn't put needless constraints.
Yes you are completely right. A single if statement can become measurable, but only in either very poorly designed applications or very rare use cases where SFML won't even be considered to be used ;).
The problem is that this then leads to incompatible SFML distributions, so we have to come up with meaningful defaults that 99% of the people use.
This is wrong. You can have ZERO overhead and 100% compatible binaries.
Channel and Level are structs for type safety reasons as recommended by Scott Meyers Effective C++.
Why not enums? Why Channel at all?
Enums aren't typesafe and clutter the namespace they are defined in. I would have used enum class if C++03 hadn't been a requirement.
Why channel? Because of usability: If I track a network bug, I'm not interested in log entries coming from the graphics subsystem. Furthermore it would allow SFML addons like SFGUI to use the same logging frontend and therefore the user wouldn't have to implement redirection for them seperately.
That's true, I'm not sure if we should prefer function pointers with void* over a class with virtual functions. Functions don't need memory management, but only as long as you don't pass an object via void*.
I think that a function to add log processors is overkill and unneeded, almost no one needs that multiplexing ability and it is easily implemented on top of a single global log processor. I changed my mind about the userdata pointer/class based approach: It's unnecessary, simply use a static function with globals (normally I wouldn't recommend globals, but in this case it doesn't matter, because the log backend is set on a global basis anyways.
-
Yes you are completely right. A single if statement can become measurable, but only in either very poorly designed applications or very rare use cases where SFML won't even be considered to be used ;).
Do you really not understand what I'm trying to say? If we want our logger to be usable universally within SFML, we have to make sure it can be optionally disabled, in order to have full verbosity when debugging and full speed for normal builds. As soon as we get into the situation "a log output here would be very useful, but I'm worried about the runtime overhead", we've done the fundamental design wrong.
This is wrong. You can have ZERO overhead and 100% compatible binaries.
Only under constraints. You have to be extremely careful when linking differently compiled libraries. And it's not possible to use inline functions or other scenarios that may affect the binary interface.
Enums aren't typesafe and clutter the namespace they are defined in.
They're typesafe among each other, just convertible to integers. We use the scoped enum idiom. Enums work very well in the rest of the SFML API, we're not going to switch to an obscure and uncommon technique ;)
I think that a function to add log processors is overkill and unneeded, almost no one needs that multiplexing ability and it is easily implemented on top of a single global log processor.
I agree.
I changed my mind about the userdata pointer/class based approach: It's unnecessary, simply use a static function with globals (normally I wouldn't recommend globals, but in this case it doesn't matter, because the log backend is set on a global basis anyways.
But it only hides the problem: it's not guaranteed that global/static objects outlive the logger, so we may get UB as well. I don't think there's a nice solution as long as SFML uses global objects itself.
-
This is wrong. You can have ZERO overhead and 100% compatible binaries.
Only under constraints. You have to be extremely careful when linking differently compiled libraries. And it's not possible to use inline functions or other scenarios that may affect the binary interface.
In our case we can simply remove the calls to the log system by defining sfLog(message) as nothing. We don't need to change any other function or class of the log system. Thus the API and ABI doesn't differ, all calls to the log system are removed by the preprocessor -> zero overhead.
Enums aren't typesafe and clutter the namespace they are defined in.
They're typesafe among each other, just convertible to integers. We use the scoped enum idiom. Enums work very well in the rest of the SFML API, we're not going to switch to an obscure and uncommon technique
It's neither obscure nor uncommon, see Scott Meyers Effective C++ (http://www.aristeia.com/books.html) tip 18 & 19.
And I would not call this typesafe among each other:
enum e1 {E1V1,E1V2}; enum e2 {E2V1,E2V2};
int main( )
{
e1 v1;
e2 v2;
bool b = v1 == v2 || v1 < v2 || v1 > v2; //<- valid c++
}
-
Just a couple quick thoughts.
SFML's logging system should either be:
1. A fully robust logging system that will cover most reasonable use cases.
or
2. Easily redirected into another stream/file, so SFML users can set up their own logging system and easily direct sfml output into it.
As a user I don't care which. I respect the team's decision on whether a feature-rich logging system is within the scope of SFML or not.
-
SFML's logging system should either be:
1. A fully robust logging system that will cover most reasonable use cases.
No I don't think so. Adding a fully robust logging system to SFML would be like adding a fully standard compliant SMTP/POP3/IMAP protocol implementation to the network library - out of scope ;).
-
SFML's logging system should either be:
1. A fully robust logging system that will cover most reasonable use cases.
No I don't think so. Adding a fully robust logging system to SFML would be like adding a fully standard compliant SMTP/POP3/IMAP protocol implementation to the network library - out of scope ;).
I respect your opinion.
Still, I'd say error logging is a near-necessity for most graphics or network programs. So it's not insanely out of scope. These are both areas in which things go wrong all the time, often on an end-user's computer. Logging is a critical tool in helping diagnose those errors.
But there are a lot of other logging options out there. So it's not a big deal if we need to use one of those, or roll one ourselves.
I could see it either way.
-
@Mario: So you would add an API to specify global log handlers, like the following?
sf::Log::addHandler(myHandler);
Yes, something like that.
-
In our case we can simply remove the calls to the log system by defining sfLog(message) as nothing.
Of course, that's the whole reason why I'm in favor of a macro :)
We don't need to change any other function or class of the log system. Thus the API and ABI doesn't differ, all calls to the log system are removed by the preprocessor -> zero overhead.
And what if the preprocessor has an effect to the ABI? I mentioned inline functions, templates are also possible. I'm not saying it's impossible, but as always when dealing with conditional compilation across libraries, we have to be careful.
It's neither obscure nor uncommon
What is it exactly? A link to a list of books is not helpful. I'm assuming you talk about a class (the "enum") that has public static constants (the "enumerators"). This overengineers the situation and introduces its own problems, for example it makes the initialization of the constants dynamic. And yes, this is a very real problem (https://github.com/SFML/SFML/commit/0c3d361cebb9001c404b8da83be235e44d3406c6), possibly more than the comparison of different enums.
Anyway, I already said we used enum successfully throughout the SFML API and won't change it only because an authority said so 10 years ago. In SFML 3, we may consider well-known techniques like enum classes ;)
But there are a lot of other logging options out there. So it's not a big deal if we need to use one of those, or roll one ourselves.
People will have different requirements regarding logging, so it's best if we provide the basic flexibility to plug in other loggers, rather than reinventing one specific wheel within SFML itself.
-
People will have different requirements regarding logging, so it's best if we provide the basic flexibility to plug in other loggers, rather than reinventing one specific wheel within SFML itself.
Sounds good to me!
About defining sfLog as a macro which can be preprocessed out to nothing:
In my experience, this doesn't fully solve the problem. Often, you need to create a string or stringstream and format various information into your log message. If you really want to preprocess out all costs associated with logging, you need to put your #ifdefs around the entire block including both the log statement, the string(stream) variable, and the formatting / string concatenation calls.
Just #defining the sfLog call to nothing leaves a bunch of these logging perf costs in place. It may also result in a bunch of unused variable warnings. Those warnings can be turned off, but it's generally a bad idea to do so, as you might be masking other instances of logic errors in your code.
So, the sfLog macro idea may be less helpful than it might originally seem.
-
About defining sfLog as a macro which can be preprocessed out to nothing:
In my experience, this doesn't fully solve the problem. Often, you need to create a string or stringstream and format various information into your log message. If you really want to preprocess out all costs associated with logging, you need to put your #ifdefs around the entire block including both the log statement, the string(stream) variable, and the formatting / string concatenation calls.
Just #defining the sfLog call to nothing leaves a bunch of these logging perf costs in place. It may also result in a bunch of unused variable warnings. Those warnings can be turned off, but it's generally a bad idea to do so, as you might be masking other instances of logic errors in your code.
So, the sfLog macro idea may be less helpful than it might originally seem.
Meh, this is only true if sfLog has no formatting abilities. My updated proof of concept (https://github.com/SFML/SFML/pull/998) is as flexible as a stringstream (because it uses one under the hood ::)), can discard the log messages and associated formatting instructions at preprocessing time which guarantees zero overhead and doesn't affect binary compatibility, i.e. the ABI doesn't differ between binaries with and without logging enabled. So, the sfLog macro idea can be as helpful as it originally seems.
We don't need to change any other function or class of the log system. Thus the API and ABI doesn't differ, all calls to the log system are removed by the preprocessor -> zero overhead.
And what if the preprocessor has an effect to the ABI? I mentioned inline functions, templates are also possible. I'm not saying it's impossible, but as always when dealing with conditional compilation across libraries, we have to be careful.
Yes, I agree with you that the preprocessor can affect the ABI, but this is only the case if you use preprocessor magic within exported function/method signatures or class definitions and as my poc shows we don't need to do this, just voiding out the function like sfLog macro suffices and can't affect the ABI at all.
@Nexus regarding enums, etc.: The approach I've taken was recommended by C++ Gurus (Herb Sutter, Scott Meyers, ...) until C++11 solved the problem at language level with enum class, so I consider it as well known. Anyways I won't use SFML, i.e. I'm done with this.
-
Meh, this is only true if sfLog has no formatting abilities. My updated proof of concept (https://github.com/SFML/SFML/pull/998) is as flexible as a stringstream (because it uses one under the hood ::)), can discard the log messages and associated formatting instructions at preprocessing time which guarantees zero overhead and doesn't affect binary compatibility, i.e. the ABI doesn't differ between binaries with and without logging enabled. So, the sfLog macro idea can be as helpful as it originally seems.
Is it possible to preprocess that out? What would that look like? If so, I agree that's a good solution.
-
Have you guys considered building something simple ontop of the fmt (formerly cppfmt) library?
https://github.com/fmtlib/fmt
I've used this library in other projects and I can tell you its great to be able to do printf style logging in C++. Its also much faster than iostream (see benchmarks).
-
Seems like a neat library. Re-reading some of the discussion I think came to the conclusion that we should keep things as simple as possible. Adding a whole dependency just for simple output formatting seems a bit too much. Unless that was a general questions to everyone and not directly connected to SFML. :)