View more

View more

View more

### Image of the Day Submit

IOTD | Top Screenshots

### The latest, straight to your Inbox.

Subscribe to GameDev.net Direct to receive the latest updates and exclusive content.

# How to Log and stay Modular

Old topic!

Guest, the last post of this topic is over 60 days old and at this point you may not reply in this topic. If you wish to continue this conversation start a new topic.

56 replies to this topic

### #41Riztro  Members

Posted 10 September 2011 - 08:42 PM

Okay so it seems like just creating a function that logs stuff either to a file or to the console should be fine as it is the simplest and there is really no need for anything more that that. If I need something more, like a logger that sends stuff through the network then I could just take the log data and send it with a different thing. After all, I shouldn't make something that does everything.

### #42ApochPiQ  Moderators

Posted 11 September 2011 - 01:25 AM

How exactly are you going to provide a logging hook to a library by simply a free/static function?

The OP specifically asked how to do logging in a modular fashion. Discounting the utility of that requirement, at the very least you'll need some static variable that the user of the library can re-assign/populate.

Function pointers. Delegates. Whatever your language of choice supports. Doesn't matter.

I guess maybe Java is at a disadvantage here, but I did get the impression we're talking about C++, so function pointer it is. If you're fixated on passing an object, it can still be a static member function if absolutely necessary, but I still honestly don't see any benefit whatsoever to passing an object for this.

Or you have your logging itself be provided by a module (statically linked lib) by itself, which exposes a free function/set of free functions; this seems like the obvious choice to me, and indeed has long been my preference (and that of many programmers smarter than me with whom I have worked over the years).

And for the record, I didn't intend to refer to "overhead" in the sense of runtime cost; although there is some cost, it's probably negligible next to the cost of actually doing logging in the first place. My point isn't that free functions are preferable because they're "faster" or "more efficient" or some vacuous nonsense like that; it's about mental overhead.

Most of the time, you get something like this:

Logger log;
log.Write("Something happened!");

Oh boy! Now it takes two lines of code to do one thing.

Worse, we get suggestions like earlier in the thread. This is a pattern I have seen in actual code and it always makes me want to vomit:

#define LOG(x)    do { Logger log; log.Write(x); } while(false)

Now you have a macro to generate two lines of code to do one thing.

I repeat my former plea: someone please explain to me why this is considered a reasonable thing to do, ever.
Wielder of the Sacred Wands

### #43Telastyn  Members

Posted 11 September 2011 - 06:50 AM

How exactly are you going to provide a logging hook to a library by simply a free/static function?

The OP specifically asked how to do logging in a modular fashion. Discounting the utility of that requirement, at the very least you'll need some static variable that the user of the library can re-assign/populate.

Function pointers. Delegates. Whatever your language of choice supports. Doesn't matter.

Cool, just making sure that's what you meant.

### #44Antheus  Members

Posted 11 September 2011 - 08:12 AM

So, what's the final color of bike shed?

### #45Hodgman  Moderators

Posted 11 September 2011 - 08:28 AM

Most of the time, you get something like this:

Logger log;
log.Write("Something happened!");

Sorry, I've just jumped in at the end of the thread... but what is this?

log.Write is saying "write this line to this log output", right? Which means the constructor of Logger should take an argument that says what that output channel is, like Logger log("c:/foobar.txt"); ?

Without that constructor argument, then Logger is a monostate, which puts it in the same bucket as singletons and globals, but in the more-obscure-than-singleton corner!

So this particular example seems to be a complete straw-man, as it's conceptually identical to a free-function implementation, except with stupid monostate-syntax...
Do people really use monostate log implementations?
IMHO the point of using a log object would be in configuring it's output/destination via the constructor, like above, instead of having a global log output/destination.

...and in C++, the delegate-to-free-function being recommended could likely be implemented as an object...

### #46Cornstalks  Members

Posted 11 September 2011 - 08:51 AM

