Sign in to follow this  

Creating of logging system

This topic is 398 days old which is more than the 365 day threshold we allow for new replies. Please post a new topic.

If you intended to correct an error in the post then please contact us.

Recommended Posts

Hi,

During the journey called my new (d3d11) engine, I've encountered (and got feedback) on the usage of OutputDebugString.

I personally find it very handy during debugging, because I can see results right away.

 

But in release mode this won't bring anything.

So now I'm thinking about creating a logging system.

Basically a class which allows me to simply report text/ errors/ info etc. to a ASCII file (with a header that I'll include where needed).

I'm not sure yet how that would work with opening a filestream and when to close it, because calling the logging system would be from anywhere/ many different places (no in scope object everywhere).

 

With this I'm thinking of also adding the lines to the debugger output (OutputDebugString), so I have the best of both worlds.

Do you have any advice on this, or maybe best practices?

Share this post


Link to post
Share on other sites

I have build up a logging system for my engine framework too that is realy simple and leight weight. The main part was to make it multi-threaded by adding an internal queue for each of a number of previously set threads. Simple spin-lock lets threads add messages and and keeps the internal running publishing thread up from outputting waste.

 

This I have added a handler interface so that you were able to change the output method like to file or remote via UDP socket.

At least added a template function so that I'm possible to call something similar to C#'s string.Format when writing log messages. I think it is more simple than printf but thats a taste thing.

 

I have had doing this in less than 8 hours so it should also be very simple for you to do something similar if you decide to

Share this post


Link to post
Share on other sites
Thanks all.
I really like the simplicity of easylogging++ and will probably go for that one.

From a practical point of view, how do you quickly check the results in the output file when debugging? From that standpoint the VS debugger output directly stands out and is always visible. Are there any tricks, for example to show the logfile in a browser or other application that constantly refreshes?

Share this post


Link to post
Share on other sites

From a practical point of view, how do you quickly check the results in the output file when debugging? From that standpoint the VS debugger output directly stands out and is always visible. Are there any tricks, for example to show the logfile in a browser or other application that constantly refreshes?

VS will ask you if you want to reload a file whenever it's externally modified. However, your logger should have an option to write to a file and to whatever the native console/TTL output is, such as DebugOutputString, or even stdout. Other platforms will have their own equivalents to DebugOutputString, which may, for example, automatically send the data from a console devkit over a network to a system tray app on your dev PC.

Share this post


Link to post
Share on other sites

Thanks.

@Hodgman: sounds fancy, not sure if Easylogging++ supports that.

But ideally I want a lightweight solution which can output to 2 paths: a text file + debugger output (OutputDebugString).

If if only supports the 1st one, I can search for a simple tail program (like the suggested mTail).

Share this post


Link to post
Share on other sites

I've got Easlyogging++ up and running, works like a charm (lightweight and easy to use without lib's, just 1 include).

What I do encounter is a decision I have to make in the workflow:

 

- the logger outputs logging in a file, which can be read (and perhaps tailed in a tool like mTail)

- Visual Studio debugger output shows D3D info/warning/logging, VLD (visual leak detector) and other API feedback

 

How do you handle this situation in practice?

Do you keep an eye out on both 'streams',  or do you combine logging information for API's and your own framework?

 

My current view on this, is that it could work fine besides each other, because when something fails/ unexpected happens, you just have 2 sources to look for information. I personally think combining both will not bring enough, looking at the needed effort. The Easylogging++ API doesn't support outputting to the VS debugger output, unless I redirect stdout (which it does output) to the VS output debugger. Googling doesn't leed me to an easy solution of doing this.

Share this post


Link to post
Share on other sites

Do you keep an eye out on both 'streams', or do you combine logging information for API's and your own framework?

 

It can be valuable to have the (time) order in which all operations occurred. This is mainly true in a multithreading, and/or networking environment.

Share this post


Link to post
Share on other sites

In an ideal world, APIs wouldn't produce any logging output without you having the ability to configure it.

 

In the real world where APIs don't respect that, redirecting stdout and stderr is standard (and UNIX fans may argue that is in fact the preferred method).

 

If you can easily get everything in one file, and those files aren't too big to work with, do so. If not, have multiple files.

Share this post


Link to post
Share on other sites

Would you combine logging for your own framework/engine and the API's/VSdebugger output?

 

My preference is to have those outputs active at the same time. In your case were you are using Easlyogging++, you can just add OutputDebugString in their code right next to where it prints it out.

 

