Logger api to Server Core?

[ScriptDevCenter]

hi,

i was switching through the code of the latest SVN (Server and Scripts) and have seen some really strange pieces of code:
as an example there is A LOT of blocks like

try
{
   . . . program . . .
}
catch
{
}

that (bad) practice has found the way into custom scripts already, since the existinging script code is/can/should be used as a "guide" on how to implement things.
exceptions are there for a reason. exceptions should not be swallowed like this.

i dont want to rise the finger without giving an alternative to that practice:
using logger and logging api's.

after searching a while, i found log4net as a wide featured customizeable (provides settings via xml, features like loglevel and several appenders for console logging, file logging etc are included) logging framework.

it can simply be used as e.g. a component in Server.Core.
there is a somehow hand written "logging api" already implemented in Core to log the commands used in game.
but there is no

Core.Logger.Debug("some debug information, printed if loglevel is set to 'debug'.");

useablility in the system. instead all (except the command logging) is done with

Console.WriteLine("some information, always ever printed.");

and then the console.out is set to write to file, or to the windows event log or stay as console output.

so i'd like to suggest providing a logging api from Core, that can be accessed everywhere to use it everywhere.

once it is included, the swallowed exceptions can be handled from

catch
{
}

to (info? or debug because was not mentioned before anyway.. but on some level say whats happened )

catch (Exception e)
{
       Core.Logger.Info("was swallowed first, so just for information", e);
}

the access is easy and can take place in the scripts / custom scripts as well using just
Core.Logger.[LEVEL]("log");
there are countless advantages using a logger api (easy exception propagation is just one), you can add or modify the "appender" by the config file to log to file AND console... eehm.. countless advantages



here are the steps taken to use the log4net framework (could be some other framework too.. just using some framework to give levelable logging to custom scripters from the "Core hand")

in Main.cs adding:

using System.Runtime;
using log4net;

[assembly: log4net.Config.XmlConfigurator(Watch = true)] // notice changes on the log config file while running
namespace Server
{
    public delegate void Slice();

    public static class Core
    {
        public static ILog Logger { get { return m_logger != null ? m_logger : (m_logger = LogManager.GetLogger("NameOfTheLogger")); } }

in Data\Assemblies.cfg adding:

System.Windows.Forms.dll
log4net.dll

last but not least, a configuration file for the logger (has to be named as the binary with ".config" extension e.g. RunUO.exe.config):

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
    <!-- Register a section handler for the log4net section -->
    <configSections>
        <section name="log4net" type="System.Configuration.IgnoreSectionHandler" />
    </configSections>
    <!-- This section contains the log4net configuration settings -->
    <log4net>
    <!-- Define some output appenders -->
    <appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
      <mapping>
        <level value="ERROR" />
        <foreColor value="White" />
        <backColor value="Red, HighIntensity" />
      </mapping>
      <mapping>
        <level value="DEBUG" />
        <backColor value="Green" />
      </mapping>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%-5level] [%location] - %message%newline" />
      </layout>
    </appender>
    <!-- Setup the root category, add the appenders and set the default level -->
    <root>
        <level value="INFO" />
        <appender-ref ref="ColoredConsoleAppender" />
    </root>
    </log4net>
</configuration>

links:
log4net home
some conversionPattern info

would be nice if this starts a discussion

greetings
scriptdevcenter

 

[Jeff]

try catching isnt bad practice, and in all cases there is a console write that happens. A better logger would just hook into the console, and output to a file. That way you don't have to do any editing. Log4Net is great for debugging, but I've moved away from it as it has some painful overhead. try catches are fine, as long as the catch handles the exception in a good manor... I would love for you to point out where you think we are doing this wrong so we can tell you why YOU are wrong, or.. fix it.

 

[ScriptDevCenter]

thank you for your reply, so we can discuss it

you are right, try catch isnt bad practice
but

catch
{
}

to dont mention there was something bad happened should be

and in all cases there is a console write that happens

that is not true. (SVN 665)
there are 3 places in main.cs (server) that do not handle the exception
there is one place in BaseArmor.cs (scripts) that do not handle the exception
there are at least 279 catches (in server and scripts), only a few of it handles the exception (i dont have checked it, but the feeling i have is that less than 25% of the catches log the exception or does special treatment)

why using a logging framework (self coded or existing api)

The main advantage of logging API over plain printf resides in its ability to disable certain log statements while allowing others to print unhindered. This capability assumes that the logging space, that is, the space of all possible logging statements, is categorized according to some developer-chosen criteria. It provides precise context about a run of the application. Once inserted into the code, the generation of logging output requires no human intervention. Moreover, log output can be saved in a persistent medium to be studied at a later time. In addition to its use in the development cycle, a sufficiently-rich logging package can also be viewed as an auditing tool. Logging does have its drawbacks. It can slow down an application. If too verbose, it can cause scrolling blindness.

(the statement is taken from Log4Cplus, page does not exist anymore but found it in the google cache) LINK
a logging api isnt just good for debugging, it is good to let the user decide (based on a config file) what level is to log and where the log have to go to (console, file, windows event log, etc.)
an api then can let the user decide how the logs are formated (suggar).

in production it may be useful to log only on error or warning level
you can have several logger (from the same self coded or existing api) to log commands (as already done) separate from e.g. internal program logic
each on its own level
so a production server could log:
commands ALL
program ERROR
for development you can set
commands ALL
program DEBUG
by changing the config

why using a dedicated logging framework instead of develop a logging mechanism on the own?
there is a wheel already invented, and in case of a program.. it is already community and/or unit tested. a public api is well documented, error prooven and provides updates / fixes that you dont have to worry about (with manpower on the own developed logging mechanism, that manpower is then free to be used on the core project)


i have tried to use one api to check how much work it would be to include it to the existing project.. it was log4net, could be any logging api.. just to have (or in the case of runuo dont have) a logging api is what i would like to discuss. the try catch was one point that i used as an example where it then could be really used.

 

[Jeff]

You are more then welcome to add this to your own project, but it wont be added to RunUO as it is not needed and we don't want the overhead.

Lets look at your claims however, you said in main.cs there are 3 places that do not have handled exceptions...However, in Main.cs there is only 1 catch statement

catch( Exception e )
{
   CurrentDomain_UnhandledException( null, new UnhandledExceptionEventArgs( e, true ) );
}

And it is being handled.

As for the other 279, point them out and we can discuss, catching and handling isnt always required... but fact of the matter is this, RunUO is VERY stable, and has been used in production by not only 4 UOGamers servers for over 9 years now, but by 1000's of free shard owners as well. Logging has never been an issue, all escensial crashes get dumped to a crash dump, and all network related issues dump to the network log... Over logging is an issue in so many API's, there have been several discussions by development communities regarding it and I'm a firm believer that over logging is a bad thing. I've worked for a company that wanted everything logged... and it slowed down their product so much (and it was log4net). My latest employer only logs whats necessary... and its great.

We can debate this all day long, and never come to a conclusion. My bottom line is that adding logging to a stable product, and especially to spots that you have pointed out is just unnecessary. However, that said, feel completely free to do as you please with your server.

 

[ScriptDevCenter]

You are more then welcome to add this to your own project, [...]

if i (or someone else) would do that, it takes away the possibilty to share the scripts because of using proprietary technologies. the point is to provide an api for a development standard (logging in application) from one (the base) hand, so it can be used without using techniques not supported by the core.

[...]Lets look at your claims however, you said in main.cs there are 3 places that do not have handled exceptions...However, in Main.cs there is only 1 catch statement

catch( Exception e )
{
   CurrentDomain_UnhandledException( null, new UnhandledExceptionEventArgs( e, true ) );
}

And it is being handled.
[...]

SVN 665, File Main.cs, Line 263
SVN 665, File Main.cs, Line 276

