Difference between revisions of "Logging"

From wiki.visual-prolog.com

Line 15: Line 15:
  <LogConfigurations>
  <LogConfigurations>
<LogConfig name="ConfigName0">
<LogConfig name="ConfigName0">
<Appenders>
<Appenders>
<Appender name="AppenderName0">
<Appender name="AppenderName0">
<LogLevel>all</LogLevel>
<LogLevel>all</LogLevel>
<Type>console</Type>
<Type>console</Type>
<PatternLayout>%username: %thread - %msg</PatternLayout>
<PatternLayout>%username: %thread - %msg</PatternLayout>
</Appender>
</Appender>
</Appenders>
</Appenders>
</LogConfig>
</LogConfig>



Revision as of 14:36, 19 November 2015

Overview

Logging in Prolog currently supports logging to console, file, event log, database table, PDC notification log (to be done). Logging is thread safe and even supported for several processes that are writing to the same log. Application can also simultaneously log to several logs including logging to several files and/or database tables. Logging performance does not depend on log type. It is very fast operation and done asynchronously meaning that logging message placed into the message queue, which is processed in background thread.


Log configuration

Log configuration file (has .XML format) defines where applications logs the information. Here is the log configuration file example:

<?xml version="1.0" encoding="utf-8"?>
<LogConfigurations>

<LogConfig name="ConfigName0"> <Appenders> <Appender name="AppenderName0"> <LogLevel>all</LogLevel> <Type>console</Type> <PatternLayout>%username: %thread - %msg</PatternLayout> </Appender> </Appenders> </LogConfig>

<LogConfig name="ConfigName1">

<Appenders>

<Appender name="AppenderName1">

<LogLevel>all</LogLevel>

<Type>event</Type>

<Target>Helpdeskdashboard</Target>

<PatternLayout>\[%lineno\] %userid %proc:%thread %datetime %msg

                    </PatternLayout>

<filter>class:entityModel;method:aaa</filter>

</Appender>

<Appender name="AppenderName2">

<LogLevel>all</LogLevel>

<Type>file</Type>

<Target>log.txt</Target>

<PatternLayout>\[%lineno\] %userid(%username) \[%callerClassName/%callerPredicateName/%callerCursor\]%newline %proc:%thread time=%time dt=%datetime %msg(%msglevel)</PatternLayout>

<filter>class:entityModel;method:aaa</filter>

</Appender>

<Appender name="AppenderName3">

<LogLevel>all</LogLevel>

<Type>dbtable</Type>

<PatternLayout>%userid %proc:%thread %datetime %msg</PatternLayout>

<filter>class:entityModel;method:aaa</filter>

</Appender>

<Appender name="AppenderName4">

<LogLevel>all</LogLevel>

<Type>console</Type>

<PatternLayout>%userid %proc:%thread %datetime %msg</PatternLayout>

<filter>class:entityModel;method:aaa</filter>

</Appender>


</Appenders>

</LogConfig>

<LogConfig name="ODBCTable">

<Appenders>

<Appender name="AppenderName4">

<LogLevel>all</LogLevel>

<Type>odbcAsync</Type>

<Target>wwLogging</Target>

<ConnectionString>Driver=\{SQL Server\};Server=WEB1.dmz.hc\SQLEXPRESS;Database=Helpdesk_test;UID=xxx;PWD=yyy;app=HelpdeskDashboard</ConnectionString>

<ColumnInfo>

<Column name="level" attribute="msglevel"></Column>

<Column name="linenumber" attribute ="lineno"></Column>

<Column name="username" attribute ="username"></Column>

<Column name="userID" attribute ="userid"></Column>

<Column name="procid" attribute ="proc"></Column>

<Column name="thread" attribute ="thread"></Column>

<Column name="datetime" attribute ="datetime"></Column>

<Column name="time" attribute ="datetime"></Column>

<Column name="callerClassNameElem" attribute ="callerclassname"></Column>

<Column name="callerPredicateNameElem" attribute ="callerpredicatename"></Column>

<Column name="callerCursorElem" attribute ="callercursor"></Column>

<Column name="msg" attribute ="msg"></Column>

</ColumnInfo>

</Appender>

</Appenders>

</LogConfig>

<LogConfig name="DBTable">

<Appenders>

<Appender name="AppenderName5">

<Type>dbTableAsync</Type>

</Appender>

</Appenders>

</LogConfig>

<LogConfig name="PDCNotification">

<Appenders>

<Appender name="AppenderName6">

<Type>service</Type>

<PatternLayout>%thread - %msg</PatternLayout>

</Appender>

</Appenders>

</LogConfig>

</LogConfigurations>


Log configuration file may contain one or more named configurations:

<LogConfig name="ConfigName0">

...

</LogConfig>


Each configuration contains one or more appenders. Appender defines the log target and has the following parameters: LogLevel, Type, Target, PatternLayout, Filter, ConnectionString, ColumnInfo

<Loglevel> can be one of the following:

  • all
  • debug
  • info
  • warn
  • error
  • fatal
  • off


<Type> can be one of the following:

  • console logging to console
  • event logging to the event log
  • file or fileAsync logging to file synchronously or asynchronously
  • dbTable or dbTableAsync logging errors to the internal database synchronously or asynchronously
  • odbc or odbcAsync logging to the database synchronously or asynchronously
  • service logging to the PDC Notification log


<Target> defines where to log for every log <Type> and has the following values:

  • <EventSource> if logging to the event log. Event source is usually application name
  • <file name> if logging to a file (environment variable allowed, ex: %TEMP%\my.log).
  • if logging to the ODBC db.

    The <Target> parameter may be omitted for everything else.


    <PatternLayout> parameter defines message-formatting rules. It can contain the following keys:

    • %lineno Line number of logged message (starts from zero)
    • %userid user ID (unknown if not logged in)
    • %username user name (unknown if not logged in)
    • %proc Process ID
    • %thread Thread ID
    • %time Time stamp
    • %datetime Date/time stamp
    • %msg Message itself
    • %msglevel Message level
    • %newline New line
    • %callerClassName Caller class name
    • %callerPredicateName Caller predicate name
    • %callerCursor Caller module name with line/position values

    For example: <PatternLayout>%userid(%username) \[%callerClassName/%callerPredicateName/%callerCursor\]%newline %proc:%thread time=%time dt=%datetime %msg(%msglevel)</PatternLayout> Logged message (2 lines): 145(Test User) \[0x600260 "serviceLog"/anonymous$o0$1$setproc_name/2np$serviceLog/sourceCursor("tools\\dashboard\\common\\Service.pro", 14, 17)\]

    18244:4660 time=16:35:51.935 dt=2015/08/06 - 16:35:51.935 Call: workspace_GetDefaultDirContent(\{\})(debug)
    


    <Filter> defines what messages will be filtered out (excluded) from the log. It can contain zero or more class names and/or zero or more method names separated by semicolon: class:<class name>;method:<method name>

    For example: if filter is defined as following class:entityModel;method:getList all logging for class entityModel and method getList (no matter from which class) will be skipped.


    <ConnectionString> defines connection string for ODBC logging.

    <ColumnInfo> defines set of columns where to log some information. The Name attribute defines column name, the Attribute defines what to log. Attributes can have the same values described in <PatternLayout> section, except for skipped percentage sign (%) in the beginning.


    Notes:

    • Log configuration file can have more than one appender that logs to a file or database table. Of course, in this case file names/database table names should be different. For example, critical errors can be logged to separate file and/or database table.

    Activating pfc\log from command line

    To use log package it is enough to specify one of the command lines parameters:

    -LogConfig <Log Configuration File Name> <Configuration Name> For example: -LogConfig LogConfig.xml ConfigName1



    Using pfc\log programmatically

    ==Loading log configuration file ==

    Make the following calls: logConfig::loadConfig(ConfigFileName, ConfigName).


    Where: ConfigFileName: log configuration file; ConfigName: configuration name define in log configuration;

    If it is necessary to pass connection string (for db/odbc appenders) it is enough to enumerate activated appenders by name and set the connection string (in this example connection string is set for pfc\log\dbTable appender):

    LogAppenders = log::getAcivatedAppenders(@"pfc\log\dbTableAppender"), foreach LogAppender in LogAppenders do

       LogAppender:connectionString := db_connectionString
    

    end foreach



    == Logging messages==


    =

    Use log::write(level Level, ...) and/or log::writef(level Level, string Format \[formatString\], ...) predicates to log messages.

    For example: Log message "Start" with log level "all": log::write(log::all, "Start").

    Log fatal error using formatted log: log::writef(log::fatal, "SQL ERROR during startup: %", NativeMessage).


    Using log programmatically without log configuration file

    Here is an example of using ODBC appender: ===

           ODBC = odbcAppender::new(),	<-- constructor
           ODBC:loglevel := log::all, 		<-- log level
           ODBC:columninfo := \[tuple("username", "username"), tuple("msg", "msg")\], <-- column info (write 'username' to the 'username' column, write 'msg' to the 'msg' column,
           ODBC:connectionString := @"Driver=\{SQL Server\};Server=WEB1.dmz.hc\SQLEXPRESS;Database=Helpdesk_test;UID=leo;PWD=PdcPdcPdc1;app=HelpdeskDashboard",
           log::activateAppender(true, ODBC), <-- activate appender
           log::write(log::debug, "Example"),	<-- log
    


    List of ideas

    • For critical errors - when we want to call PDC notification log, then we do also need:

    %siteURL (URL of the service) %applicationName %projectName %programVersion %customerName %machineName

    I guess we should implement an expression is logging should be done, something like UserName in \["Leo","Alexander"\] and Time>17:00 or Level>info or Message %= "dfhj"

    - Where the Upper case names refer to the Variable.
    
    • Reload log configuration from UI (App settings/utility/etc.) \[DONE\]
    • PDC Notification Log: \[DONE\]

    - analyze;

    • Also I think there should be a state variable something like:

    Enablelogging_if User="Leo" and Message contains "login"

    Disablelogging_if User="Leo" and Message contains "logout"


    This is not precise; I just thought it is needed with a mechanism to start and stop logging based on logical condition...