Implementing: LogWrite()

[Scatman]

I've committed two new files (Log.h and Log.cpp) to SVN. This is the new proposed logging system I'd like to propose. If any of you are interested, please review these files. John and I have been talking and before we do anything with this, we'd like to get input/additions/whatever from you other developers.

This will be integrated into a log.ini (or something similar) to parse so server admins can specify their own default values. But I'd like to discuss a hard coded set of default values. That way, if a value is not found in the log.ini file, the hard coded defaults will take over.

Also, we need to construct a list of log types (spell casting, quests, etc but more detailed). Note: These two files are NOT integrated into the project file so please don't add them yet. If you want, write your own test driver if you want to play around with it locally.

[Scatman]

I love using the same verbs in a single sentence. I don't feel like editing it tho so DEAL WIT ETT

[John Adams]

Let me just start by saying thank you, Scat, for starting us out, and the rest of you for following in and having an interest in better logging! Yay!

My first suggestion is to "invent" the definitions of at least a few main log types. Here is a logtypes.h from the EVEmulator that shows one concept of how we might do this:

Code: Select all

/*
	------------------------------------------------------------------------------------
	LICENSE:
	------------------------------------------------------------------------------------
	This file is part of EVEmu: EVE Online Server Emulator
	Copyright 2006 - 2008 The EVEmu Team
	For the latest information visit http://evemu.mmoforge.org
	------------------------------------------------------------------------------------
	This program is free software; you can redistribute it and/or modify it under
	the terms of the GNU Lesser General Public License as published by the Free Software
	Foundation; either version 2 of the License, or (at your option) any later
	version.

	This program is distributed in the hope that it will be useful, but WITHOUT
	ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
	FOR A PARTICULAR PURPOSE. See the GNU Lesser General Public License for more details.

	You should have received a copy of the GNU Lesser General Public License along with
	this program; if not, write to the Free Software Foundation, Inc., 59 Temple
	Place - Suite 330, Boston, MA 02111-1307, USA, or go to
	http://www.gnu.org/copyleft/lesser.txt.
	------------------------------------------------------------------------------------
	Author:		Zhur
*/

#ifndef LOG_CATEGORY
#define LOG_CATEGORY(name)
#endif
#ifndef LOG_TYPE
#define LOG_TYPE(cat, type, default_value, str)
#endif
#ifndef ENABLED
#define ENABLED true
#endif
#ifndef DISABLED
#define DISABLED false
#endif

/*                                                                              
 * Recommended log level names/ordering:
 *  fatal error
 *  error
 *  warning
 *  debug
 *  success
 *  trace
 *
*/

LOG_CATEGORY( NET )
LOG_TYPE( NET, PRES_ERROR, ENABLED, "PresError" )
LOG_TYPE( NET, PRES_DEBUG, DISABLED, "PresDebug" )
LOG_TYPE( NET, PRES_TRACE, DISABLED, "PresTrace" )
LOG_TYPE( NET, PRES_REP, DISABLED, "PresRep" )
LOG_TYPE( NET, PRES_RAW, DISABLED, "PresRaw" )
LOG_TYPE( NET, PRES_REP_OUT, DISABLED, "PresOut" )
LOG_TYPE( NET, PRES_RAW_OUT, DISABLED, "RawOut" )
LOG_TYPE( NET, MARSHAL_ERROR, ENABLED, "MarshalError" )
LOG_TYPE( NET, MARSHAL_TRACE, DISABLED, "MarshalTrace" )
LOG_TYPE( NET, UNMARSHAL_TRACE, DISABLED, "UnmarshalTrace" )
LOG_TYPE( NET, UNMARSHAL_BUFHEX, DISABLED, "UnmarshalHex" )
LOG_TYPE( NET, UNMARSHAL_ERROR, ENABLED, "UnmarshalError" )
LOG_TYPE( NET, ZEROINFL, DISABLED, "0Inflate" )
LOG_TYPE( NET, ZEROCOMP, DISABLED, "0Compress" )
LOG_TYPE( NET, PACKET_ERROR, ENABLED, "PacketError" )
LOG_TYPE( NET, PACKET_WARNING, DISABLED, "PacketWarning" )
LOG_TYPE( NET, DISPATCH_ERROR, ENABLED, "NetDispatch" )

