Output levels

A place to discuss everything about the Orxonox framework.

Moderator: PPS-Leaders

User avatar
x3n
Baron Vladimir Harkonnen
Posts: 810
Joined: Mon Oct 30, 2006 5:40 pm
Contact:

Re: Output levels

Post by x3n » Mon Aug 01, 2011 9:18 pm

I spent my weekend replacing COUT() with orxout() :angry-pc: and because this means I edited pretty much everyone's code, I think I owe you a summary of what I did and what you should expect from it (and what not) ;)

First of all, the number of output levels almost doubled. This means for every existing line of output I had to use one of the new levels:
COUT(0) -> orxout(message) or orxout(debug_output)
COUT(1) -> orxout(user_error) or orxout(internal_error)
COUT(2) -> orxout(user_warning) or orxout(internal_warning)
COUT(3) -> orxout(user_status), orxout(user_info), orxout(internal_status), or orxout(internal_info)
COUT(4) -> orxout(verbose)
COUT(5) -> orxout(verbose_more)
COUT(6) -> orxout(verbose_ultra)

I tried to use the best level for each message, but obviously it's not perfect. Naturally I used the internal levels more often than the user levels. There are no definite rules how to use the levels and I can not really estimate the frequency of each output, hence it's hard to get it right without testing.

As you can imagine, while replacing roughly 1000 lines I surely made some mistakes. Unfortunately that's hard to find because the vast majority of output is either error, warning, or verbose. Errors and warnings are usually not visible while executing orxonox (because there are no errors) and verbose output is not visible unless its context is activated. This means we have to see in the next time if output still works as it should and everyone is asked to clean up the output in his own code if necessary. But no hurry.

And please don't think there's only one correct way to use the output levels and if you do it wrong you get punched in the face. In fact your output can have almost every possible level as long as it makes some sense and is useful.

While looking through the code I also noticed that many people used some workarounds with the old COUT levels. For example, if they had important errors and less important errors, the less important errors were often printed with warning level. And less important warnings with info level. In the new output system this doesn't work anymore because every output with error levels has "Error: " in front of it (the same also with warning, status, etc). But since there are user and internal levels, we're probably fine. I tried to transform output levels in these casees in a meaningful way, i.e. if a message described an error but used warning level, I used internal_error.

---

Because every line of output now has a prefix depending on the level ("Error: ", "Warning: ", etc) I removed these tokens from the output messages because it would be redundant.

Additionally I changed std::endl to endl - even though I don't care about these additional 5 chars I think many pps students do, so since we already allow the use of "endl" we may as well make it the default. ;)

---

About the output contexts: I used about 20 contexts for the framework and about 10 for the game logic. Basically every verbose output needs a context because otherwise you will not see it (unless you activate ALL verbose output, but you probably don't want that). So there are cases were I used a context for one single line. In other cases output was used for dozens of output lines, not only verbose but also warnings, errors, etc, for example everything related to quests.

Note that you don't have to use a context for every message. It's mostly useful for verbose output, but if we already have a context for some part of the code, we may also use it for non-verbose output. ;)

---

In the next days I will add some more output with status and info level, and also tweak the existing output a bit. The output levels status and info are important because they guide the user through the different states of the game and provide valuable information in the log file. The goal is to get some information in which state the game was if it crashes.

---

Something else I noticed is that obviously everyone thinks his part of the game is the most important part and consequently uses "strong" output levels and messages. There is some code in orxonox where a slightly wrong parameter results in "FATAL ERROR! something went terribly wrong" assert(0); or something similar ;)

I mean I totally understand this from a programmer's point of view and I don't want to blame anyone (it concerns also my code), but we should try to print our internal errors only with internal output level and don't annoy the user with a load of (for him) unimportant messages. Also aborting the game will be bad practice if we finally get an editor because then the game should keep running and just print an error message. I didn't change anything of this though, that's up for future changes.
Fabian 'x3n' Landau, Orxonox developer

User avatar
1337
Baron Vladimir Harkonnen
Posts: 521
Joined: Wed Oct 10, 2007 7:59 am

Re: Output levels

Post by 1337 » Tue Aug 02, 2011 1:28 am