And for the record, I didn't intend to refer to "overhead" in the sense of runtime cost; although there is some cost, it's probably negligible next to the cost of actually doing logging in the first place. My point isn't that free functions are preferable because they're "faster" or "more efficient" or some vacuous nonsense like that; it's about mental overhead.

Ok, good. I was worried for a second. Although if you're getting mental overhead from creating a global logger object and using it, You're Doing It Wrong. It's not supposed to be tricky, complex, ugly, etc.

Most of the time, you get something like this:

Logger log;
log.Write("Something happened!");

I hope not. I'm not talking about creating a new Logger object whenever you want to log something. I'm talking about having a global Logger object that the one can access from anywhere and use to log.

This is a pattern I have seen in actual code and it always makes me want to vomit:

#define LOG(x)    do { Logger log; log.Write(x); } while(false)

I agree, whoever does that should be fired.

I repeat my former plea: someone please explain to me why this is considered a reasonable thing to do, ever.

Ever? Really? I'm in agreement with you 95% of the time. Most of the time you won't need anything more than some free function to do the logging. And in the OP's case, I think a free function will provide him with all the functionality he needs and it will a clean and great solution. But there are a few times where it's convenient to make a logger object that can store its state and encapsulate its information. For example, let's say you want to provide the user with the ability to choose where the log gets outputted to. It's easy and clean with an object, because you can simply do globalLogger = Logger("new/output/file.txt");, and none of the other code has to know that there was any kind of change at all. You can also tell the user where it's currently logging by simply doing globalLogger.getLogFilePath(), or something like that. The idea is that the data is encapsulated. You can provide this same kind of functionality with free functions, but IMHO using an object as a logger is a cleaner solution in this case because it keeps all the data encapsulated. And no, I wouldn't add any atrocious boiler plate code, like in your example. That'd just be ridiculous.

So, what's the final color of bike shed?