LOG_CATEGORY( COLLECT )
LOG_TYPE( COLLECT, MESSAGE, DISABLED, "Message" )
LOG_TYPE( COLLECT, ERROR, ENABLED, "Error" )
LOG_TYPE( COLLECT, ERROR_DETAIL, ENABLED, "ErrorDetail" )
LOG_TYPE( COLLECT, TCP, DISABLED, "TCP" )
LOG_TYPE( COLLECT, RAW_HEX, DISABLED, "RawHex" )
LOG_TYPE( COLLECT, PYREP_DUMP, DISABLED, "PyRep" )
LOG_TYPE( COLLECT, PACKET_DUMP, DISABLED, "PacketDump" )
LOG_TYPE( COLLECT, PACKET_SRC, DISABLED, "PacketSrc" )
LOG_TYPE( COLLECT, PACKET_DEST, DISABLED, "PacketDest" )
LOG_TYPE( COLLECT, CALL_SUMMARY, ENABLED, "CallSummary" )
LOG_TYPE( COLLECT, DESTINY, DISABLED, "Destiny" )
LOG_TYPE( COLLECT, DESTINY_REP, DISABLED, "Destiny" )
LOG_TYPE( COLLECT, DESTINY_HEX, DISABLED, "Destiny" )
LOG_TYPE( COLLECT, CALL_DUMP, DISABLED, "CallDump" )
LOG_TYPE( COLLECT, NOTIFY_SUMMARY, DISABLED, "NotifySummary" )
LOG_TYPE( COLLECT, NOTIFY_DUMP, DISABLED, "NotifyDump" )
LOG_TYPE( COLLECT, OTHER_DUMP, DISABLED, "OtherDump" )
LOG_TYPE( COLLECT, CALL_XML, DISABLED, "CallReqXML" )
LOG_TYPE( COLLECT, CALLRSP_XML, DISABLED, "CallRspXML" )
LOG_TYPE( COLLECT, NOTIFY_XML, DISABLED, "NotifyXML" )
LOG_TYPE( COLLECT, MISC_XML, DISABLED, "MiscXML" )
LOG_TYPE( COLLECT, CALLRSP_SQL, DISABLED, "CallRspSQL" )

LOG_CATEGORY( SERVICE )
LOG_TYPE( SERVICE, ERROR, ENABLED, "SvcError" )
LOG_TYPE( SERVICE, WARNING, DISABLED, "SvcWarning" )
LOG_TYPE( SERVICE, CALLS, DISABLED, "SvcCall" )
LOG_TYPE( SERVICE, MESSAGE, DISABLED, "SvcMessage" )
LOG_TYPE( SERVICE, CACHE, DISABLED, "SvcCache" )
LOG_TYPE( SERVICE, CACHE_DUMP, DISABLED, "SvcCache" )
LOG_TYPE( SERVICE, CALL_TRACE, DISABLED, "SvcCallTrace" )

LOG_CATEGORY( SPAWN )
LOG_TYPE( SPAWN, ERROR,   ENABLED, "Error" )
LOG_TYPE( SPAWN, WARNING, DISABLED, "Warning" )
LOG_TYPE( SPAWN, MESSAGE, DISABLED, "Message" )
LOG_TYPE( SPAWN, POP, DISABLED, "SpawnPop" )
LOG_TYPE( SPAWN, DEPOP, DISABLED, "SpawnDepop" )

LOG_CATEGORY( ITEM )
LOG_TYPE( ITEM, ERROR,   ENABLED, "Error" )
LOG_TYPE( ITEM, WARNING, DISABLED, "Warning" )
LOG_TYPE( ITEM, MESSAGE, DISABLED, "Message" )
LOG_TYPE( ITEM, DEBUG, DISABLED, "Debug" )
LOG_TYPE( ITEM, TRACE, DISABLED, "Trace" )

LOG_CATEGORY( NPC )
LOG_TYPE( NPC, ERROR,   ENABLED, "Error" )
LOG_TYPE( NPC, WARNING, DISABLED, "Warning" )
LOG_TYPE( NPC, MESSAGE, DISABLED, "Message" )
LOG_TYPE( NPC, TRACE, DISABLED, "Trace" )
LOG_TYPE( NPC, AI_TRACE, DISABLED, "AITrace" )

LOG_CATEGORY( AGENT )
LOG_TYPE( AGENT, ERROR,   ENABLED, "Error" )
LOG_TYPE( AGENT, WARNING, DISABLED, "Warning" )
LOG_TYPE( AGENT, MESSAGE, DISABLED, "Message" )
LOG_TYPE( AGENT, TRACE, DISABLED, "Trace" )

