Logging

All developers know about having to troubleshoot mysterious errors. No matter good design, design review, carefull implementation, code review, extensive unit test etc. then some bugs always slips through to test.

Online debuggers has become very effective the last 30 years, but often real world applications are so big and complex that it is practically impossible to step through the application in an online debugger.

So in all those cases it is still necessarry to log debug information as the applications runs.

And this is where the last 20 years logging frameworks have been replacing adhoc logging.

Example of problem:

package logging;

public class Test {
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        return res;
    }
    public static void main(String[] args) {
        System.out.println(fac(50));
    }
}

using System;

namespace Logging
{
    public class Test
    {
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            return res;
        }
        public static void Main(string[] args)
        {
            Console.WriteLine(Fac(50));
        }
    }
}

Imports System

Namespace Logging
    Public Class Test
        Public Shared Function Fac(n As Integer) As Integer
            Dim res As Integer
            If n <= 1 Then
                res = 1
            Else
                res = n * Fac(n - 1)
            End If
            Return res
        End Function
        Public Shared Sub Main(args As String())
            Console.WriteLine(Fac(50))
        End Sub
    End Class
End Namespace

To make it work integer overflow check need to be disabled.

<?php
class Test {
    public static function fac($n) {
        if($n <= 1) {
            $res = 1;
        } else {
            $res = $n * Test::fac($n - 1);
        }
        return (int)$res;
    }
}

echo Test::fac(50) . "\r\n";
?>

The example of a problem I chose is not really a problem in python. Python is so powerful that the 1:1 transalation to python:

def fac(n):
    if n <= 1:
        res = 1
    else:
        res = n * fac(n - 1)
    return res

print(fac(50))

actuall works. To get the same problem in Python one need to use the numpy package:

import numpy
numpy.warnings.simplefilter("ignore", RuntimeWarning)

def fac(n):
    if n <= 1:
        res = 1
    else:
        res = n * fac(n - 1)
    return res

print(fac(numpy.int32(50)))

program Problem;

function fac(n : integer) : integer;

var
  res : integer;

begin
  if n <= 1 then begin
    res := 1;
  end else begin
    res := n * fac(n - 1);
  end;
  fac := res;
end;

begin
  writeln(fac(50));
end.

(the experienced developer has of course already guessed that it is an overflow problem, but we will use this as an example)

Adhoc approach:

package logging.adhoc;

public class Test {
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        System.err.println("fac : n = " + n + " res = " + res);
        return res;
    }
    public static void main(String[] args) {
        System.out.println(fac(50));
    }
}

using System;

namespace Logging
{
    public class Test
    {
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            Console.Error.WriteLine("fac : n = " + n + " res = " + res);
            return res;
        }
        public static void Main(string[] args)
        {
            Console.WriteLine(Fac(50));
        }
    }
}

Imports System

Namespace Logging
    Public Class Test
        Public Shared Function Fac(n As Integer) As Integer
            Dim res As Integer
            If n <= 1 Then
                res = 1
            Else
                res = n * Fac(n - 1)
            End If
            Console.Error.WriteLine("fac : n = " & n & " res = " & res)
            Return res
        End Function
        Public Shared Sub Main(args As String())
            Console.WriteLine(Fac(50))
        End Sub
    End Class
End Namespace

<?php
$stderr = fopen('php://stderr', 'w');

class Test {
    public static function fac($n) {
        global $stderr;
        if($n <= 1) {
            $res = 1;
        } else {
            $res = $n * Test::fac($n - 1);
        }
        fwrite($stderr, 'fac : n = ' . $n . ' res = ' . $res . "\r\n");
        return (int)$res;
    }
}

echo Test::fac(50) . "\r\n";
?>

import numpy
numpy.warnings.simplefilter("ignore", RuntimeWarning)

def fac(n):
    if n <= 1:
        res = 1
    else:
        res = n * fac(n - 1)
    print('fac : n = %d res = %d' % (n, res))
    return res

print(fac(numpy.int32(50)))

program AdHoc;

function fac(n : integer) : integer;

var
  res : integer;

begin
  if n <= 1 then begin
    res := 1;
  end else begin
    res := n * fac(n - 1);
  end;
  writeln('fac : ', n, ' res = ', res);
  fac := res;
end;

begin
  writeln(fac(50));
end.

which produces output:

fac : n = 1 res = 1
fac : n = 2 res = 2
fac : n = 3 res = 6
fac : n = 4 res = 24
fac : n = 5 res = 120
fac : n = 6 res = 720
fac : n = 7 res = 5040
fac : n = 8 res = 40320
fac : n = 9 res = 362880
fac : n = 10 res = 3628800
fac : n = 11 res = 39916800
fac : n = 12 res = 479001600
fac : n = 13 res = 1932053504
fac : n = 14 res = 1278945280
fac : n = 15 res = 2004310016
fac : n = 16 res = 2004189184
fac : n = 17 res = -288522240
fac : n = 18 res = -898433024
fac : n = 19 res = 109641728
fac : n = 20 res = -2102132736
fac : n = 21 res = -1195114496
fac : n = 22 res = -522715136
fac : n = 23 res = 862453760
fac : n = 24 res = -775946240
fac : n = 25 res = 2076180480
fac : n = 26 res = -1853882368
fac : n = 27 res = 1484783616
fac : n = 28 res = -1375731712
fac : n = 29 res = -1241513984
fac : n = 30 res = 1409286144
fac : n = 31 res = 738197504
fac : n = 32 res = -2147483648
fac : n = 33 res = -2147483648
fac : n = 34 res = 0
fac : n = 35 res = 0
fac : n = 36 res = 0
fac : n = 37 res = 0
fac : n = 38 res = 0
fac : n = 39 res = 0
fac : n = 40 res = 0
fac : n = 41 res = 0
fac : n = 42 res = 0
fac : n = 43 res = 0
fac : n = 44 res = 0
fac : n = 45 res = 0
fac : n = 46 res = 0
fac : n = 47 res = 0
fac : n = 48 res = 0
fac : n = 49 res = 0
fac : n = 50 res = 0
0

It can be seen that the problem starts when going from n=13 to n=14 and the values make is rather obvious that it is an overflow problem.

So the adhoc method did solve the problem. But it does have serious problems:

Adding print statements all over when one have a problem and removing them again when the problem is solved is a huge task. And even the improved approach of just outcommenting when problem is solved and remove outcommenting when a new problem show up is way too much work.
The debug print may sometimes need to go to console and sometimes to a file depending on context.

Enhanced adhoc approach:

To solve these problems the next approach is to make:

print debug or not
where to print

easily configurable:

package logging.enhadhoc;

import java.io.PrintStream;

public class Logging {
    public static boolean log = false;
    public static PrintStream dbg = System.err;
}

and:

package logging.enhadhoc;

public class Test {
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(Logging.log) {
            Logging.dbg.println("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        Logging.log = true;
        Logging.dbg = System.err;
        System.out.println(fac(50));
    }
}

using System;
using System.IO;

namespace Logging
{
    public static class Logging
    {
        public static bool log = false;
        public static TextWriter dbg = Console.Error;
    }
    public class Test
    {
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            Console.Error.WriteLine("fac : n = " + n + " res = " + res);
            return res;
        }
        public static void Main(string[] args)
        {
            Logging.log = true;
            Logging.dbg = Console.Error;
            Console.WriteLine(Fac(50));
        }
    }
}

Imports System
Imports System.IO

Namespace Logging
    Public NotInheritable Class Logging
        Private Sub New()
        End Sub
        Public Shared log As Boolean = False
        Public Shared dbg As TextWriter = Console.Error
    End Class
    Public Class Test
        Public Shared Function Fac(n As Integer) As Integer
            Dim res As Integer
            If n <= 1 Then
                res = 1
            Else
                res = n * Fac(n - 1)
            End If
            Console.[Error].WriteLine("fac : n = " & n & " res = " & res)
            Return res
        End Function
        Public Shared Sub Main(args As String())
            Logging.log = True
            Logging.dbg = Console.Error
            Console.WriteLine(Fac(50))
        End Sub
    End Class
End Namespace

<?php
class Logging {
    public static $log = FALSE;
    public static $dbg;
}

class Test {
    public static function fac($n) {
        if($n <= 1) {
            $res = 1;
        } else {
            $res = $n * Test::fac($n - 1);
        }
        if(Logging::$log) {
            fwrite(Logging::$dbg, 'fac : n = ' . $n . ' res = ' . $res . "\r\n");
        }
        return (int)$res;
    }
}

Logging::$log = TRUE;
Logging::$dbg = fopen('php://stderr', 'w');
echo Test::fac(50) . "\r\n";
?>

import sys

import numpy
numpy.warnings.simplefilter("ignore", RuntimeWarning)

log = False
dbg = sys.stderr

def fac(n):
    if n <= 1:
        res = 1
    else:
        res = n * fac(n - 1)
    if log:
        # Python 2.x
        print >>dbg, 'fac : n = %d res = %d' % (n, res)
        # Python 3.x
        #print('fac : n = %d res = %d' % (n, res), file=dbg)
    return res

log = True
dbg = sys.stderr
print(fac(numpy.int32(50)))

program Enhanced;