                    try
                     {
                         for( int i = 0; i <  m_MessagePump.Listeners.Length; i++ )
                         {
                             m_MessagePump.Listeners.Dispose();
                         }
                     }
                     catch
                     {
                     }

SVN 665, File Main.cs, Line 422

[...]we can discuss, catching and handling isnt always required[...]

so the whole try cach then is not required (on the places examples shown above)?

[...]RunUO is VERY stable, and has been used in production[...]

yes it is. but again the point is to provide an api for the community to beeing able to produce scalable logging to their custom additionals (Scripts) supported by core functionality (Server) without handcoding an api again and again for every addon.

[...]Over logging is an issue in so many API's[...]

yes, it can be an issue.. also as it can be an issue to dont say anything/having the possiblity to say anything at all (same extreme with the oposite sign).
print outs to the console (even if the the Console.SetOut(..) is pointing to a file) isnt scaleable / customizeable / levelable

[...]and it slowed down their product so much (and it was log4net)[...]

performance is an argument, right.. it could/should be used non excessive (i agree with you that overlogging is an issue.. to debug log every single line of code is overused.. but swallowing exceptions.. again for example is underused)
a good logging framework doesnt impact on performance if the log level is set above these trace logs.
it dont even have to be log4net (was an example to see how much work it would be to get an existing logging api to the core) to give the community the possibilty to scale their output as needed?

[...]it wont be added to RunUO as it is not needed and we don't want the overhead[...]

i dont hope the discussion ends here..

greetings

 

[Jeff]

All those spots you pointed out the try catch is required, but handling is not... with out the try catch, the app would crash, if for any reason an exception is thrown inside the try... we still want to continue, but its not anything we care about. I personally see no advantage in adding logging, so the discussion ends here for me. BTW, your who "using proprietary technology" comment is useless, thats what pre-processor directive and declarations are for... simple

#if LOG4NET
    log.WriteLine("blah");
#endif

Pretty common practice.

 

[ScriptDevCenter]

ah.. thats indeed a strategy..
wrapping the logger method signature in a seperate class (to dont have to write 3 lines instead of 1) that then can be provided with the scripts isnt much work. the scripts then can be still used by the community.
this fulfills both requrirements. thank you for that hint.

about the try catch swallow.. we maybe can discuss this in another thread.. it was used as the nail to hang up the logging picture

greetings