As a bonus, you could add an option for command line (or ini file) to turn outputs off. This way, you can disable file out, but keep VC++ output or vice versa. It's a nice to have but strictly not necessary.

 

Making a game is hard. Speaking from personal experienced, it is easy to get sidetracked and spend time on that sort of things. Stay focus and stay on track :)

Share this post


Link to post
Share on other sites

For who's interested/ reuse, I've been playing around with Easylogging++ and with a minor tweak (read further on) it does the following for me:

 

Debug:

- outputs LOG(INFO), LOG(ERROR) and LOG(DEBUG) to both the filestream and the VS debugger output

-- the VS debugger output reacts on the configuration parameter: "TO_STANDARD_OUTPUT"

 

Release:

- outputs only LOG(INFO) and LOG(ERROR) to only the filestream

 

You also have the easy possibility to create own 'loggers' / aka identifying your own systems in the logging output.

This is the only tweak you have to do in the Easylogging++ header:

// ORIGINAL

                    if (m_data->logMessage()->logger()->m_typedConfigurations->toStandardOutput(m_data->logMessage()->level())) 
					{
						if (ELPP->hasFlag(LoggingFlag::ColoredTerminalOutput))
							m_data->logMessage()->logger()->logBuilder()->convertToColoredOutput(&logLine, m_data->logMessage()->level());
						
						ELPP_COUT << ELPP_COUT_LINE(logLine);
                    }

// TWEAKED

                    if (m_data->logMessage()->logger()->m_typedConfigurations->toStandardOutput(m_data->logMessage()->level())) 
					{
						if (ELPP->hasFlag(LoggingFlag::ColoredTerminalOutput))
							m_data->logMessage()->logger()->logBuilder()->convertToColoredOutput(&logLine, m_data->logMessage()->level());
						
						ELPP_COUT << ELPP_COUT_LINE(logLine);
						#ifdef _DEBUG
						OutputDebugStringA(logLine.c_str());
						#endif
                    }

With the example code:

#define  ELPP_NO_DEFAULT_LOG_FILE 
#define _ELPP_THREAD_SAFE

#include "easylogging++.h"

INITIALIZE_EASYLOGGINGPP

int WINAPI WinMain(HINSTANCE hInstance,
                   HINSTANCE hPrevInstance,
                   LPSTR lpCmdLine,
                   int nCmdShow)
{
	// register new logger
	el::Logger* rendererLogger = el::Loggers::getLogger("Renderer");
	if(rendererLogger == nullptr) { } // handle error here
	
	// Load configuration from file
    el::Configurations conf("mylog.conf");
    // Reconfigure single logger
    el::Loggers::reconfigureLogger("default", conf);
    // Actually reconfigure all loggers instead
    el::Loggers::reconfigureAllLoggers(conf);
    // Now all the loggers will use configuration from file

	
	LOG(DEBUG) << "My first debug log line!";
	CLOG(INFO, "Renderer") << "My first info log line!";
	LOG(ERROR) << "My first error log line!";

    return 1;
}

And config file:

* GLOBAL:
   FORMAT               =  "%datetime [%level] [%logger] %msg"
   FILENAME             =  "logs/your.log"
   ENABLED              =  true
   TO_FILE              =  true
   TO_STANDARD_OUTPUT   =  true
   MILLISECONDS_WIDTH   =  2
   PERFORMANCE_TRACKING =  true
   MAX_LOG_FILE_SIZE    =  2097152 ## 2MB - Comment starts with two hashes (##)
   LOG_FLUSH_THRESHOLD  =  100 ## Flush after every 100 logs
* DEBUG:
   FORMAT               =  "%datetime [%level] [%logger] %msg File:%fbase,Line:%line,Func:%func"

Sample output:

2016-11-10 21:00:17,12 [DEBUG] [default] My first debug log line! File:main.cpp,Line:30,Func:int __stdcall WinMain(struct HINSTANCE__ *,struct HINSTANCE__ *,char *,int)
2016-11-10 21:00:17,13 [INFO ] [Renderer] My first info log line!
2016-11-10 21:00:17,14 [ERROR] [default] My first error log line!

All in all, a nice and flexible solution with gives be best of both worlds (which in this case I was looking for).

Share this post


Link to post
Share on other sites

This topic is 398 days old which is more than the 365 day threshold we allow for new replies. Please post a new topic.

If you intended to correct an error in the post then please contact us.

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now

Sign in to follow this