LOG_CATEGORY( MARKET )
LOG_TYPE( MARKET, ERROR,   ENABLED, "Error" )
LOG_TYPE( MARKET, WARNING, DISABLED, "Warning" )
LOG_TYPE( MARKET, MESSAGE, DISABLED, "Message" )
LOG_TYPE( MARKET, DEBUG, DISABLED, "Debug" )
LOG_TYPE( MARKET, TRACE, DISABLED, "Trace" )

LOG_CATEGORY( MINING )
LOG_TYPE( MINING, ERROR,   ENABLED, "Error" )
LOG_TYPE( MINING, WARNING, DISABLED, "Warning" )
LOG_TYPE( MINING, MESSAGE, DISABLED, "Message" )
LOG_TYPE( MINING, DEBUG, DISABLED, "Debug" )
LOG_TYPE( MINING, TRACE, DISABLED, "Trace" )

LOG_CATEGORY( DESTINY )
LOG_TYPE( DESTINY, ERROR,   ENABLED, "Error" )
LOG_TYPE( DESTINY, WARNING, DISABLED, "Warning" )
LOG_TYPE( DESTINY, MESSAGE, DISABLED, "Message" )
LOG_TYPE( DESTINY, DEBUG, DISABLED, "Debug" )
LOG_TYPE( DESTINY, TRACE, DISABLED, "Trace" )
LOG_TYPE( DESTINY, BUBBLE_DEBUG, DISABLED, "BubbleDebug" )
LOG_TYPE( DESTINY, BUBBLE_TRACE, DISABLED, "BubbleTrace" )
LOG_TYPE( DESTINY, UPDATES, DISABLED, "Update" )

LOG_CATEGORY( PHYSICS )
LOG_TYPE( PHYSICS, ERROR, ENABLED, "PhysicsError" )
LOG_TYPE( PHYSICS, MESSAGE, DISABLED, "PhysicsMessage" )
LOG_TYPE( PHYSICS, TRACE, DISABLED, "Physics" )
LOG_TYPE( PHYSICS, TRACEPOS, DISABLED, "Physics" )

LOG_CATEGORY( COMMON )
LOG_TYPE( COMMON, ERROR,   ENABLED, "Error" )
LOG_TYPE( COMMON, WARNING, DISABLED, "Warning" )
LOG_TYPE( COMMON, MESSAGE, DISABLED, "Message" )
LOG_TYPE( COMMON, THREADS, DISABLED, "Threads" )
LOG_TYPE( COMMON, PYREP, DISABLED, "PyRep" )

LOG_CATEGORY( SERVER )
LOG_TYPE( SERVER, INIT_ERR, ENABLED, "ServerInitError" )
LOG_TYPE( SERVER, INIT, DISABLED, "ServerInit" )
LOG_TYPE( SERVER, CLIENTS, DISABLED, "ServerClients" )
LOG_TYPE( SERVER, SHUTDOWN, DISABLED, "ServerShutdown" )

LOG_CATEGORY( COMMAND )
LOG_TYPE( COMMAND, ERROR, ENABLED, "CmdError" )
LOG_TYPE( COMMAND, MESSAGE, DISABLED, "Cmd" )

LOG_CATEGORY( SHIP )
LOG_TYPE( SHIP, ERROR, ENABLED, "CmdError" )
LOG_TYPE( SHIP, MODULE_TRACE, DISABLED, "ModTrace" )
LOG_TYPE( SHIP, MODULE_AGGREGATE, DISABLED, "ModAgg" )

LOG_CATEGORY( TARGET )
LOG_TYPE( TARGET, ERROR, ENABLED, "TargetError" )
LOG_TYPE( TARGET, DEBUG, DISABLED, "TargetTrace" )
LOG_TYPE( TARGET, TRACE, DISABLED, "TargetTrace" )

LOG_CATEGORY( LSC )
LOG_TYPE( LSC, ERROR, ENABLED, "LSCError" )
LOG_TYPE( LSC, MESSAGE, DISABLED, "LSC" )
LOG_TYPE( LSC, CHANNELS, DISABLED, "LSCChan" )

