Log4net works in Debug but fails in Release build

P

2

15

I've been using log4net for a while so I'm not quite new to it. But this was my first larger .NET 4.0 solution deployed on a Windows Server 2008 R2 64-bit machine.

Of course I searched first and found similar topics. One topic sounds quite the same - log4net doesn't log when running a .Net 4.0 Windows application built in Release mode - But my issue is still different.

Part of my solution is a console application that utilizes log4net. Everything works fine until I switch to Release build. During test on my PC it still works fine. But on server side log4net won't work anymore.

So I enabled log4net internal debugging. This points to a repository conflict. I've never dived so deep into log4net to fully understand it. But the problem seems to be that it first creates a repository for the domain assembly (CRMFacade.Domain) and then tries to create one for the console application (CRMFacade.DataImport). This fails because a default repository already exists:

log4net: log4net assembly [log4net, Version=1.2.10.0, Culture=neutral, PublicKeyToken=1b44e1d426115821]. Loaded from [Global Assembly Cache]. (.NET Runtime [4.0.30319.225] on Microsoft Windows NT 6.1.7601 Service Pack 1)
log4net: DefaultRepositorySelector: defaultRepositoryType [log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: Creating repository for assembly [CRMFacade.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]
log4net: DefaultRepositorySelector: Assembly [CRMFacade.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] Loaded From [C:\Program Files (x86)\CRMFacade.DataImport\CRMFacade.Domain.dll]
log4net: DefaultRepositorySelector: Assembly [CRMFacade.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] does not have a RepositoryAttribute specified.
log4net: DefaultRepositorySelector: Assembly [CRMFacade.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] using repository [log4net-default-repository] and repository type [log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: Creating repository [log4net-default-repository] using type [log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: Creating repository for assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]
log4net: DefaultRepositorySelector: Assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] Loaded From [C:\Program Files (x86)\CRMFacade.DataImport\CRMFacade.DataImport.exe]
log4net: DefaultRepositorySelector: Assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] does not have a RepositoryAttribute specified.
log4net: DefaultRepositorySelector: Assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] using repository [log4net-default-repository] and repository type [log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: repository [log4net-default-repository] already exists, using repository type [log4net.Repository.Hierarchy.Hierarchy]

The funny thing is: In Debug build the console application (CRMFacade.DataImport) is the first and only assembly that log4net creates a repository for. In either case CRMFacade.Domain is in Release build. CRMFacade.Domain also references log4net from the GAC in order to emit log output. But it doesn't have a log4net configuration. This is always provided by the assemblies using the domain assembly.

Weird because it still works in Release build on my local computer.

For the sake of completeness here's the log4net debug output where everything works just fine:

log4net: log4net assembly [log4net, Version=1.2.10.0, Culture=neutral, PublicKeyToken=1b44e1d426115821]. Loaded from [Global Assembly Cache]. (.NET Runtime [4.0.30319.225] on Microsoft Windows NT 6.1.7601 Service Pack 1)
log4net: DefaultRepositorySelector: defaultRepositoryType [log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: Creating repository for assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]
log4net: DefaultRepositorySelector: Assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] Loaded From [C:\Program Files (x86)\CRMFacade.DataImport\CRMFacade.DataImport.exe]
log4net: DefaultRepositorySelector: Assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] does not have a RepositoryAttribute specified.
log4net: DefaultRepositorySelector: Assembly [CRMFacade.DataImport, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] using repository [log4net-default-repository] and repository type [log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: Creating repository [log4net-default-repository] using type [log4net.Repository.Hierarchy.Hierarchy]
log4net: XmlConfigurator: configuring repository [log4net-default-repository] using file [C:\Program Files (x86)\CRMFacade.DataImport\CRMFacade.DataImport.exe.Config]
log4net: XmlConfigurator: configuring repository [log4net-default-repository] using stream
log4net: XmlConfigurator: loading XML configuration
log4net: XmlConfigurator: Configuring Repository [log4net-default-repository]
log4net: XmlHierarchyConfigurator: Configuration update mode [Merge].
log4net: XmlHierarchyConfigurator: Logger [root] Level string is [INFO].
log4net: XmlHierarchyConfigurator: Logger [root] level set to [name="INFO",value=40000].
log4net: XmlHierarchyConfigurator: Loading Appender [ConsoleAppender] type: [log4net.Appender.ConsoleAppender]
log4net: XmlHierarchyConfigurator: Setting Property [LevelMin] to Level value [INFO]
log4net: XmlHierarchyConfigurator: Setting Collection Property [AddFilter] to object [log4net.Filter.LevelRangeFilter]
log4net: PatternParser: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: XmlHierarchyConfigurator: Setting Property [ConversionPattern] to String value [%timestamp [%thread] %-5level %type: %message%newline]
log4net: PatternParser: Converter [timestamp] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [literal] Option [ [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [thread] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [literal] Option [] ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [level] Option [] Format [min=5,max=2147483647,leftAlign=True]
log4net: PatternParser: Converter [literal] Option [ ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [type] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [literal] Option [: ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: XmlHierarchyConfigurator: Setting Property [Layout] to object [log4net.Layout.PatternLayout]
log4net: XmlHierarchyConfigurator: Created Appender [ConsoleAppender]
log4net: XmlHierarchyConfigurator: Adding appender named [ConsoleAppender] to logger [root].
log4net: XmlHierarchyConfigurator: Loading Appender [RollingFileAppender] type: [log4net.Appender.RollingFileAppender]
log4net: XmlHierarchyConfigurator: Setting Property [File] to String value [C:\\Logfiles\\APPS\\Corporate\\CRMFacade\\DataImport\\log.txt]
log4net: XmlHierarchyConfigurator: Setting Property [AppendToFile] to Boolean value [True]
log4net: XmlHierarchyConfigurator: Setting Property [RollingStyle] to RollingMode value [Size]
log4net: XmlHierarchyConfigurator: Setting Property [MaxSizeRollBackups] to Int32 value [10]
log4net: XmlHierarchyConfigurator: Setting Property [MaximumFileSize] to String value [2MB]
log4net: XmlHierarchyConfigurator: Setting Property [StaticLogFileName] to Boolean value [True]
log4net: PatternParser: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: XmlHierarchyConfigurator: Setting Property [ConversionPattern] to String value [%date [%thread] %-5level %logger - %message%newline]
log4net: PatternParser: Converter [date] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [literal] Option [ [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [thread] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [literal] Option [] ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [level] Option [] Format [min=5,max=2147483647,leftAlign=True]
log4net: PatternParser: Converter [literal] Option [ ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [logger] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [literal] Option [ - ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: PatternParser: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: XmlHierarchyConfigurator: Setting Property [Layout] to object [log4net.Layout.PatternLayout]
log4net: RollingFileAppender: Searched for existing files in [C:\Logfiles\APPS\Corporate\CRMFacade\DataImport]
log4net: RollingFileAppender: curSizeRollBackups starts at [0]
log4net: FileAppender: Opening file for writing [C:\Logfiles\APPS\Corporate\CRMFacade\DataImport\log.txt] append [True]
log4net: XmlHierarchyConfigurator: Created Appender [RollingFileAppender]
log4net: XmlHierarchyConfigurator: Adding appender named [RollingFileAppender] to logger [root].
log4net: XmlHierarchyConfigurator: Hierarchy Threshold []

Pharsalus answered 24/6, 2011 at 10:0 Comment(0)

G

3

If you download the latest log4net code, look on the Build tab for the log4net project in Visual Studio 2010.

In Debug mode the compiler symbols are NET;NET_2_0;NET_4_0.

In Release mode NET_4_0 is missing.

Change the symbols in Release mode to NET;NET_2_0;NET_4_0 before you build a Release version and you should have no problem. Look at the file properties of the finished DLL in Windows Explorer. Under "Details" and you will see the File Description is "Apache log4net for .NET Framework 4.0"

Geochronology answered 1/12, 2011 at 23:25 Comment(2)

log4net 1.2.11 solves this problem. But since your answer pointed out the cause of the problem correctly I accepted it as the answer. Thanks! – Pharsalus 8/2, 2012 at 15:4

The NET_4_0 entry for log4net 1.2.11 is not there. I added that as suggested by @SQLDBDude. Now I see the log file created. But only the date time and thread number is written in the log file. Like the following example: 2013-03-27 18:58:27,340 [ The stack trace is not being written in the log file. – Undis 27/3, 2013 at 13:5

M

8

We experienced the same issues. It's still not clear to me what the root cause is, but we got log4net working again. We experienced the problems only in websites where we configure log4net using the XmlConfiguratorAttribute on the website assembly. We managed to work around this by calling XmlConfigurator.Configure() directly from Application_Start(). Not a pretty solution, but it seems to work.

Mopboard answered 3/11, 2011 at 13:28 Comment(1)

private static void Main(string[] args) { XmlConfigurator.Configure(); ... fixed it right up on my console app. – Cicala 15/5, 2014 at 15:44

G

3