That sound very good indeed!
When I can find the time after my brief visit to the land of eatable cheese, good chocolate and reasonable air conditioning, I sure will have a look at orxout() in my code.

Thx!
http://www.xkcd.com/
A webcomic of romance, sarcasm, math, and language.

User avatar
x3n
Baron Vladimir Harkonnen
Posts: 810
Joined: Mon Oct 30, 2006 5:40 pm
Contact:

Re: Output levels

Post by x3n » Fri Aug 12, 2011 12:26 pm

The output system is advancing quite well (considering my current work load). Time to give you an overview of the recent changes.

Filtering output
Of course we want to generate as little output as possible. A line of output in the code might look somewhat like this:

Code: Select all

orxout(level, context) << "blabla: " << value << " asdf " << othervalue << "!" << endl;
In this example we have to convert 2 values to string and concatenate a total of 5 strings. But this should only happen if at least one of the output writers (console, logfile, etc) actually want's to print this line.
This means we have to check for each line of output if the given level and context are desired. In fact this happens for each call of the << operator because we can't just skip the whole line. This again means that the check needs to be fast.

I implemented this with binary masks for levels and contexts. Each OutputListener defines a mask with their desired levels and contexts. The OutputManager then combines all these masks. If the level and context of a new line of output matches this mask, the line is sent to OutputManager. There the check is repeated for each OutputListener to send them only the requested output.

There's a total of 3 masks, which looks like overkill at the first glance, but allows a great deal of flexibility. The first mask defines which output levels you want, independent of contexts! The other two masks are used to request specific contexts with specific output level. Any of these masks can be 0 to disable output.

The masks are used like this:

Code: Select all

bool acceptsOutput(level, context)
{
    return (level & levelMask) ||
            ((context & additionalContextMask) && (level && additionalContextLevelMask));
}
So for example you could define something like this: "I want all output with user level plus all output with network context and verbose level." The second part is labeled "additional contexts" because in 99% of the cases you don't use them. But if you want to debug a part of your code, you can activate this context. We can also create a listener that receives only output with xml context and error level. In this case levelMask would be 0 and only the part with the additional contexts is used.


Sub-contexts
While this approach using masks is certainly fast and simple, it limits the number of contexts to 64 (including implicit contexts like "undefined"). Even though we currently use only 30 contexts, I figured that this is not enough. In fact while adapting each line of output to the new system I abandoned some contexts because I thought it's not worth to create a new context for only one or two lines of output. So even though I was not even close to 64 contexts, I already felt the pressure of this limitation. :wink:

However at the same time I appreciate the performance of the binary mask. So I decided to implement sub-contexts. Different sub-contexts of the same main-context have the same binary mask, but they have different names and can be activated separately. Using sub-contexts looks like this:

Code: Select all

// 2 normal contexts
REGISTER_OUTPUT_CONTEXT(network);
REGISTER_OUTPUT_CONTEXT(xml);

namespace misc
{
    // 2 sub-contexts of the main-context "misc"
    REGISTER_OUTPUT_SUBCONTEXT(misc, example);
    REGISTER_OUTPUT_SUBCONTEXT(misc, otherexample);
}

// output with context "network"
orxout(internal_info, context::network) << "bla" << endl;

// output with subcontext "misc::example" (and main-context "misc")
orxout(internal_info, context::misc::example) << "blub" << endl;
Note that the namespace "misc" is entirely optional, but it ensures that two sub-contexts of different main-contexts can not collide and it looks much better if you can write context::misc::example instead of e.g. context::misc_example. The downside of using a namespace is that you can not use context::misc allone. But this is rarely ever needed and you can still work around this by defining e.g. context::misc::general.

In the config file, sub-contexts can be activated using the string "<main-context>::<sub-context>" (e.g. "misc::example"). This holds even if you don't define the sub-context in the "misc" namespace. The only thing that counts is that "example" is a sub-context of "misc".

Note that since all sub-contexts in the above example share the binary mask of the "misc" context, this means that once you activate one sub-context in the config file, the output of the other sub-contexts will also be generated, but not displayed. Also note that filtering sub-contexts is only supported by the output writers inheriting from BaseWriter, not OutputListener in general. Still they provide a great deal of flexibility and we can define contexts much more fine-grained. There is no limit for the number of sub-contexts and they don't harm the performance (except if you activate only a single sub-context, but this probably means that you're debugging and then you don't care)
Fabian 'x3n' Landau, Orxonox developer