LOG_CATEGORY( CLIENT )
LOG_TYPE( CLIENT, ERROR, ENABLED, "ClientError" )
LOG_TYPE( CLIENT, MESSAGE, DISABLED, "ClientMessage" )
LOG_TYPE( CLIENT, CALL_REP, DISABLED, "ClientCallRep" )
LOG_TYPE( CLIENT, CALL_DUMP, DISABLED, "ClientCallDump" )
LOG_TYPE( CLIENT, IN_ALL, DISABLED, "InAll" )
LOG_TYPE( CLIENT, NOTIFY_REP, DISABLED, "NotifyRep" )
LOG_TYPE( CLIENT, NOTIFY_DUMP, DISABLED, "NotifyDump" )
LOG_TYPE( CLIENT, SESSION, DISABLED, "Session" )
LOG_TYPE( CLIENT, TRACE, DISABLED, "Trace" )
LOG_TYPE( CLIENT, TEXT, DISABLED, "ClientText" )

LOG_CATEGORY( CCLIENT )
LOG_TYPE( CCLIENT, ERROR, ENABLED, "Error" )
LOG_TYPE( CCLIENT, INIT_ERR, ENABLED, "InitError" )
LOG_TYPE( CCLIENT, INIT, DISABLED, "Init" )
LOG_TYPE( CCLIENT, MESSAGE, DISABLED, "Message" )
LOG_TYPE( CCLIENT, CLIENTS, DISABLED, "Clients" )
LOG_TYPE( CCLIENT, SHUTDOWN, DISABLED, "Shutdown" )
LOG_TYPE( CCLIENT, IN_ALL_DUMP, DISABLED, "InAll" )
LOG_TYPE( CCLIENT, IN_DUMP, DISABLED, "In" )
LOG_TYPE( CCLIENT, OUT_ALL_DUMP, DISABLED, "OutAll" )
LOG_TYPE( CCLIENT, SESSION, DISABLED, "Session" )
LOG_TYPE( CCLIENT, BINDS, DISABLED, "Binds" )

LOG_CATEGORY( DATABASE )
LOG_TYPE( DATABASE, MESSAGE, DISABLED, "DBMessage" )
LOG_TYPE( DATABASE, ERROR, ENABLED, "DBError" )
LOG_TYPE( DATABASE, QUERIES, DISABLED, "DBQuery" )
LOG_TYPE( DATABASE, RESULTS, DISABLED, "DBResult" )
LOG_TYPE( DATABASE, ALL_ERRORS, ENABLED, "DBAllErrors" )
LOG_TYPE( DATABASE, PACKED, DISABLED, "DBPacked" )


#undef LOG_TYPE
#undef LOG_CATEGORY
#undef ENABLED
#undef DISABLED

Taking an entry apart:

Code: Select all

LOG_CATEGORY( DATABASE )

This is the Category - in the log.ini, it would be

Code: Select all

DATABASE=[off|on]

or

DATABASE__ERROR=[on|off]

Individual log types for the category:

Code: Select all

LOG_TYPE( DATABASE, MESSAGE, DISABLED, "DBMessage" )
LOG_TYPE( DATABASE, ERROR, ENABLED, "DBError" )
LOG_TYPE( DATABASE, QUERIES, DISABLED, "DBQuery" )
LOG_TYPE( DATABASE, RESULTS, DISABLED, "DBResult" )

...with ENABLED|DISABLED as a hard-coded DEFAULT value Scat is looking for.

LOG_TYPE( Category, Type, Default, Name) where "Name" would be what you see in the log itself.

Sample Log entry for a Database Error:

12:57:38 [DBError] _FunctionName(SourceFile.cpp:149): Failed to insert record {ErrorNo} {Query}

etc...

Btw, we can never have too much information in our logs... especially if we are offering a way to shut off a majority of logging.

To one thing Scat mentioned, about defaults.. even if someone put every category=OFF, there still has to be a category that is NOT configurable - merely something like the startup banner, and success/fail of connection to the LoginServer or something. Call it "Core" category, unconfigurable, or something like that.

[Zcoretri]

Don't really have anything to add at this point but, would like to help out and of course learn along the way

[John Adams]

I think the general plan for Scat and I is to get an "engine" built, show you guys how to code/convert log lines to it, and let you loose going through all the source and adding logging where appropriate.

Example, all our RunQuery (SQL) statements, many don't even have error trapping. So we'll need log lines written for DATABASE__MESSAGE (echo friendly messages from DB like "Success!"), DATABASE__ERROR (oops! something busted!), DATABASE__RESULTS (echo the results codes and rows effected?) and DATABASE__QUERY (echoes the query being executed)

