Implementing: LogWrite()

[John Adams]

FYI, I meant the "cat_text" to eliminate the need for this kind of definition:

CHARACTER__XP
CHARACTER__SKILL
CHARACTER__SPELL
CHARACTER__QUEST
CHARACTER__ITEM
CHARACTER__ETC

Now, we simply need:

CHARACTER__INFO (or WARN, or ERROR, or DEBUG) and "CharacterXP" if you wanted to log a player getting XP. Or
CHARACTER__INFO (or WARN, or ERROR, or DEBUG) and "CharSkill" if you wanted to log a player skill changing, or being used.

Etc. Make sense?


BTW: you should always put the LOG__CATEGORY at least inside the "cat_text", otherwise you will not really know what system the log is relating to.

In other words, don't do LogWrite(WORLD__DEBUG, "test", "Here is my test"); because nowhere will you see that it is "WORLD__DEBUG" that is calling the entry.

And!!! if cat_text is blank? "" -- the logger will display the WORLD__INFO default tag in it's place.

[John Adams]

Interesting, I just found I could put macros, like __FUNCTION__ in the cat_text slot, and have the function name passed to the logger as a tag

LogWrite(ITEM__DETAIL, __FUNCTION__, "%s: max(id): %u", __FUNCTION__, atoul(row[0]));

Output:

12:55 T WorldDatabase::LoadNextUniqueItemID: WorldDatabase::LoadNextUniqueItemID: max(id): 8

I guess it is just a string, huh?

Tho I guess any chance of you guys using LogWrite() for debugging rather than printf() is a hopeless dream

[Scatman]

Yep. Just a string defined by the compiler. I'll never use any custom logging for local debugging (stuff that doesn't go in release commits) That's not against you, I just never have, never will. If there was a printf function called 'p', I'd used that instead so I could type less (Hmmm, what a good idea for a macro!).

But for anything that's staying in world, of course I'll use LogWrite. I think I added close to 10 gazillion LogWrites for collections (+/- a few).

[John Adams]

I think I added close to 10 gazillion LogWrites for collections (+/- a few).

Good boy!!!

[John Adams]

/necro

Part 1:
Scatman, tell me what you think of this enhancement. I know I mentioned it before, but can't find the stinking post :/

Currently, I have instructed you all to "wrap" your spammy loggers in defined EQDEBUG levels --

Code: Select all

#if EQDEBUG >= 5
  LogWrite(Something_That_Spams_the_Hell_Out_of__CONSOLE, "blah");
#endif

However, this is going to take up a SHIT LOAD of lines of code, and improperly ENDed #if's could spell disaster (I misplaced an #endif and spent 4 hours trying to figure out why something stopped working ).

Would it be a better idea to put the logger "level" in-line? Example:

LogWrite(NPC_AI__DEBUG, 1, "NPC_AI", "This is a level 1 log", params);
LogWrite(NPC_AI__DEBUG, 5, "NPC_AI", "This is a level 5 spammy log", params);
LogWrite(NPC_AI__DEBUG, 9, "NPC_AI", "This is a level 9 REALLY spammy log", params);

Then in the definitions for loggers, always default to 1, unless they are specifically overridden in the log_config.xml:

Code: Select all

<ConfigType Type="DEBUG" Level="5" Color="GreenBold" Enabled="False" Logs="3" />

This gives me contol over each and every logger, type by type to not only Enable the logger, set it to console/file, but now say AND LogWrite() with a level of 1 through 5 WILL get printed out, but 6 through 9 will not. Thus, no changing of EQDEBUG, no recompiling, no worrying about the Additional Options tags, etc.

• Nice-To-Have:
  We could even go so far as to say a Log definition is UNIQUE based on it's CAT__TYPE -and- LEVEL, so we could have more than one NPC_AI__DEBUG (level 1) and NPC_AI__DEBUG (level 5) configured, if we wanted to be that picky.

This is going more towards log4net concepts. Because in reviewing how LogWrites() are being done now, I think it's just going to be too much effort to #if wrap them, and too dangerous.

BUTT! The huge question I always ask:
If I put these loggers in various loops as Level = 9, even if they are turned off, they will call LogWrite() VERY frequently. How will this impact World Performance? Considering someday, this entire beast will be Logging... and knowing an #if ... #endif doesn't even get compiled in at all, right?

Gimme your best thoughts on this! Thanks.