Neon pink witha neon green roof, why?
[ I was ninja'd 71 times before I stopped counting a long time ago ] [ f.k.a. MikeTacular ] [ My Blog ] [ SWFer: Gaplessly looped MP3s in your Flash games ]

### #47Antheus  Members

Posted 11 September 2011 - 09:02 AM

This is a pattern I have seen in actual code and it always makes me want to vomit:

#define LOG(x)    do { Logger log; log.Write(x); } while(false)

I agree, whoever does that should be fired.

Ever used std::clog or std::cout?

### #48Cornstalks  Members

Posted 11 September 2011 - 10:04 AM

This is a pattern I have seen in actual code and it always makes me want to vomit:

#define LOG(x)    do { Logger log; log.Write(x); } while(false)

I agree, whoever does that should be fired.

Ever used std::clog or std::cout?

Yeah, and I wish the industry would use and support them more. I'm not saying we should reinvent the wheel unnecessarily. Just discussing some options that can be used when a different wheel/tool is needed.
[ I was ninja'd 71 times before I stopped counting a long time ago ] [ f.k.a. MikeTacular ] [ My Blog ] [ SWFer: Gaplessly looped MP3s in your Flash games ]

### #49ApochPiQ  Moderators

Posted 11 September 2011 - 11:37 AM

Sure, if your logger needs to store state, then by all means use a lightweight object to do so; that's fine by me. (I'm skeptical that 99% of the loggers written would ever need to store any state, and that last 1% better be darn convincing, but I wouldn't rule it out entirely.)

What I'm arguing against is people who think they need state who simply don't. My monostate logger example is really just an extreme stripped-down version of what I see most people doing; they think there is state but there really isn't, and so their code boils down to a verbose version of what I flippantly dismissed as evil in my earlier post.

My preferred solution is to invert the relationship between the code doing the logging (call it the "client") and the logging system itself (call it the "provider"). Most solutions involve the client telling the provider where to log, etc. at the point of invocation (or nearby if you're using constructors and logging objects). To me this seems brittle; if you suddenly want all of your graphics-related logging to go to foo.txt instead of bar.txt, have fun updating your 500 constructor calls across the project!

Instead, I like to abstract the notion of a "channel" into a simple enum. Everything related to Foo goes into the Foo channel. There is also often a useful case where a severity can be attached; every Foo-related Error gets a channel of Foo and a severity of Error. Then, all call sites to the logging provider look the same: they provide a channel, a severity, and some content. Period. There is no need for state or other cruft; hence my tendency towards a simple free function.

The real power comes when you look at the provider itself. The obvious approach is to have your Log() function simply wrap std ostreams or whatever else. What gets interesting is when you make the Log() function just a dispatcher; all it does is forward the log request, possibly based on its channel and severity, to a "back end" implementation. The back end then takes care of doing the heavy lifting: writing to a network log, serializing to disk, printing something in the debugger if applicable, etc.

Last but not least, you write a couple of free functions for pushing and popping back ends onto a simple stack (only the topmost "active" back end is invoked by the provider dispatch layer). Add some RAII objects (which is totally legit!) to handle scope-controlled back end manipulation, and poof, you're done.

Now you have a system which minimizes mental overhead. If all you want to do is write to the logs, you write a single function call. If you want to change the log temporarily to reroute it, you create a single RAII wrapper on the stack. If you want to change the way all of your logging is handled across the program, which might be millions of lines of code, all you do is hook in a new provider back end at the appropriate point.

This gives you complete flexibility and control over all aspects of your logging, while pretty much ensuring that anything you want to do requires minimal effort.
Wielder of the Sacred Wands

### #50alnite  Members

Posted 11 September 2011 - 12:21 PM

Okay so it seems like just creating a function that logs stuff either to a file or to the console should be fine as it is the simplest and there is really no need for anything more that that. If I need something more, like a logger that sends stuff through the network then I could just take the log data and send it with a different thing. After all, I shouldn't make something that does everything.

Yes. Is the purpose of your log to keep track of your code path? Then the standard output should do just fine. std::cout, printf, or System.out.println, whatever fancies you the most.

If you want more complex behavior, such as sending it over to a network for further processing, then yes, you'd need more functionalities. Even in such cases, I advise you that you still do not need to make such complex objects that you pass around wherever you need logging.

### #51Antheus  Members

Posted 11 September 2011 - 02:23 PM

If you want more complex behavior

Something struck me recently. Many companies advertise: "... complex solutions..." I suppose simple solutions to complex problems don't sell. What I want is dead simple behavior that cannot be messed up, either now or somewhere far along the line.

Major thing that is painfully missing in such debates is what constitutes a "module". C++ only knows compilation unit and process.

If we define per-system logging, things become much clearer. If we want Physics, Input and Renderer systems to have modular logging, then each of these has its own. What does this mean? Several ways:
struct System {
public const char * LOG_SYSTEM_NAME = "System";
};
..
struct System {
Logger logger;
};

System::Logger logger = "System";
...
The thing we need in common is a tag unique to system which we append to logs. Logs are typically text files on disk. Tag must be immutable since it will outlive the process by far, so whatever can be done while the code is running is just the birth of a log.

It may seem like deciding upon this tag is the big challenge now, making sure it's unique, but the tag itself, its location and name will be implicitly determine by logical dependencies of the project itself. If suddenly Input wants to log as Renderer, there is something weird going on and in reverse - Input will never need access to Renderer log. If it does, we got emergent complexity of InputRenderer, which is more of a design issue to worry than how the log is stored.

And by implication - if all tags are stored in some global file, we succumb to the God Class or "#include <everywhere.h>" problem, where modularity was lost already - a single change in that file affects everything.
--------
Log aggregation needs to be addressed next. At simplest level each system logs to its own file. We might choose each run to create its own instance in which case filename needs to be stateful in system implementation. Something like:
Logger logger("SYSTEM", Date.now());

Problem of uniqueness now becomes an issue (the static/global/singleton problem). Maybe we add process or machine ID to that. Benefit of this - ability to directly store all logs.

A minor triviality that needs to be solved is how to initialize such system, we might want log location to be externally specified. Again, passing a Config struct or having command-line parser set some common fields works, but one can wrap this into full IoC design. As mentioned, IoC is most intrusive and may not enable third-party libraries to use it.
-------
Let's say our logging is not boring, and we track a bunch of stuff, user actions, transactions, etc... with goal of running ETL. The idea of logging straight to database might be tempting in this case and is often done for web services but it's just implementation detail. Typical stumbling blocks here will involve configuration parsing and sequential initialization (config comes from database but to talk to database we need to read config, or database connection may drop or database may become unresponsive).

With the last two issues we come back to state. Stateful loggers are hard and if they hiccup, the application stops.

For this reason we want whatever "tags" our loggers use to be immutable per some unique context (see process, etc.). This way, logging can continue without regard to state (database/file are state) and we can even make use of fragments.

Also, see various logging services provided by OS which prevent logs from overflowing, but useful logs might not be

Then there's fancy fast stuff, such as K/V database (redis, mongo, etc...) which may be good fit with stateless loggers but may be at odds with ETL. Dumb SQL table or flat files might still be simplest way.
-------
Q: "I know, I'll log as XML or HTML"
A: "Any time your application exits unexpectedly (the time you need logs most) the log will not be valid XML and HTML" Don't add complexity - XML/HTML are stateful - the depth and nesting need to be properly terminated which can only happen under ideal circumstances.

Q: "But good logging system will make debugging easy"
A: "No, it will never log the correct information, use debugger or printf, the data will be discarded after each run anyway"

Q: "So, which option is the best"
A: "Depends on goals and how pragmatical one is"

--------
PS: If logging, start each line/entry with date/time in standardized format: YYYYMMDDThhmmss.msecZ. The reason - they are naturally ordered and can be compared using any strcmp algorithm to produce correct ordering. It makes searching easy (str > "2009" && str < "2010") will return expected range using just about any text mangling tool.

### #52Cornstalks  Members

Posted 11 September 2011 - 02:47 PM

*snip*

My preferred solution is to invert the relationship between the code doing the logging (call it the "client") and the logging system itself (call it the "provider"). Most solutions involve the client telling the provider where to log, etc. at the point of invocation (or nearby if you're using constructors and logging objects). To me this seems brittle; if you suddenly want all of your graphics-related logging to go to foo.txt instead of bar.txt, have fun updating your 500 constructor calls across the project!

*snip*

I completely agree with the snipped out portions. The only problem I have with the one paragraph I've left in is the part about updating 500 constructor calls. The reason is: yes, a system designed like that is horrible in my opinion, and so it shouldn't exist in the first place. What I usually mean when it comes to logging systems with objects is essentially what you've described, except where each "channel" is a separate Logger object. Only one per channel. And they're global. So there's only one constructor for each channel (and there shouldn't be that many channels, and they should all be initialized in the same spot). That way, each Logger/Channel encapsulates whatever data it needs to store. And logging with the system is just a simple function call (via the channel logger's member method), something like globalSystemLog.Log("I'm logging this now"). Which is basically the same as a free function (someNamespace::log(LOG_SYSTEM, "I'm logging this now")), only the channel is now a global Logger object rather than an enum being passed to a global logging function.

*snip*

Yeah, I agree with you in pretty much every sense.
[ I was ninja'd 71 times before I stopped counting a long time ago ] [ f.k.a. MikeTacular ] [ My Blog ] [ SWFer: Gaplessly looped MP3s in your Flash games ]

### #53ApochPiQ  Moderators

Posted 11 September 2011 - 06:59 PM

I still don't see any benefit to using a global object over a free function. Of course I realize they're isomorphic at a certain point, that was never under contention; my dispute with people who use global objects is that there doesn't seem to actually be a reason to have an object to begin with!

You also better hope that nobody besides your logging system uses global objects, or you get a wonderful static order of initialization SNAFU and life is miserable.

A free function minimizes potential points of failure. It also provides a very clean, natural way to serialize log requests, which is essential in multithreaded systems. Nothing sucks like trying to unravel a log file that has three threads stomping on each others' output. Of course you technically can serialize requests made by multiple redundant logger objects, but it's more complex - more possible ways to get it wrong. Why subject yourself to that? Why not do the simplest thing that gets the job done?

I'm not just being argumentative for the hell of it, by the way. I genuinely do not understand the mentality of programmers who do not treat implementation complexity as their enemy.
Wielder of the Sacred Wands

### #54speciesUnknown  Members

Posted 11 September 2011 - 08:49 PM

The OP could have written a logging system many times over in the time this thread has taken. I think we have run into the bikeshed principle here.

OP: Use free functions. Forget modularity. Then get on with the real work, of which actual logging is probably a tiny fraction.
Don't thank me, thank the moon's gravitation pull! Post in My Journal and help me to not procrastinate!

### #55Riztro  Members

Posted 11 September 2011 - 09:10 PM

The OP could have written a logging system many times over in the time this thread has taken. I think we have run into the bikeshed principle here.

OP: Use free functions. Forget modularity. Then get on with the real work, of which actual logging is probably a tiny fraction.

Done.

### #56VReality  Members

Posted 12 September 2011 - 02:49 AM

Most solutions involve the client telling the provider where to log, etc. at the point of invocation (or nearby if you're using constructors and logging objects). To me this seems brittle; if you suddenly want all of your graphics-related logging to go to foo.txt instead of bar.txt, have fun updating your 500 constructor calls across the project!

Amen, brother. That seems like a poor design choice. (Or perhaps more accurately, it's "lack of design.")

Sure, if your logger needs to store state, then by all means use a lightweight object to do so; that's fine by me. (I'm skeptical that 99% of the loggers written would ever need to store any state, and that last 1% better be darn convincing, but I wouldn't rule it out entirely.)

Like I said,

The problem with logs in videogame development isn't that no one needs them, it's that they quickly become unusable as they get spammed by every system under development.

When you make a logging system on a full-team development project, within about ten minutes it's being spammed with so much diagnostic information that it becomes nearly useless. So then everyone decides that you shouldn't check in any code containing log calls unless there's a really good reason. Then it takes a good half an hour to an hour for it to become unusable again. Then you do code reviews and don't allow any log calls to be checked in unless there's a very good reason, and this time it takes a good week to a week and a half before you lose your diagnostic info in the noise.

The solution to that - er wait. I should say, A solution to that is to make logging locally configurable.

First, I would introduce logging channels. And I wouldn't use enums. I would allow any arbitrary string to identify a channel, so that at any point a developer could make up a new channel for their own purposes without touching logging system code.

Second, I would make a config file (not shared under revision control) that could optionally exist at a known location, in which they could put entries sending arbitrary channels to various destinations, e.g "AI" to be displayed in-game, "Memory Manager" to be saved to a file, "Network" to be sent to the debug console, etc.

All the systems under development would still post logs with simple calls to free functions which did not store any state. And the application, or logging system, or whatever, could optionally create a single logging system object with which to manipulate and store state, e.g. by loading and applying that config file, passing the object around and making configuration calls on it, etc. It seems right to have only a single instance, but there's no reason to make it global or to create it statically.

This gives users flexibility, freedom, and control, to log arbitrarily and to different destinations, and to see exactly the information they're interested in, without the noise. In other words, it makes logs usable. And it does so without the need to add objects or state to the actual logging interface used by the systems generating log calls.

Now, as written, just about none of the logging systems I've seen in use felt the need to store state...

But pretty much every logging system I've seen really needed to start storing state to avoid becoming instantly useless.

### #57ApochPiQ  Moderators

Posted 12 September 2011 - 01:32 PM

I think this is just a minor discrepancy in terminology. Sure, the process of logging and routing and viewing the logs taken as a whole has stateful components. I'm not disputing the utility of that.

The act of writing a single entry to a log does not, and should not IMO, involve state, and therefore encapsulation as an object is nonsensical.

Of course, my philosophy on logging generally boils down to "spam away, and use better log viewing tools."
Wielder of the Sacred Wands

Old topic!

Guest, the last post of this topic is over 60 days old and at this point you may not reply in this topic. If you wish to continue this conversation start a new topic.