Code sample:

Code: Select all

codelog(DATABASE__ERROR, "Error in query: %s", res.error.c_str());

etc... however, this is still just suggestions. Don't take my examples as gospel until I hate your ideas and override them with my own.

HAHA :/ j/k

[Scatman]

That format is exactly how my logging system is built EXCEPT it even has an additional param. So you can mix types with the type of error. For example, you can have a COMBAT_MELEE param. So whenever a melee combat occurs, you can output a message. BUT, now you can specify ERROR, DEBUG, or whatever. So you actually have two COMBAT_MELEE logs. One for error and one for debug. So you can turn off all error messages, or all debug messages, or you can just turn off COMBAT_MELEE all together (for error and debug).

LogWrite(ERROR, COMBAT_MELEE, "There's an error in the code for melee combat!");
LogWrite(DEBUG, COMBAT_MELEE, "Scatman just hit John in the face for 9billion damage, ouch!");

And of course the LogWrite is printf style, so you can use %s, %i, etc and additional parameters.

[Eradani]

my understanding:
- this is our usual chat log stuff
- since we're all devs, this includes code debugging kinds of msgs

something like:
LOG_CATEGORY( HARVEST)
LOG_TYPE(HARVEST, FAIL, ENABLED, "You failed to %s from the %s.")
LOG_TYPE(HARVEST, RARE, ENABLED, "You have received a rare!")
LOG_TYPE(HARVEST, SUCCESS, ENABLED, "You receive %d %s from the %s.")

would you then envision:
LOG_TYPE(HARVEST, SKILLUP, ENABLED, "You get better at %s (%d/%d).")
LOG_TYPE(TRADESKILL, SKILLUP, ENABLED, "You get better at %s (%d/%d).")
LOG_TYPE(COMBAT, SKILLUP, ENABLED, "You get better at %s (%d/%d).")
LOG_TYPE(GENERAL, SKILLUP, ENABLED, "You get better at %s (%d/%d).")

or just:
LOG_TYPE(SKILLS, SKILLUP, ENABLED, "You get better at %s (%d/%d).")

I wonder if I'm getting this right cause aren't the user's abilities to turn on/off chat log messages part of the client?

[John Adams]

Messaging happens on the server regardless of what happens on the client (or how would the server know how much to raise a skill?) We're talking about adding (MUCHO) additional logging to help with future development, so people can see exactly wtf is going on instead of the hex garble that is there now.

For your example, "Your" would be replaced by a value as if the server is telling us (via log) what's going on.

LOG_TYPE(HARVEST, SKILLUP, ENABLED, "PlayerSkillUp")

And the Console/Text Log would read:

[date/time] PlayerSkillUp: Eradani (char_id) raised <skill_name> <skill_id> from <old_value> to <new_value> (<max_value>).

or something similar to that.

This is not about log messages in the client or chat boxes at all, all server-side.

[John Adams]

Thought: That's not to say we could not echo this kind of logging to the Client (ie., like EQEmu's "subscription" concept, where you subscribe to a specific Category|Type message, and see it in the client). But that gets way heavy on Server/Client IO...

Tho Scat, let's consider it anyway shall we? It can always be off by default. Someone wants to turn it on (for like a remote Dev/GM) it might be helpful - like /lua_debug start|stop (then we can get rid of that old command, too )

[Eradani]

thx for clearing that up.
/spins head 360 degrees clockwise to get back on the right track

[Scatman]

Yep. We can send anything we want to from the server to the client. It's all a matter of error checking and sending the message.

[John Adams]

Scat, what about color coding?

red: error
yellow: warning
green: all cool
white: debug, info, system
etc...


The EVEmu and WoW emu's have this, while I think EQEmu still just does plain white.

[Eradani]

maybe a color separation between debug and (info, system)

[Scatman]

Sure. I can add that to the configs. What I'll do it use the exact #define CHANNEL_COLOR_* variables so you can make it whatever you want. But I'll make those the hard-coded defaults.

[John Adams]

Btw, Community folks...

The reason we're discussing this here instead of a private dev forum is because I'm hoping to get more than just the Core Dev teams involved in this project. It's simple, adding log lines, and with even basic C++ knowledge it will help more people get familiar with our server code. With that, maybe you'll feel more comfortable helping out with bigger tasks.

Consider this an EQ2Emu 101 exercise, and I hope some of you get involved.