Part 2:
To finish this system up (because it is imcomplete, aside from my enhancements ) is to add the ability to "subscribe" to loggers in-game, and route the output to a chat channel. We have File, Console, and "Client" currently unsupported.

What would it take to finish this up, and get these loggers to output to the client? And what restrictions should we enforce, so super spammy logging does not end up blowing a client to hell? Or, is that even an issue?


Part 3:
This is the biggun, that will probably require your coding expertise (the rest above I can probably handle).

But I need this log system "queued", because currently as loggers hit the LogWrite() and start over-writing each other, so the logs are literally useless once we turn on excessive debugging/details. While this is rare right now, some of the loggers I rely on simply cannot keep up with the current system.

Would this be easy? FIFO? Somethin?

[Scatman]

I will get back to you on this after work. Going through your post and quoting stuff is too much of a pain on my phone

[John Adams]

Haha, no worries. Just a side job that is relatively low-priority.... though the queuing would be nice because I'm reaching that point in logging again where it's getting re-damn-diculous

[John Adams]

It is that time once again for me to completely revamp the LogWrite() system. We have run into a number of problems with the current implementation. The main problem is we have finally hit a point where, if all logging is enabled (worst case scenario), the log entries start being sent to LogWrite() at the same microsecond and log entries get written in the middle of each other.

09:42:18 D Clie09:42:18 I Zone: Loading new Zone 'GreaterFaydark'nt: Client::Zone: Zoning player to coordinates x: -116.830002, y: -43.939999, z: -785.469971, heading: 0.000000 in zone 'GreaterFaydark'...

This has prevented us from adding adequate TRACE-level logging to try and find our deadlocks, as one example.

The other problem has been the sheer number of Loggers (preprocessors) defined, and my constant confusion when adding log writers as to what to categorize a logger under. I need more dynamics, and options to DEBUG things at different "log levels" for the same logger.


I've asked Scatman to implement Log Queuing (FIFO) so the logwrites are written to a queue, then processed in order they were received, instead of flying out the system all at once.

The second issue was resolved by my adding a Log Level to the function. This will give us the option to use a simple DEBUG logger for all things DEBUG, but set different "levels" of how much info we want. Ie., minimal DEBUG info is level 1, massive spam attack flood of DEBUG info is 9. This reduces the need for such defines as DETAILS or TRACE, etc... simplifying configs.

When the new system is in place, I can add the ton of logging I have planned to try and troubleshoot problems easier.


Any ideas you have, please feel free to add them here before we finish this revamp.

[John Adams]

Scatman was kind enough to give me "Log Queuing" so the logs should no longer stampede over each other. In the process, he has started re-writing how the log system functions to be majorly fast, and not reliant on the preprocessor definitions. We're still hashing out what the best config can be, but we're getting close.

Work-in-progress, so please do not start using the new LogWrite2() functions yet.

His current code is on SVN.

[Zcoretri]

I'm back! Looks like I didn't miss a whole lot. Look forward to the new LogWrite code.

[John Adams]

Hold on using LogWrite2().

Scat and I need to converse. Excellent work by him as usual, but I don't think I like the new options. Of course, you all know me

[Scatman]

Oh boy..

[John Adams]

Scat! Where arrrreeeeee yoouuuuuUUuuuuu?!

I have very little time to hash this out. My house guests are gone, jamfests are over, but I have only this weekend free in the foreseeable future to sit on IRC and work this out with you. Will you be available? If not, I'll just continue to use LogWrite() v1.0 until we can get together.

When you coming to AZ? I've had beer chillin for 4 mos!

[Scatman]

I just got back from a jamfest of my own! (listening, not playing ). I'll be available today, possibly wed, thur (all after 5:30pm est) and saturday morning to afternoon. You're telling me the new logging system isn't PURRRFECT and passes JA standards?

Our west coast trip was put off for the time being due to both schedule conflicts...what else is new

[John Adams]

I will try to be online at least on IRC, parked for the week. See if I can catch you. Been busier than a one-legged man in an ass-kicking contest lately myself.

While I loooooove your new logger ideas, I think I am failing to comprehend the new parameters. I can be re-trained, but they seem unclear, redundant. I'd almost like to just stick with our old preprocessor style, but queue the messaging like you have recently added.

Is that possible? I'd like to keep the LogWrite() commands as they are now.

Code: Select all

LogWrite(SCATMAN__WARNING, 0, "Logging, "Do what JA asks or heads will roll!!!");

I know you dislike the preprocessor setup. If the concat thing is a performance issue, let's talk about that. Because you know I am all about performance.