var
  log : boolean;
  dbg : TextFile;

function fac(n : integer) : integer;

var
  res : integer;

begin
  if n <= 1 then begin
    res := 1;
  end else begin
    res := n * fac(n - 1);
  end;
  if log then begin
     writeln(dbg, 'fac : ', n, ' res = ', res);
  end;
  fac := res;
end;

begin
  log := true;
  dbg := output;
  writeln(fac(50));
end.

with no changes to output:

fac : n = 1 res = 1
fac : n = 2 res = 2
fac : n = 3 res = 6
fac : n = 4 res = 24
fac : n = 5 res = 120
fac : n = 6 res = 720
fac : n = 7 res = 5040
fac : n = 8 res = 40320
fac : n = 9 res = 362880
fac : n = 10 res = 3628800
fac : n = 11 res = 39916800
fac : n = 12 res = 479001600
fac : n = 13 res = 1932053504
fac : n = 14 res = 1278945280
fac : n = 15 res = 2004310016
fac : n = 16 res = 2004189184
fac : n = 17 res = -288522240
fac : n = 18 res = -898433024
fac : n = 19 res = 109641728
fac : n = 20 res = -2102132736
fac : n = 21 res = -1195114496
fac : n = 22 res = -522715136
fac : n = 23 res = 862453760
fac : n = 24 res = -775946240
fac : n = 25 res = 2076180480
fac : n = 26 res = -1853882368
fac : n = 27 res = 1484783616
fac : n = 28 res = -1375731712
fac : n = 29 res = -1241513984
fac : n = 30 res = 1409286144
fac : n = 31 res = 738197504
fac : n = 32 res = -2147483648
fac : n = 33 res = -2147483648
fac : n = 34 res = 0
fac : n = 35 res = 0
fac : n = 36 res = 0
fac : n = 37 res = 0
fac : n = 38 res = 0
fac : n = 39 res = 0
fac : n = 40 res = 0
fac : n = 41 res = 0
fac : n = 42 res = 0
fac : n = 43 res = 0
fac : n = 44 res = 0
fac : n = 45 res = 0
fac : n = 46 res = 0
fac : n = 47 res = 0
fac : n = 48 res = 0
fac : n = 49 res = 0
fac : n = 50 res = 0
0

This solves the problem it was intending to solve, but the solution is still not great:

one may want to do some logging instead of no logging or all logging
one may want to log to multiple destinations
one may need other types of log destinations
it is nice with a standard logging solution instead of multiple homegrown solutions

Solution - a logging framework:

So one really need a full feature logging framework.

Several such exists. And in the following we will look at some of the most common.

Most logging frameworks are very similar because they are all inspired by log4j.

Loggers are structured as a tree based on package/namespace. When you change settings for a logger node then changes also applies to all loggers below it unless explicit changed for those.

Loggers have methods to log:

logger.level_1(...);
...
logger.level_n(...);

and if log level is set to x then only log calls via logger.level_i where i >= x actually prints.

Log4j is the oldest logging framework for Java. In fact it is the oldest of the widely used logging frameworks and it has heavily inspired most other logging frameworks.

package logging.log4j;

import org.apache.log4j.Logger;