User avatar
1337
Baron Vladimir Harkonnen
Posts: 521
Joined: Wed Oct 10, 2007 7:59 am

Re: Output levels

Post by 1337 » Fri Aug 12, 2011 2:50 pm

x3n wrote:There is no limit for the number of sub-contexts.
I was thinking of defining 4294967297 subcontexts for the input system...

Apart from that, it all looks great!
If I happen to have more time (no more traveling for the next few weeks...), I will certainly study the new system because so far, I've always learned something new ;)

So, I should probably close firefox now: it's using a whole core and I have this tab plus empty Google open...
http://www.xkcd.com/
A webcomic of romance, sarcasm, math, and language.

User avatar
x3n
Baron Vladimir Harkonnen
Posts: 810
Joined: Mon Oct 30, 2006 5:40 pm
Contact:

Re: Output levels

Post by x3n » Fri Aug 12, 2011 3:42 pm

Actually the sub-context ID is only uint16_t at the moment :D
However both the main-context mask and the sub-context ID are both virtually unlimited because the name of the context is stored in the context struct, so if you only want nice context names in the logfile, you can use a bazillion of them.
The masks and IDs are created whenever a context is used first. Defining a context in the config file is equivalent to using it. So it's only important that the number of contexts in the config file + the number of contexts used before loading the config file doesn't exceed the limit. However since we can not really control the number of contexts during the static initialization, I don't recommend declaring more contexts than officially supported. ;)

Edit: The code is not yet documented, you might want to wait with looking at the code until I comment it. I doubt you can learn much since most is pretty straight forward, but you're welcome to review it and give me some advice ;)

Sometimes the code is even ugly, e.g. when I store a pointer to a context struct instead of a copy, just to gain some performance. It's unclear what happens if output is generated during the deallocation of the static values. But this holds for the whole system anyway (and it was the same with the old output system). I never experienced problems so far. The worst case is a crash during exit and/or if the logfile gets opened again and its content is thus overwritten.
Fabian 'x3n' Landau, Orxonox developer

User avatar
x3n
Baron Vladimir Harkonnen
Posts: 810
Joined: Mon Oct 30, 2006 5:40 pm
Contact:

Re: Output levels

Post by x3n » Mon Aug 22, 2011 10:52 pm

Merged back to trunk.
Changes:
- you have to include util/Output.h instead of util/Debug.h
- COUT(x) is now called orxout(level)
- output levels are now defined by an enum instead of numbers. see util/Output.h for the definition
- it's possible to use output contexts with orxout(level, context). see util/Output.h for some common contexts. you can define more contexts
- you must use 'endl' at the end of an output message, '\n' does not flush the message

Output levels:
- instead of COUT(0) use orxout()
- instead of COUT(1) use orxout(user_error) or orxout(internal_error)
- instead of COUT(2) use orxout(user_warning) or orxout(internal_warning)
- instead of COUT(3) use orxout(user_status/user_info) or orxout(internal_status/internal_info)
- instead of COUT(4) use orxout(verbose)
- instead of COUT(5) use orxout(verbose_more)
- instead of COUT(6) use orxout(verbose_ultra)

Guidelines:
- user_* levels are for the user, visible in the console and the log-file
- internal_* levels are for developers, visible in the log-file
- verbose_* levels are for debugging, only visible if the context of the output is activated

Usage in C++:
- orxout() << "message" << endl;
- orxout(level) << "message" << endl;
- orxout(level, context) << "message" << endl;

Usage in Lua:
- orxout("message")
- orxout(orxonox.level.levelname, "message")
- orxout(orxonox.level.levelname, "context", "message")

Usage in Tcl (and in the in-game-console):
- orxout levelname message
- orxout_context levelname context message
- shortcuts: log message, error message, warning message, status message, info message, debug message
Actually you find the levels and contexts in util/output/OutputDefinitions.h
Link: OutputDefinitions.h


Edit: COUT() is still defined, but deprecated.
Fabian 'x3n' Landau, Orxonox developer

Post Reply

Who is online

Users browsing this forum: No registered users and 3 guests