public class Test {
    private static final Logger log = Logger.getLogger(Test.class);
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(log.isDebugEnabled()) {
            log.debug("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

Configuration via properties file:

java -Dlog4j.configuration=file:///C:/work/log4j.properties ...

log4j.properties:

# logging.log4j.Test logger: minimum level=debug, two appenders (logfile + console)
log4j.category.logging.log4j.Test = debug, logfile, console
# console: minimum level=info, special format
log4j.appender.console.threshold = info
log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.appender.console.layout = org.apache.log4j.PatternLayout
log4j.appender.console.layout.ConversionPattern = %-30c %d %-5p %m%n
# logfile: minimum level=debug, file=test.log, special format
log4j.appender.logfile.threshold = debug
log4j.appender.logfile = org.apache.log4j.FileAppender
log4j.appender.logfile.file = /work/test.log
log4j.appender.logfile.layout = org.apache.log4j.PatternLayout
log4j.appender.logfile.layout.ConversionPattern = %-30c %d %-5p %m%n

Configuration via XML file:

java -Dlog4j.configuration=file:///C:/work/log4j.xml ...

log4j.xml:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
    <!--
      console: minimum level=info, special format
    -->
    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <param name="threshold" value="info"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
        </layout>
    </appender>
    <!--
      logfile: minimum level=debug, file=test.log, special format
    -->
    <appender name="logfile" class="org.apache.log4j.FileAppender">
        <param name="threshold" value="debug"/>
        <param name="file" value="/work/test.log"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
        </layout>
    </appender>
    <!--
      logging.log4j.Test logger: minimum level=debug, two appenders (logfile + console)
    -->
    <logger name="logging.log4j.Test">
        <level value="debug"/>
        <appender-ref ref="console"/>              
        <appender-ref ref="logfile"/>
    </logger>
</log4j:configuration>

Console output:

logging.log4j.Test             2016-11-15 21:23:16,786 INFO  Start
0
logging.log4j.Test             2016-11-15 21:23:16,796 INFO  End

test.log:

logging.log4j.Test             2016-11-15 21:23:16,786 INFO  Start
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 1 res = 1
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 2 res = 2
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 3 res = 6
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 4 res = 24
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 5 res = 120
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 6 res = 720
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 7 res = 5040
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 8 res = 40320
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 9 res = 362880
logging.log4j.Test             2016-11-15 21:23:16,794 DEBUG fac : n = 10 res = 3628800
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 11 res = 39916800
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 12 res = 479001600
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 13 res = 1932053504
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 14 res = 1278945280
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 15 res = 2004310016
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 16 res = 2004189184
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 17 res = -288522240
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 18 res = -898433024
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 19 res = 109641728
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 20 res = -2102132736
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 21 res = -1195114496
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 22 res = -522715136
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 23 res = 862453760
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 24 res = -775946240
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 25 res = 2076180480
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 26 res = -1853882368
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 27 res = 1484783616
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 28 res = -1375731712
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 29 res = -1241513984
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 30 res = 1409286144
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 31 res = 738197504
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 32 res = -2147483648
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 33 res = -2147483648
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 34 res = 0
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 35 res = 0
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 36 res = 0
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 37 res = 0
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 38 res = 0
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 39 res = 0
logging.log4j.Test             2016-11-15 21:23:16,795 DEBUG fac : n = 40 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 41 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 42 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 43 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 44 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 45 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 46 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 47 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 48 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 49 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 DEBUG fac : n = 50 res = 0
logging.log4j.Test             2016-11-15 21:23:16,796 INFO  End

If you wonder why the if statement in:

        if(log.isDebugEnabled()) {
            log.debug("fac : n = " + n + " res = " + res);
        }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

Log4j has a long list of appenders for various destinations:

ConsoleAppender: standard output or error
FileAppender: disk file
DailyRollingFileAppender: disk file with new file at specified interval (like every midnight)
JDBCAppender: database
JMSAppender: message queue
SMPTPAppender: email
SyslogAppender: *nix syslog
NTEventLogAppender: Windows event log

JUL (java.util.logging or Java 1.4 logging) is a sligtly simpler logging framework that got added to Java SE in version 1.4.

package logging.jul;

import java.util.logging.Level;
import java.util.logging.Logger;

public class Test {
    private static final Logger log = Logger.getLogger(Test.class.getTypeName());
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(log.isLoggable(Level.FINE)) {
            log.fine("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

Configuration:

java -Djava.util.logging.config.file=/work/jul.properties ...

jul.properties:

# logging.jul.Test logger: minimum level=fine, two handlers (console + logfile)
logging.jul.Test.level = FINE
handlers = java.util.logging.ConsoleHandler, java.util.logging.FileHandler
# console: minimum level=info
java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
# logfile: minimum level=fine, file=test.log
java.util.logging.FileHandler.level = FINE
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
java.util.logging.FileHandler.pattern = /work/test.log
# format - requires Java 7+
java.util.logging.SimpleFormatter.format=%2$-30s %1$tc %4$-7s %5$s %n

Console output:

logging.jul.Test main          Tue Nov 15 21:46:42 EST 2016 INFO    Start 
0
logging.jul.Test main          Tue Nov 15 21:46:42 EST 2016 INFO    End

test.log:

logging.jul.Test main          Tue Nov 15 21:46:42 EST 2016 INFO    Start 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 1 res = 1 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 2 res = 2 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 3 res = 6 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 4 res = 24 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 5 res = 120 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 6 res = 720 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 7 res = 5040 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 8 res = 40320 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 9 res = 362880 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 10 res = 3628800 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 11 res = 39916800 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 12 res = 479001600 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 13 res = 1932053504 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 14 res = 1278945280 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 15 res = 2004310016 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 16 res = 2004189184 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 17 res = -288522240 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 18 res = -898433024 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 19 res = 109641728 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 20 res = -2102132736 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 21 res = -1195114496 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 22 res = -522715136 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 23 res = 862453760 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 24 res = -775946240 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 25 res = 2076180480 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 26 res = -1853882368 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 27 res = 1484783616 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 28 res = -1375731712 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 29 res = -1241513984 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 30 res = 1409286144 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 31 res = 738197504 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 32 res = -2147483648 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 33 res = -2147483648 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 34 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 35 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 36 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 37 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 38 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 39 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 40 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 41 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 42 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 43 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 44 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 45 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 46 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 47 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 48 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 49 res = 0 
logging.jul.Test fac           Tue Nov 15 21:46:42 EST 2016 FINE    fac : n = 50 res = 0 
logging.jul.Test main          Tue Nov 15 21:46:42 EST 2016 INFO    End

If you wonder why the if statement in:

        if(log.isLoggable(Level.FINE)) {
            log.fine("fac : n = " + n + " res = " + res);
        }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

JUL has a few handlers for various destinations:

ConsoleHandler: standard output or error
FileHandler: disk file

SLF (Simple Logging Facade) is not a real logging framework. It is a logging facade that enables a single API to use log4j or jul via configuration.

package logging.slf;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Test {
    private static final Logger log = LoggerFactory.getLogger(Test.class);
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(log.isDebugEnabled()) {
            log.debug("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

Configure for log4j by putting slf-log4j-version.jar in classpath and configure log4j as shown under log4j.

Configure for JUL by putting slf-jdk14-version.jar in classpath and configure JUL as shown under JUL.

JCL (Jakarta Commons Logging or Apache Commons Logging) is not a real logging framework. It is a logging facade that enables a single API to use log4j or jul via configuration.

package logging.jcl;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

public class Test {
    private static final Log log = LogFactory.getLog(Test.class);
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(log.isDebugEnabled()) {
            log.debug("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

Configure for log4j by:

java -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Log4JLogger ...

and configure log4j as shown under log4j.

Configure for JUL by:

java -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Jdk14Logger ...

and configure JUL as shown under JUL.

Log4j version 2 is a complete rewrite of log4j.

package logging.log4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Test {
    private static final Logger log = LogManager.getLogger(Test.class);
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(log.isDebugEnabled()) {
            log.debug("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

or if one want to finally get rid of that if and are on Java 8+:

package logging.log4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Test {
    private static final Logger log = LogManager.getLogger(Test.class);
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        log.debug(() -> "fac : n = " + n + " res = " + res);
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

Configuration:

java -Dlog4j.configurationFile=/work/log4j2.xml ...

log4j2.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Appenders>
        <!--
          console: minimum level=info, special format
        -->
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout pattern="%-30c %d %-5p %m%n"/>
            <ThresholdFilter level="INFO"/> 
        </Console>
        <!--
          logfile: minimum level=debug, file=test.log, special format
        -->
        <File name="logfile" fileName="/work/test.log">
            <PatternLayout pattern="%-30c %d %-5p %m%n"/>
            <ThresholdFilter level="DEBUG"/> 
        </File>
    </Appenders>
    <Loggers>
        <!--
          logging.log4j2.Test logger: minimum level=debug, two appenders (logfile + console)
        -->
        <Logger name="logging.log4j2.Test" level="debug">
            <AppenderRef ref="console"/>
            <AppenderRef ref="logfile"/>
        </Logger>
        <Root level="none"/>
    </Loggers>
</Configuration>

Console output:

logging.log4j2.Test            2016-11-17 20:49:36,214 INFO  Start
0
logging.log4j2.Test            2016-11-17 20:49:36,219 INFO  End

test.log:

logging.log4j2.Test            2016-11-17 20:49:36,214 INFO  Start
logging.log4j2.Test            2016-11-17 20:49:36,215 DEBUG fac : n = 1 res = 1
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 2 res = 2
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 3 res = 6
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 4 res = 24
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 5 res = 120
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 6 res = 720
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 7 res = 5040
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 8 res = 40320
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 9 res = 362880
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 10 res = 3628800
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 11 res = 39916800
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 12 res = 479001600
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 13 res = 1932053504
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 14 res = 1278945280
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 15 res = 2004310016
logging.log4j2.Test            2016-11-17 20:49:36,216 DEBUG fac : n = 16 res = 2004189184
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 17 res = -288522240
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 18 res = -898433024
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 19 res = 109641728
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 20 res = -2102132736
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 21 res = -1195114496
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 22 res = -522715136
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 23 res = 862453760
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 24 res = -775946240
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 25 res = 2076180480
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 26 res = -1853882368
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 27 res = 1484783616
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 28 res = -1375731712
logging.log4j2.Test            2016-11-17 20:49:36,217 DEBUG fac : n = 29 res = -1241513984
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 30 res = 1409286144
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 31 res = 738197504
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 32 res = -2147483648
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 33 res = -2147483648
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 34 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 35 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 36 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 37 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 38 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 39 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 40 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 41 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 42 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 43 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 44 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,218 DEBUG fac : n = 45 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,219 DEBUG fac : n = 46 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,219 DEBUG fac : n = 47 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,219 DEBUG fac : n = 48 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,219 DEBUG fac : n = 49 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,219 DEBUG fac : n = 50 res = 0
logging.log4j2.Test            2016-11-17 20:49:36,219 INFO  End

Log4j 2 has a long list of appenders for various destinations:

ConsoleAppender: standard output or error
FileAppender: disk file
RollingFileAppender: disk file with new file at specified interval (like every midnight)
JdbcAppender: database
JpaAppender: database
JMSAppender: message queue
KafkaAppender: Apache Kafka
SmtpAppender: email
SyslogAppender: *nix syslog
NTEventLogAppender: Windows event log

Logback is another replacement for log4j.

Logback classic uses SLF4J API.

package logging.logback;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Test {
    private static final Logger log = LoggerFactory.getLogger(Test.class);
    public static int fac(int n) {
        int res;
        if (n <= 1) {
            res = 1;
        } else {
            res = n * fac(n - 1);
        }
        if(log.isDebugEnabled()) {
            log.debug("fac : n = " + n + " res = " + res);
        }
        return res;
    }
    public static void main(String[] args) {
        log.info("Start");
        System.out.println(fac(50));
        log.info("End");
    }
}

Logback can be configured in many different ways, but I will just use a simple logback.xml that is picked up automatically from classpath.

logback.xml:

<configuration>
    <!--
    console: minimum level=info, special format
    -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>info</level>
        </filter>
        <encoder type="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%-30logger %d %-5level %msg%n</pattern>
        </encoder>
    </appender>
    <!--
    logfile: minimum level=debug, file=test.log, special format
    -->
    <appender name="logfile" class="ch.qos.logback.core.FileAppender">
        <file>test.log</file>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>debug</level>
        </filter>
        <encoder type="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%-30logger %d %-5level %msg%n</pattern>
        </encoder>
    </appender>
    <!--
    logging.logback.Test logger: minimum level=debug, two appenders (logfile + console)
    -->
    <logger name="logging.logback.Test" level="debug">
        <appender-ref ref="console"/>
        <appender-ref ref="logfile"/>
    </logger>
    <root level="none"/>
</configuration>

Console output:

logging.logback.Test           2019-06-19 22:39:56,867 INFO  Start
0
logging.logback.Test           2019-06-19 22:39:56,867 INFO  End

test.log:

logging.logback.Test           2019-06-19 22:39:56,867 INFO  Start
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 1 res = 1
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 2 res = 2
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 3 res = 6
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 4 res = 24
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 5 res = 120
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 6 res = 720
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 7 res = 5040
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 8 res = 40320
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 9 res = 362880
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 10 res = 3628800
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 11 res = 39916800
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 12 res = 479001600
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 13 res = 1932053504
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 14 res = 1278945280
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 15 res = 2004310016
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 16 res = 2004189184
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 17 res = -288522240
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 18 res = -898433024
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 19 res = 109641728
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 20 res = -2102132736
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 21 res = -1195114496
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 22 res = -522715136
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 23 res = 862453760
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 24 res = -775946240
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 25 res = 2076180480
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 26 res = -1853882368
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 27 res = 1484783616
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 28 res = -1375731712
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 29 res = -1241513984
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 30 res = 1409286144
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 31 res = 738197504
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 32 res = -2147483648
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 33 res = -2147483648
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 34 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 35 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 36 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 37 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 38 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 39 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 40 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 41 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 42 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 43 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 44 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 45 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 46 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 47 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 48 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 49 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 DEBUG fac : n = 50 res = 0
logging.logback.Test           2019-06-19 22:39:56,867 INFO  End

Logback has a long list of appenders for various destinations:

ConsoleAppender: standard output or error
FileAppender: disk file
RollingFileAppender: disk file with new file at specified interval (like every midnight)
DBAppender: database
SmtpAppender: email
SocketAppender: TCP socket
SyslogAppender: *nix syslog

log4net is a port of log4j to .NET.

using System;

using log4net;
using log4net.Config;

namespace Logging.Log4Net
{
    public class Test
    {
        private static readonly ILog log = LogManager.GetLogger(typeof(Test));
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            if(log.IsDebugEnabled)
            {
                log.Debug("fac : n = " + n + " res = " + res);
            }
            return res;
        }
        public static void Main(string[] args)
        {
            XmlConfigurator.Configure();
            log.Info("Start");
            Console.WriteLine(Fac(50));
            log.Info("End");
        }
    }
}

Configuration via app.config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
    <configSections>
        <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net"/>
    </configSections>
    <log4net>
        <appender name="console" type="log4net.Appender.ConsoleAppender,log4net">
            <threshold value="INFO"/>
            <layout type="log4net.Layout.PatternLayout,log4net">
                <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
            </layout>
        </appender>
        <appender name="logfile" type="log4net.Appender.FileAppender,log4net">
            <threshold value="DEBUG"/>
            <file value="C:\work\test.log"/>
            <layout type="log4net.Layout.PatternLayout,log4net">
                <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
            </layout>
        </appender>
        <logger name="Logging.Log4Net.Test">
            <level value="DEBUG"/>
            <appender-ref ref="console"/>
            <appender-ref ref="logfile"/>
        </logger>
    </log4net>
</configuration>

Console output:

Logging.Log4Net.Test           2017-09-23 22:38:46,189 INFO  Start
0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 INFO  End

test.log:

Logging.Log4Net.Test           2017-09-23 22:38:46,189 INFO  Start
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 1 res = 1
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 2 res = 2
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 3 res = 6
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 4 res = 24
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 5 res = 120
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 6 res = 720
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 7 res = 5040
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 8 res = 40320
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 9 res = 362880
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 10 res = 3628800
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 11 res = 39916800
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 12 res = 479001600
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 13 res = 1932053504
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 14 res = 1278945280
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 15 res = 2004310016
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 16 res = 2004189184
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 17 res = -288522240
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 18 res = -898433024
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 19 res = 109641728
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 20 res = -2102132736
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 21 res = -1195114496
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 22 res = -522715136
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 23 res = 862453760
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 24 res = -775946240
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 25 res = 2076180480
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 26 res = -1853882368
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 27 res = 1484783616
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 28 res = -1375731712
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 29 res = -1241513984
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 30 res = 1409286144
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 31 res = 738197504
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 32 res = -2147483648
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 33 res = -2147483648
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 34 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 35 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 36 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 37 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 38 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 39 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 40 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 41 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 42 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 43 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 44 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 45 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 46 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 47 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 48 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 49 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 50 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 INFO  End

If you wonder why the if statement in:

             if(log.IsDebugEnabled)
            {
                log.Debug("fac : n = " + n + " res = " + res);
            }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

log4net has many appenders for various destinations:

ConsoleAppender: standard output or error
FileAppender: disk file
AdoNetAppender: database
EventLogAppender: Windows event log
LocalSyslogAppender & RemoteSyslogAppender: *nix syslog
MemoryAppender: array
SmtpAppender: email
TraceAppender: trace system

NLog is an alternative logging framework for .NET.

using System;

using NLog;

namespace Logging.NLog
{
    public class Test
    {
        private static readonly Logger log = LogManager.GetCurrentClassLogger();
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            if(log.IsDebugEnabled)
            {
                log.Debug("fac : n = " + n + " res = " + res);
            }
            return res;
        }
        public static void Main(string[] args)
        {
            log.Info("Start");
            Console.WriteLine(Fac(50));
            log.Info("End");
        }
    }
}

Configuration via app.config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <configSections>
     <section name="nlog" type="NLog.Config.ConfigSectionHandler, NLog"/>
  </configSections>
  <nlog>
    <targets>
      <target name="logfile" type="File" fileName="\work\test.log" layout="${logger:padding=-30} ${date} ${level:padding=-5} ${message}"/>
      <target name="console" type="Console" layout="${logger:padding=-30} ${date} ${level:padding=-5} ${message}"/>
    </targets>
    <rules>
      <logger name="Logging.NLog.Test" minlevel="Info" writeTo="console" />
      <logger name="Logging.NLog.Test" minlevel="Debug" writeTo="logfile" />
    </rules>
  </nlog>
    <startup>
        <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.0" />
    </startup>
</configuration>

Console output:

Logging.NLog.Test              2017/09/23 22:59:57.287 Info  Start
0
Logging.NLog.Test              2017/09/23 22:59:57.418 Info  End

test.log:

Logging.NLog.Test              2017/09/23 22:59:57.287 Info  Start
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 1 res = 1
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 2 res = 2
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 3 res = 6
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 4 res = 24
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 5 res = 120
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 6 res = 720
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 7 res = 5040
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 8 res = 40320
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 9 res = 362880
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 10 res = 3628800
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 11 res = 39916800
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 12 res = 479001600
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 13 res = 1932053504
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 14 res = 1278945280
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 15 res = 2004310016
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 16 res = 2004189184
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 17 res = -288522240
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 18 res = -898433024
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 19 res = 109641728
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 20 res = -2102132736
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 21 res = -1195114496
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 22 res = -522715136
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 23 res = 862453760
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 24 res = -775946240
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 25 res = 2076180480
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 26 res = -1853882368
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 27 res = 1484783616
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 28 res = -1375731712
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 29 res = -1241513984
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 30 res = 1409286144
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 31 res = 738197504
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 32 res = -2147483648
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 33 res = -2147483648
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 34 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 35 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 36 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 37 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 38 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 39 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 40 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 41 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 42 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 43 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 44 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 45 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 46 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 47 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 48 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 49 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 50 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Info  End

If you wonder why the if statement in:

            if(log.IsDebugEnabled)
            {
                log.Debug("fac : n = " + n + " res = " + res);
            }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

NLog has many target types for various destinations:

Console: standard output or error
File: disk file
Database: database
Mail: email
EventLog: Windows event log
Trace: trace system
Memory: ArrayList

.NET Core and .NET 5+ has Microsoft Extensions Logging.

NuGet dependencies:

Microsoft.Extensions.Logging
Microsoft.Extensions.Logging.Console
Microsoft.Extensions.Logging.Configuration
Microsoft.Extensions.Configuration
Microsoft.Extensions.Configuration.Json

using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Configuration;

namespace Logging.Util
{
    public class LogContext
    {
        private static LogContext inst = new LogContext();
        public static LogContext Instance { get { return inst; } }
        private ILoggerFactory lf;
        private LogContext()
        {
            IConfigurationBuilder cfgb = (new ConfigurationBuilder()).AddJsonFile("appsettings.json", false, true);
            IConfiguration cfg = cfgb.Build();
            lf = LoggerFactory.Create(builder => builder.AddConsole().AddConfiguration(cfg.GetSection("Logging")) );
        }
        public ILogger CreateLogger<T>()
        {
            return lf.CreateLogger<T>();
        }
        public void FlushAll()
        {
            lf.Dispose(); // flushes output
        }
    }
}

using System;

using Microsoft.Extensions.Logging;

using Logging.Util;

namespace Logging.MsExtLog
{
    public class Test
    {
        private static ILogger log = LogContext.Instance.CreateLogger<Test>();
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            if(log.IsEnabled(LogLevel.Debug))
            {
                log.LogDebug("fac : n = " + n + " res = " + res);
            }
            return res;
        }
        public static void Main(string[] args)
        {
            log.LogInformation("Start");
            Console.WriteLine(Fac(50));
            log.LogInformation("End");
            LogContext.Instance.FlushAll();
        }
    }
}

Configuration via appsettings.json:

{
    "Logging": {
        "LogLevel": {
            "Default": "Warning",
            "Logging.MsExtLog": "Debug"
        },
        "Console": {
            "LogLevel": {
                "Default": "Warning",
                "Logging.MsExtLog": "Debug"
            },
            "FormatterName": "simple",
            "FormatterOptions": {
                "SingleLine": true
            }
        }
    }
}

Console output:

0
info: Logging.MsExtLog.Test[0] Start
dbug: Logging.MsExtLog.Test[0] fac : n = 1 res = 1
dbug: Logging.MsExtLog.Test[0] fac : n = 2 res = 2
dbug: Logging.MsExtLog.Test[0] fac : n = 3 res = 6
dbug: Logging.MsExtLog.Test[0] fac : n = 4 res = 24
dbug: Logging.MsExtLog.Test[0] fac : n = 5 res = 120
dbug: Logging.MsExtLog.Test[0] fac : n = 6 res = 720
dbug: Logging.MsExtLog.Test[0] fac : n = 7 res = 5040
dbug: Logging.MsExtLog.Test[0] fac : n = 8 res = 40320
dbug: Logging.MsExtLog.Test[0] fac : n = 9 res = 362880
dbug: Logging.MsExtLog.Test[0] fac : n = 10 res = 3628800
dbug: Logging.MsExtLog.Test[0] fac : n = 11 res = 39916800
dbug: Logging.MsExtLog.Test[0] fac : n = 12 res = 479001600
dbug: Logging.MsExtLog.Test[0] fac : n = 13 res = 1932053504
dbug: Logging.MsExtLog.Test[0] fac : n = 14 res = 1278945280
dbug: Logging.MsExtLog.Test[0] fac : n = 15 res = 2004310016
dbug: Logging.MsExtLog.Test[0] fac : n = 16 res = 2004189184
dbug: Logging.MsExtLog.Test[0] fac : n = 17 res = -288522240
dbug: Logging.MsExtLog.Test[0] fac : n = 18 res = -898433024
dbug: Logging.MsExtLog.Test[0] fac : n = 19 res = 109641728
dbug: Logging.MsExtLog.Test[0] fac : n = 20 res = -2102132736
dbug: Logging.MsExtLog.Test[0] fac : n = 21 res = -1195114496
dbug: Logging.MsExtLog.Test[0] fac : n = 22 res = -522715136
dbug: Logging.MsExtLog.Test[0] fac : n = 23 res = 862453760
dbug: Logging.MsExtLog.Test[0] fac : n = 24 res = -775946240
dbug: Logging.MsExtLog.Test[0] fac : n = 25 res = 2076180480
dbug: Logging.MsExtLog.Test[0] fac : n = 26 res = -1853882368
dbug: Logging.MsExtLog.Test[0] fac : n = 27 res = 1484783616
dbug: Logging.MsExtLog.Test[0] fac : n = 28 res = -1375731712
dbug: Logging.MsExtLog.Test[0] fac : n = 29 res = -1241513984
dbug: Logging.MsExtLog.Test[0] fac : n = 30 res = 1409286144
dbug: Logging.MsExtLog.Test[0] fac : n = 31 res = 738197504
dbug: Logging.MsExtLog.Test[0] fac : n = 32 res = -2147483648
dbug: Logging.MsExtLog.Test[0] fac : n = 33 res = -2147483648
dbug: Logging.MsExtLog.Test[0] fac : n = 34 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 35 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 36 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 37 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 38 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 39 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 40 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 41 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 42 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 43 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 44 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 45 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 46 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 47 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 48 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 49 res = 0
dbug: Logging.MsExtLog.Test[0] fac : n = 50 res = 0
info: Logging.MsExtLog.Test[0] End

If you wonder why the if statement in:

            if(log.IsEnabled(LogLevel.Debug))
            {
                log.LogDebug("fac : n = " + n + " res = " + res);
            }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

MS Extensions Logging only comes with support for a few output types:

Console with colored single or multiline text
Console with single line text
Console with JSON
Debug
EventLog

But it also has a provider model that allows for other provides. Available providers include:

Azure App Services File
Azure App Services BLOB
Azure Applications Insigtht
elmah.io
Gelf
log4net
NLog
Serilog
+more

At first sight MS Extensions Logging seems very primitive:

Cumbersome configuration (which is why I have the LogContext singleton in the example above)
Out of the box possible output types and configuration of output is very limited compared to other logging frameworks

But I assume that:

Configuration is not a real problem as it is integrated very nicely with MS extension DI and various server .NET Core server frameworks
The console output is fine for development and for production it is expected to use one of the available external providers

Or to put it more briefly for those familiar with Java logging: Microsoft Extensions Logging is the equivalent of SLF4J not LOG4J.

Let us see Microsoft Extensions Logging with log4net provider.

NuGet dependencies:

Microsoft.Extensions.Logging
Microsoft.Extensions.Logging.Configuration
log4net
Microsoft.Extensions.Logging.Log4Net.AspNetCore
Microsoft.Extensions.Configuration
Microsoft.Extensions.Configuration.Json

using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Configuration;

using log4net;

namespace Logging.Util
{
    public class LogContext
    {
        private static LogContext inst = new LogContext();
        public static LogContext Instance { get { return inst; } }
        private ILoggerFactory lf;
        private LogContext()
        {
            IConfigurationBuilder cfgb = (new ConfigurationBuilder()).AddJsonFile("appsettings.json", false, true);
            IConfiguration cfg = cfgb.Build();
            lf = LoggerFactory.Create(builder => builder.AddLog4Net().AddConfiguration(cfg.GetSection("Logging")) );
        }
        public ILogger CreateLogger<T>()
        {
            return lf.CreateLogger<T>();
        }
        public void FlushAll()
        {
            lf.Dispose(); // flushes output
        }
    }
}

using System;

using Microsoft.Extensions.Logging;

using Logging.Util;

namespace Logging.MsExtLog
{
    public class Test
    {
        private static ILogger log = LogContext.Instance.CreateLogger<Test>();
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            if(log.IsEnabled(LogLevel.Debug))
            {
                log.LogDebug("fac : n = " + n + " res = " + res);
            }
            return res;
        }
        public static void Main(string[] args)
        {
            log.LogInformation("Start");
            Console.WriteLine(Fac(50));
            log.LogInformation("End");
            LogContext.Instance.FlushAll();
        }
    }
}

Configuration via appsettings.json:

{
    "Logging": {
        "LogLevel": {
            "Default": "Warning",
            "Logging.MsExtLog": "Debug"
        }
    }
}

and log4net.config:

<log4net>
    <appender name="console" type="log4net.Appender.ConsoleAppender,log4net">
        <threshold value="INFO"/>
        <layout type="log4net.Layout.PatternLayout,log4net">
            <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
        </layout>
    </appender>
    <appender name="logfile" type="log4net.Appender.FileAppender,log4net">
        <threshold value="DEBUG"/>
        <file value="\work\msextlog\test.log"/>
        <layout type="log4net.Layout.PatternLayout,log4net">
            <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
        </layout>
    </appender>
    <logger name="Logging.MsExtLog.Test">
        <level value="DEBUG"/>
        <appender-ref ref="console"/>
        <appender-ref ref="logfile"/>
    </logger>
</log4net>

Console output:

Logging.MsExtLog.Test          2022/07/31 19:59:55.954 Info  Start
0
Logging.MsExtLog.Test          2022/07/31 19:59:55.984 Info  End

test.log:

Logging.MsExtLog.Test          2022-08-01 19:53:01,879 INFO  Start
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 1 res = 1
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 2 res = 2
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 3 res = 6
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 4 res = 24
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 5 res = 120
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 6 res = 720
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 7 res = 5040
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 8 res = 40320
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 9 res = 362880
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 10 res = 3628800
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 11 res = 39916800
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 12 res = 479001600
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 13 res = 1932053504
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 14 res = 1278945280
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 15 res = 2004310016
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 16 res = 2004189184
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 17 res = -288522240
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 18 res = -898433024
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 19 res = 109641728
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 20 res = -2102132736
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 21 res = -1195114496
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 22 res = -522715136
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 23 res = 862453760
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 24 res = -775946240
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 25 res = 2076180480
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 26 res = -1853882368
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 27 res = 1484783616
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 28 res = -1375731712
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 29 res = -1241513984
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 30 res = 1409286144
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 31 res = 738197504
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 32 res = -2147483648
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 33 res = -2147483648
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 34 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 35 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 36 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 37 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 38 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 39 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 40 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 41 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 42 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 43 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 44 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 45 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 46 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 47 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 48 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,892 DEBUG fac : n = 49 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,894 DEBUG fac : n = 50 res = 0
Logging.MsExtLog.Test          2022-08-01 19:53:01,894 INFO  End

If you wonder why the if statement in:

            if(log.IsEnabled(LogLevel.Debug))
            {
                log.LogDebug("fac : n = " + n + " res = " + res);
            }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

For more info about log4net options see log4net example.

Let us see Microsoft Extensions Logging with NLog provider.

NuGet dependencies:

Microsoft.Extensions.Logging
Microsoft.Extensions.Logging.Configuration
NLog
NLog.Extensions.Logging
Microsoft.Extensions.Configuration
Microsoft.Extensions.Configuration.Json

using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Configuration;

using NLog.Extensions.Logging;

namespace Logging.Util
{
    public class LogContext
    {
        private static LogContext inst = new LogContext();
        public static LogContext Instance { get { return inst; } }
        private ILoggerFactory lf;
        private LogContext()
        {
            IConfigurationBuilder cfgb = (new ConfigurationBuilder()).AddJsonFile("appsettings.json", false, true);
            IConfiguration cfg = cfgb.Build();
            lf = LoggerFactory.Create(builder => builder.AddNLog().AddConfiguration(cfg.GetSection("Logging")) );
        }
        public ILogger CreateLogger<T>()
        {
            return lf.CreateLogger<T>();
        }
        public void FlushAll()
        {
            lf.Dispose(); // flushes output
        }
    }
}

using System;

using Microsoft.Extensions.Logging;

using Logging.Util;

namespace Logging.MsExtLog
{
    public class Test
    {
        private static ILogger log = LogContext.Instance.CreateLogger<Test>();
        public static int Fac(int n)
        {
            int res;
            if (n <= 1)
            {
                res = 1;
            }
            else
            {
                res = n * Fac(n - 1);
            }
            if(log.IsEnabled(LogLevel.Debug))
            {
                log.LogDebug("fac : n = " + n + " res = " + res);
            }
            return res;
        }
        public static void Main(string[] args)
        {
            log.LogInformation("Start");
            Console.WriteLine(Fac(50));
            log.LogInformation("End");
            LogContext.Instance.FlushAll();
        }
    }
}

Configuration via appsettings.json:

{
    "Logging": {
        "LogLevel": {
            "Default": "Warning",
            "Logging.MsExtLog": "Debug"
        }
    }
}

and nlog.config:

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xsi:schemaLocation="NLog NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" autoReload="true">
  <targets>
      <target name="logfile" type="File" fileName="\work\msextlog\test.log" layout="${logger:padding=-30} ${date} ${level:padding=-5} ${message}"/>
      <target name="console" type="Console" layout="${logger:padding=-30} ${date} ${level:padding=-5} ${message}"/>
  </targets>
  <rules>
    <logger name="Logging.MsExtLog.Test" minlevel="Info" writeTo="console"/>
    <logger name="Logging.MsExtLog.Test" minlevel="Debug" writeTo="logfile"/>
  </rules>
</nlog>

Console output:

Logging.MsExtLog.Test          2022/07/31 19:59:55.954 Info  Start
0
Logging.MsExtLog.Test          2022/07/31 19:59:55.984 Info  End

test.log:

Logging.MsExtLog.Test          2022/07/31 19:28:46.698 Info  Start
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 1 res = 1
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 2 res = 2
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 3 res = 6
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 4 res = 24
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 5 res = 120
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 6 res = 720
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 7 res = 5040
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 8 res = 40320
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 9 res = 362880
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 10 res = 3628800
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 11 res = 39916800
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 12 res = 479001600
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 13 res = 1932053504
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 14 res = 1278945280
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 15 res = 2004310016
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 16 res = 2004189184
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 17 res = -288522240
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 18 res = -898433024
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 19 res = 109641728
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 20 res = -2102132736
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 21 res = -1195114496
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 22 res = -522715136
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 23 res = 862453760
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 24 res = -775946240
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 25 res = 2076180480
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 26 res = -1853882368
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 27 res = 1484783616
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 28 res = -1375731712
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 29 res = -1241513984
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 30 res = 1409286144
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 31 res = 738197504
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 32 res = -2147483648
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 33 res = -2147483648
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 34 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 35 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 36 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 37 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 38 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 39 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 40 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 41 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 42 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 43 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 44 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 45 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 46 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 47 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 48 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 49 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Debug fac : n = 50 res = 0
Logging.MsExtLog.Test          2022/07/31 19:28:46.718 Info  End

If you wonder why the if statement in:

            if(log.IsEnabled(LogLevel.Debug))
            {
                log.LogDebug("fac : n = " + n + " res = " + res);
            }

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

For more info about NLog options see NLog example.

log4net is a port of log4j to .NET.

Imports System

Imports log4net
Imports log4net.Config

Namespace Logging.Log4Net
    Public Class Test
        Private Shared ReadOnly log As ILog = LogManager.GetLogger(GetType(Test))
        Public Shared Function Fac(n As Integer) As Integer
            Dim res As Integer
            If n <= 1 Then
                res = 1
            Else
                res = n * Fac(n - 1)
            End If
            If log.IsDebugEnabled Then
                log.Debug("fac : n = " & n & " res = " & res)
            End If
            Return res
        End Function
        Public Shared Sub Main(args As String())
            XmlConfigurator.Configure()
            log.Info("Start")
            Console.WriteLine(Fac(50))
            log.Info("End")
        End Sub
    End Class
End Namespace

Configuration via app.config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
    <configSections>
        <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net"/>
    </configSections>
    <log4net>
        <appender name="console" type="log4net.Appender.ConsoleAppender,log4net">
            <threshold value="INFO"/>
            <layout type="log4net.Layout.PatternLayout,log4net">
                <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
            </layout>
        </appender>
        <appender name="logfile" type="log4net.Appender.FileAppender,log4net">
            <threshold value="DEBUG"/>
            <file value="C:\work\test.log"/>
            <layout type="log4net.Layout.PatternLayout,log4net">
                <param name="ConversionPattern" value="%-30c %d %-5p %m%n"/>
            </layout>
        </appender>
        <logger name="Logging.Log4Net.Test">
            <level value="DEBUG"/>
            <appender-ref ref="console"/>
            <appender-ref ref="logfile"/>
        </logger>
    </log4net>
</configuration>

Console output:

Logging.Log4Net.Test           2017-09-23 22:38:46,189 INFO  Start
0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 INFO  End

test.log:

Logging.Log4Net.Test           2017-09-23 22:38:46,189 INFO  Start
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 1 res = 1
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 2 res = 2
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 3 res = 6
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 4 res = 24
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 5 res = 120
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 6 res = 720
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 7 res = 5040
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 8 res = 40320
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 9 res = 362880
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 10 res = 3628800
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 11 res = 39916800
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 12 res = 479001600
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 13 res = 1932053504
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 14 res = 1278945280
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 15 res = 2004310016
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 16 res = 2004189184
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 17 res = -288522240
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 18 res = -898433024
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 19 res = 109641728
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 20 res = -2102132736
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 21 res = -1195114496
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 22 res = -522715136
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 23 res = 862453760
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 24 res = -775946240
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 25 res = 2076180480
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 26 res = -1853882368
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 27 res = 1484783616
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 28 res = -1375731712
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 29 res = -1241513984
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 30 res = 1409286144
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 31 res = 738197504
Logging.Log4Net.Test           2017-09-23 22:38:46,208 DEBUG fac : n = 32 res = -2147483648
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 33 res = -2147483648
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 34 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 35 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 36 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 37 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 38 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 39 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 40 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 41 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 42 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 43 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 44 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 45 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 46 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 47 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 48 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 49 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 DEBUG fac : n = 50 res = 0
Logging.Log4Net.Test           2017-09-23 22:38:46,209 INFO  End

If you wonder why the if statement in:

            If log.IsDebugEnabled Then
                log.Debug("fac : n = " & n & " res = " & res)
            End If

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

log4net has many appenders for various destinations:

ConsoleAppender: standard output or error
FileAppender: disk file
AdoNetAppender: database
EventLogAppender: Windows event log
LocalSyslogAppender & RemoteSyslogAppender: *nix syslog
MemoryAppender: array
SmtpAppender: email
TraceAppender: trace system

NLog is an alternative logging framework for .NET.

Imports System

Imports NLog

Namespace Logging.NLog
    Public Class Test
        Private Shared ReadOnly log As Logger = LogManager.GetCurrentClassLogger()
        Public Shared Function Fac(n As Integer) As Integer
            Dim res As Integer
            If n <= 1 Then
                res = 1
            Else
                res = n * Fac(n - 1)
            End If
            If log.IsDebugEnabled Then
                log.Debug("fac : n = " & n & " res = " & res)
            End If
            Return res
        End Function
        Public Shared Sub Main(args As String())
            log.Info("Start")
            Console.WriteLine(Fac(50))
            log.Info("End")
        End Sub
    End Class
End Namespace

Configuration via app.config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <configSections>
     <section name="nlog" type="NLog.Config.ConfigSectionHandler, NLog"/>
  </configSections>
  <nlog>
    <targets>
      <target name="logfile" type="File" fileName="\work\test.log" layout="${logger:padding=-30} ${date} ${level:padding=-5} ${message}"/>
      <target name="console" type="Console" layout="${logger:padding=-30} ${date} ${level:padding=-5} ${message}"/>
    </targets>
    <rules>
      <logger name="Logging.NLog.Test" minlevel="Info" writeTo="console" />
      <logger name="Logging.NLog.Test" minlevel="Debug" writeTo="logfile" />
    </rules>
  </nlog>
    <startup>
        <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.0" />
    </startup>
</configuration>

Console output:

Logging.NLog.Test              2017/09/23 22:59:57.287 Info  Start
0
Logging.NLog.Test              2017/09/23 22:59:57.418 Info  End

test.log:

Logging.NLog.Test              2017/09/23 22:59:57.287 Info  Start
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 1 res = 1
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 2 res = 2
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 3 res = 6
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 4 res = 24
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 5 res = 120
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 6 res = 720
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 7 res = 5040
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 8 res = 40320
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 9 res = 362880
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 10 res = 3628800
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 11 res = 39916800
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 12 res = 479001600
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 13 res = 1932053504
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 14 res = 1278945280
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 15 res = 2004310016
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 16 res = 2004189184
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 17 res = -288522240
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 18 res = -898433024
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 19 res = 109641728
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 20 res = -2102132736
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 21 res = -1195114496
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 22 res = -522715136
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 23 res = 862453760
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 24 res = -775946240
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 25 res = 2076180480
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 26 res = -1853882368
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 27 res = 1484783616
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 28 res = -1375731712
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 29 res = -1241513984
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 30 res = 1409286144
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 31 res = 738197504
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 32 res = -2147483648
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 33 res = -2147483648
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 34 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.403 Debug fac : n = 35 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 36 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 37 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 38 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 39 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 40 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 41 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 42 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 43 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 44 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 45 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 46 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 47 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 48 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 49 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Debug fac : n = 50 res = 0
Logging.NLog.Test              2017/09/23 22:59:57.418 Info  End

If you wonder why the if statement in:

            If log.IsDebugEnabled Then
                log.Debug("fac : n = " & n & " res = " & res)
            End If

then it is a performance trick to avoid doing the string concatanation in case debug is not set.

I believe that performance trick is not needed with todays CPU's. And I am only writing the code this way because that is the tradition in the Java world.

NLog has many target types for various destinations:

Console: standard output or error
File: disk file
Database: database
Mail: email
EventLog: Windows event log
Trace: trace system
Memory: ArrayList

Log4php is a logging framework based on log4j and the rest of the log4xxx frameworks.

<?php
require_once 'Logger.php';

class Test {
    public static $logger;
    public static function fac($n) {
        if($n <= 1) {
            $res = 1;
        } else {
            $res = $n * Test::fac($n - 1);
        }
        Test::$logger->debug('fac : n = ' . $n . ' res = ' . $res);
        return (int)$res;
    }
}

Logger::configure('config.xml');
Test::$logger = Logger::getLogger('Test');
Test::$logger->info('Start');
echo Test::fac(50) . "\r\n";
Test::$logger->info('End');
?>

Configuration:

<?xml version="1.0" encoding="UTF-8"?>
<configuration xmlns="http://logging.apache.org/log4php/">
    <!--
      console: minimum level=info, special format
    -->
    <appender name="console" class="LoggerAppenderConsole">
        <param name="threshold" value="info"/>
        <layout class="LoggerLayoutPattern">
            <param name="conversionPattern" value="%-30c %d %-5p %m%n"/>
        </layout>
    </appender>
    <!--
      logfile: minimum level=debug, file=test.log, special format
    -->
    <appender name="logfile" class="LoggerAppenderFile">
        <param name="threshold" value="debug"/>
        <param name="file" value="/work/test.log"/>
        <layout class="LoggerLayoutPattern">
            <param name="conversionPattern" value="%-30c %d %-5p %m%n"/>
        </layout>
    </appender>
    <!--
      Test logger: minimum level=debug, two appenders (logfile + console)
    -->
    <logger name="Test">
        <level value="debug"/>
        <appender_ref ref="console"/>              
        <appender_ref ref="logfile"/>
    </logger>
</configuration>

Console output:

Test                           2017-09-26T17:07:17-04:00 INFO  Start
0
Test                           2017-09-26T17:07:17-04:00 INFO  End

test.log:

Test                           2017-09-26T17:07:48-04:00 INFO  Start
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 1 res = 1
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 2 res = 2
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 3 res = 6
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 4 res = 24
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 5 res = 120
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 6 res = 720
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 7 res = 5040
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 8 res = 40320
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 9 res = 362880
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 10 res = 3628800
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 11 res = 39916800
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 12 res = 479001600
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 13 res = 6227020800
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 14 res = 27048749056
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 15 res = 19184179200
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 16 res = 32068960256
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 17 res = 34071216128
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 18 res = -5193400320
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 19 res = -17070227456
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 20 res = 2192834560
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 21 res = -44144787456
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 22 res = -26292518912
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 23 res = -12022448128
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 24 res = 20698890240
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 25 res = -19398656000
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 26 res = 53980692480
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 27 res = -50054823936
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 28 res = 41573941248
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 29 res = -39896219648
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 30 res = -37245419520
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 31 res = 43687870464
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 32 res = 23622320128
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 33 res = -70866960384
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 34 res = -73014444032
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 35 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 36 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 37 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 38 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 39 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 40 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 41 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 42 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 43 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 44 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 45 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 46 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 47 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 48 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 49 res = 0
Test                           2017-09-26T17:07:48-04:00 DEBUG fac : n = 50 res = 0
Test                           2017-09-26T17:07:48-04:00 INFO  End

Log4php has many appenders for various destinations:

LoggerAppenderConsole: standard output or error
LoggerAppenderFile: disk file
LoggerAppenderDailyFile: disk file with new file every day
LoggerAppenderMail: email
LoggerAppenderPDO: database
LoggerAppenderSyslog: *nix syslog

Monolog is a loging framework used by many PHP frameworks including Symfony and Laravel.

It is somewhat different from the log4xxx frameworks. It is based on the PSR-3 standard for PHP logging.

<?php
spl_autoload_register(function ($clznam) {
    include $clznam . '.php';
});

use Monolog\Logger;
use Monolog\Handler\StreamHandler;
use Monolog\Formatter\LineFormatter;

class Test {
    public static $logger;
    public static function fac($n) {
        if($n <= 1) {
            $res = 1;
        } else {
            $res = $n * Test::fac($n - 1);
        }
        Test::$logger->debug('fac : n = ' . $n . ' res = ' . $res);
        return (int)$res;
    }
}

Test::$logger = new Logger('Test');
$formatter = new LineFormatter("%channel% %datetime% %level_name% %message%\n", 'Y-m-d H:i:s');

$console = new StreamHandler('php://stderr', Logger::INFO);
$console->setFormatter($formatter);
Test::$logger->pushHandler($console);

$logfile = new StreamHandler('/work/test.log', Logger::DEBUG);
$logfile->setFormatter($formatter);
Test::$logger->pushHandler($logfile);

Test::$logger->info('Start');
echo Test::fac(50) . "\r\n";
Test::$logger->info('End');
?>

Console output:

Test 2017-09-26 17:09:54 INFO Start
0
Test 2017-09-26 17:09:54 INFO End

test.log:

Test 2017-09-26 17:11:27 INFO Start
Test 2017-09-26 17:11:27 DEBUG fac : n = 1 res = 1
Test 2017-09-26 17:11:27 DEBUG fac : n = 2 res = 2
Test 2017-09-26 17:11:27 DEBUG fac : n = 3 res = 6
Test 2017-09-26 17:11:27 DEBUG fac : n = 4 res = 24
Test 2017-09-26 17:11:27 DEBUG fac : n = 5 res = 120
Test 2017-09-26 17:11:27 DEBUG fac : n = 6 res = 720
Test 2017-09-26 17:11:27 DEBUG fac : n = 7 res = 5040
Test 2017-09-26 17:11:27 DEBUG fac : n = 8 res = 40320
Test 2017-09-26 17:11:27 DEBUG fac : n = 9 res = 362880
Test 2017-09-26 17:11:27 DEBUG fac : n = 10 res = 3628800
Test 2017-09-26 17:11:27 DEBUG fac : n = 11 res = 39916800
Test 2017-09-26 17:11:27 DEBUG fac : n = 12 res = 479001600
Test 2017-09-26 17:11:27 DEBUG fac : n = 13 res = 6227020800
Test 2017-09-26 17:11:27 DEBUG fac : n = 14 res = 27048749056
Test 2017-09-26 17:11:27 DEBUG fac : n = 15 res = 19184179200
Test 2017-09-26 17:11:27 DEBUG fac : n = 16 res = 32068960256
Test 2017-09-26 17:11:27 DEBUG fac : n = 17 res = 34071216128
Test 2017-09-26 17:11:27 DEBUG fac : n = 18 res = -5193400320
Test 2017-09-26 17:11:27 DEBUG fac : n = 19 res = -17070227456
Test 2017-09-26 17:11:27 DEBUG fac : n = 20 res = 2192834560
Test 2017-09-26 17:11:27 DEBUG fac : n = 21 res = -44144787456
Test 2017-09-26 17:11:27 DEBUG fac : n = 22 res = -26292518912
Test 2017-09-26 17:11:27 DEBUG fac : n = 23 res = -12022448128
Test 2017-09-26 17:11:27 DEBUG fac : n = 24 res = 20698890240
Test 2017-09-26 17:11:27 DEBUG fac : n = 25 res = -19398656000
Test 2017-09-26 17:11:27 DEBUG fac : n = 26 res = 53980692480
Test 2017-09-26 17:11:27 DEBUG fac : n = 27 res = -50054823936
Test 2017-09-26 17:11:27 DEBUG fac : n = 28 res = 41573941248
Test 2017-09-26 17:11:27 DEBUG fac : n = 29 res = -39896219648
Test 2017-09-26 17:11:27 DEBUG fac : n = 30 res = -37245419520
Test 2017-09-26 17:11:27 DEBUG fac : n = 31 res = 43687870464
Test 2017-09-26 17:11:27 DEBUG fac : n = 32 res = 23622320128
Test 2017-09-26 17:11:27 DEBUG fac : n = 33 res = -70866960384
Test 2017-09-26 17:11:27 DEBUG fac : n = 34 res = -73014444032
Test 2017-09-26 17:11:27 DEBUG fac : n = 35 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 36 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 37 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 38 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 39 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 40 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 41 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 42 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 43 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 44 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 45 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 46 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 47 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 48 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 49 res = 0
Test 2017-09-26 17:11:27 DEBUG fac : n = 50 res = 0
Test 2017-09-26 17:11:27 INFO End

Log4php has many handlers for various destinations:

StreamHandler: standard output or error, or disk file
RotatingFileHandler: disk file with new file every day
SyslogHandler: *nix syslog
NativeMailerHandler: email
AmqpHandler: message queue via AMQP
PsrHandler: another PSR-3 logger

Python has had a builtin logging framework since version 2.3. This framework is heavily inspired by log4j like many other logging frameworks.

import logging
import logging.config

import numpy
numpy.warnings.simplefilter("ignore", RuntimeWarning)

log = logging.getLogger('logging.Test')

def fac(n):
    if n <= 1:
        res = 1
    else:
        res = n * fac(n - 1)
    log.debug('fac : n = %d res = %d', n, res)
    return res

logging.config.fileConfig('logging.cfg')
log.info('Start')
print(fac(numpy.int32(50)))
log.info('End')

logging.cfg:

[loggers]
keys=root,Test

[handlers]
keys=logfile,console

[formatters]
keys=mylayout

[logger_root]
level=NOTSET
handlers=

[logger_Test]
level=DEBUG
handlers=logfile,console
qualname=logging.Test

[handler_console]
class=StreamHandler
level=INFO
args=(sys.stderr,)
formatter=mylayout

[handler_logfile]
class=FileHandler
level=DEBUG
args=('test.log',)
formatter=mylayout

[formatter_mylayout]
class=logging.Formatter
format=%(name)-30s %(asctime)s %(levelname)-5s %(message)s
datefmt=

Console output:

logging.Test                   2018-11-04 10:42:04,806 INFO  Start
0
logging.Test                   2018-11-04 10:42:04,821 INFO  End

test.log:

logging.Test                   2018-11-04 10:42:04,806 INFO  Start
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 1 res = 1
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 2 res = 2
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 3 res = 6
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 4 res = 24
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 5 res = 120
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 6 res = 720
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 7 res = 5040
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 8 res = 40320
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 9 res = 362880
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 10 res = 3628800
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 11 res = 39916800
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 12 res = 479001600
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 13 res = 1932053504
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 14 res = 1278945280
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 15 res = 2004310016
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 16 res = 2004189184
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 17 res = -288522240
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 18 res = -898433024
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 19 res = 109641728
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 20 res = -2102132736
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 21 res = -1195114496
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 22 res = -522715136
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 23 res = 862453760
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 24 res = -775946240
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 25 res = 2076180480
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 26 res = -1853882368
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 27 res = 1484783616
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 28 res = -1375731712
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 29 res = -1241513984
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 30 res = 1409286144
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 31 res = 738197504
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 32 res = -2147483648
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 33 res = -2147483648
logging.Test                   2018-11-04 10:42:04,806 DEBUG fac : n = 34 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 35 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 36 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 37 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 38 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 39 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 40 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 41 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 42 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 43 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 44 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 45 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 46 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 47 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 48 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 49 res = 0
logging.Test                   2018-11-04 10:42:04,821 DEBUG fac : n = 50 res = 0
logging.Test                   2018-11-04 10:42:04,821 INFO  End

Python logging has many handlers for various destinations:

StreamHandler: standard output or error
FileHandler: disk file
RotatingFileHandler: disk file with new file at specified interval (like every midnight)
SMTPHandler: email
SysLogHandler: *nix syslog
NTEventLogHandler: Windows event log

Log4delphi is a logging framework based on log4j and the rest of the log4xxx frameworks. It is not actively maintained (latest release was in 2010). But it works and the basic concepts has not changed in 20 years.

program Logging;

uses
  Interfaces, SysUtils, TLoggerUnit, TLevelUnit, TConfiguratorUnit;

var
  log : TLogger;

function fac(n : integer) : integer;

var
  res : integer;

begin
  if n <= 1 then begin
    res := 1;
  end else begin
    res := n * fac(n - 1);
  end;
  log.debug('fac : ' + IntToStr(n) + ' res = ' + IntToStr(res));
  fac := res;
end;

begin
  TConfiguratorUnit.doPropertiesConfiguration('log4delphi.properties');
  log := TLogger.GetInstance('Test');
  log.info('Start');
  writeln(fac(50));
  log.info('End');
  log.FreeInstances();
end.

log4delphi.properties:

# disable internal debugging
log4delphi.debug = false
# Test logger: minimum level=debug, one appender (logfile)
log4delphi.logger.Test = debug, logfile
# logfile: minimum level=debug, file=test.log, special format
log4delphi.appender.logfile.threshold = debug
log4delphi.appender.logfile = TFileAppender
log4delphi.appender.logfile.file = /work/test.log
log4delphi.appender.logfile.layout = TPatternLayout
log4delphi.appender.logfile.layout.Pattern = %-30L %d %-5p %m

test.log:

Test                           4/21/2019 19:25:01 INFO  Start
Test                           4/21/2019 19:25:01 DEBUG fac : 1 res = 1
Test                           4/21/2019 19:25:01 DEBUG fac : 2 res = 2
Test                           4/21/2019 19:25:01 DEBUG fac : 3 res = 6
Test                           4/21/2019 19:25:01 DEBUG fac : 4 res = 24
Test                           4/21/2019 19:25:01 DEBUG fac : 5 res = 120
Test                           4/21/2019 19:25:01 DEBUG fac : 6 res = 720
Test                           4/21/2019 19:25:01 DEBUG fac : 7 res = 5040
Test                           4/21/2019 19:25:01 DEBUG fac : 8 res = 40320
Test                           4/21/2019 19:25:01 DEBUG fac : 9 res = 362880
Test                           4/21/2019 19:25:01 DEBUG fac : 10 res = 3628800
Test                           4/21/2019 19:25:01 DEBUG fac : 11 res = 39916800
Test                           4/21/2019 19:25:01 DEBUG fac : 12 res = 479001600
Test                           4/21/2019 19:25:01 DEBUG fac : 13 res = 1932053504
Test                           4/21/2019 19:25:01 DEBUG fac : 14 res = 1278945280
Test                           4/21/2019 19:25:01 DEBUG fac : 15 res = 2004310016
Test                           4/21/2019 19:25:01 DEBUG fac : 16 res = 2004189184
Test                           4/21/2019 19:25:01 DEBUG fac : 17 res = -288522240
Test                           4/21/2019 19:25:01 DEBUG fac : 18 res = -898433024
Test                           4/21/2019 19:25:01 DEBUG fac : 19 res = 109641728
Test                           4/21/2019 19:25:01 DEBUG fac : 20 res = -2102132736
Test                           4/21/2019 19:25:01 DEBUG fac : 21 res = -1195114496
Test                           4/21/2019 19:25:01 DEBUG fac : 22 res = -522715136
Test                           4/21/2019 19:25:01 DEBUG fac : 23 res = 862453760
Test                           4/21/2019 19:25:01 DEBUG fac : 24 res = -775946240
Test                           4/21/2019 19:25:01 DEBUG fac : 25 res = 2076180480
Test                           4/21/2019 19:25:01 DEBUG fac : 26 res = -1853882368
Test                           4/21/2019 19:25:01 DEBUG fac : 27 res = 1484783616
Test                           4/21/2019 19:25:01 DEBUG fac : 28 res = -1375731712
Test                           4/21/2019 19:25:01 DEBUG fac : 29 res = -1241513984
Test                           4/21/2019 19:25:01 DEBUG fac : 30 res = 1409286144
Test                           4/21/2019 19:25:01 DEBUG fac : 31 res = 738197504
Test                           4/21/2019 19:25:01 DEBUG fac : 32 res = -2147483648
Test                           4/21/2019 19:25:01 DEBUG fac : 33 res = -2147483648
Test                           4/21/2019 19:25:01 DEBUG fac : 34 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 35 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 36 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 37 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 38 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 39 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 40 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 41 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 42 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 43 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 44 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 45 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 46 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 47 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 48 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 49 res = 0
Test                           4/21/2019 19:25:01 DEBUG fac : 50 res = 0
Test                           4/21/2019 19:25:01 INFO  End

Log4delphi does not have many appenders - only TFileAppender, TRollingFileAppender, TWriterAppender and TDBAppender, but those are probbaly the most important ones anyway.

What to choose:

Java

As seen above then there are plenty of logging frameworks to choose from in Java, so which to pick. Naturally there are many opinions on that topic.

My recommendation is:

simple Java SE application => choose JUL, because it comes with Java SE so no additional libraries are needed
complex Java EE appplication => choose SLF and log4j, because SLF allows to to change to JUL if needed and log4j is more flexible and have more appenders than JUL

Log4j 2 looks very promising, but I have not seen it used enough to feel comfortable with it.

I prefer SLF over JCL only because I think SLF is more widely used.

UPDATE: log4j is now officially obsolete. The most obvious replacements are SLF + log4j 2 and SLF + logback. It is my impression that logback is more widely used than log4j 2, so my recommendation for Java EE is now SLF + logback.

.NET (C# and VB.NET)

As seen above then there are a few logging frameworks to choose from in .NET, so which to pick. Naturally there are many opinions on that topic.

My recommendation is to chose log4net because it is more similar to log4j and therefore easier for a lot of programmers and I don't see any major advantages of NLog.

If on .NET Core/5+ then I recommend wrapping log4net in MEL API.

PHP

As seen above then there are a few logging frameworks to choose from in PHP, so which to pick. Naturally there are many opinions on that topic.

My recommendation is:

pure PHP shop => choose Monolog because it is the most widely used
mixed PHP and other languages shop => choose log4php as it is more similar to logging frameworks in other languages

Python:

My recommendation is to chose the builtin. It is great so no need to look for third party framework.

Delphi/Lazarus:

Log4delphi seems to work OK even though the selection of appenders are not great.

Article history:

Version	Date	Description
1.0	September 26th 2017	Initial version based on old article (in Danish) on Eksperten.dk
1.1	November 4th 2018	Add Python
1.2	April 21st 2019	Add Delphi/Lazarus
1.3	June 19th 2019	Add logback
1.4	July 31st 2022	Add MEL logging

Comments:

Please send comments to Arne Vajhøj

Logging

Content:

Introduction:

Example of problem:

Adhoc approach:

Enhanced adhoc approach:

Solution - a logging framework:

What to choose:

Java

.NET (C# and VB.NET)

PHP

Python:

Delphi/Lazarus:

Article history:

Other articles:

Comments: