logwizard icon indicating copy to clipboard operation
logwizard copied to clipboard

Published 20 hours ago • verified publisher icon jtorjo

Log4Net - xml errors and patternLayout is not showing "Level", file pattern look ok but view is not eq.

Open robgha01 opened this issue 8 years ago • 3 comments

I get a fatal error using umbraco which uses log4net.

Here is some entries from the log: using XmlLayout

<log4net:event logger="Umbraco.Core.CoreBootManager" timestamp="2017-01-28T20:24:14.3063983+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Umbraco 7.5.7 application starting on ARES</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.3373991+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Determining hash of code files on disk</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.3529119+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Hash determined (took 14ms)</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.MainDom" timestamp="2017-01-28T20:24:14.4224246+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Acquiring MainDom...</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.MainDom" timestamp="2017-01-28T20:24:14.4254253+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Acquired MainDom.</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.4334254+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Starting resolution types of umbraco.interfaces.IApplicationStartupHandler</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.6324789+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 199ms)</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.6554887+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.6630346+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 7ms)</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.6640351+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.PluginManager" timestamp="2017-01-28T20:24:14.6730363+01:00" level="INFO" thread="1" domain="/LM/W3SVC/4/ROOT-1-131301050409526170"><log4net:message>Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 9ms)</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="2" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>
<log4net:event logger="Umbraco.Core.UmbracoApplicationBase" timestamp="2017-01-28T20:34:27.1200017+01:00" level="INFO" thread="62" domain="/LM/W3SVC/4/ROOT-3-131301050731010914"><log4net:message>Application shutdown. Details: ConfigurationChange

_shutDownMessage=CONFIG change
HostingEnvironment initiated shutdown
CONFIG change
CONFIG change
HostingEnvironment orsakade avslut

_shutDownStack=   vid System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
   vid System.Environment.get_StackTrace()
   vid System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal()
   vid System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand()
   vid System.Web.HttpRuntime.ShutdownAppDomain(String stackTrace)
   vid System.Web.Configuration.HttpConfigurationSystem.OnConfigurationChanged(Object sender, InternalConfigEventArgs e)
   vid System.Configuration.Internal.InternalConfigRoot.OnConfigChanged(InternalConfigEventArgs e)
   vid System.Configuration.BaseConfigurationRecord.OnStreamChanged(String streamname)
   vid System.Web.DirectoryMonitor.FireNotifications()
   vid System.Web.Util.WorkItem.CallCallbackWithAssert(WorkItemCallback callback)
   vid System.Web.Util.WorkItem.OnQueueUserWorkItemCompletion(Object state)
   vid System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   vid System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   vid System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
   vid System.Threading.ThreadPoolWorkQueue.Dispatch()</log4net:message><log4net:properties><log4net:data name="processId" value="14900" /><log4net:data name="appDomainId" value="4" /><log4net:data name="log4net:HostName" value="ares" /></log4net:properties></log4net:event>

<?xml version="1.0"?>
<log4net>
  <root>
    <priority value="Info" />
    <appender-ref ref="AsynchronousLog4NetAppender" />
  </root>
  <appender name="rollingFile" type="log4net.Appender.RollingFileAppender">
    <file type="log4net.Util.PatternString" value="App_Data\Logs\UmbracoTraceLog.%property{log4net:HostName}.txt" />
    <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
    <appendToFile value="true" />
    <rollingStyle value="Date" />
    <maximumFileSize value="5MB" />
    <layout type="log4net.Layout.XmlLayout" />
    <encoding value="utf-8" />
  </appender>
  <appender name="AsynchronousLog4NetAppender" type="Umbraco.Core.Logging.ParallelForwardingAppender,Umbraco.Core">
    <appender-ref ref="rollingFile" />
  </appender>
  <logger name="NHibernate">
    <level value="WARN" />
  </logger>
</log4net>

When i use the default settings:

<layout type="log4net.Layout.PatternLayout">
      <conversionPattern value=" %date [P%property{processId}/D%property{appDomainId}/T%thread] %-5level %logger - %message%newline" />
    </layout>

it seams to load but the level field is empty. image

The log is like this if not xml:

2017-01-28 20:48:05,140 [P14900/D5/T1] INFO  Umbraco.Core.CoreBootManager - Umbraco 7.5.7 application starting on ARES
2017-01-28 20:48:05,158 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Determining hash of code files on disk
2017-01-28 20:48:05,165 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Hash determined (took 6ms)
2017-01-28 20:48:05,206 [P14900/D5/T1] INFO  Umbraco.Core.MainDom - Acquiring MainDom...
2017-01-28 20:48:05,206 [P14900/D5/T1] INFO  Umbraco.Core.MainDom - Acquired MainDom.
2017-01-28 20:48:05,219 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2017-01-28 20:48:05,232 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 13ms)
2017-01-28 20:48:05,238 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2017-01-28 20:48:05,239 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 1ms)
2017-01-28 20:48:05,240 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
2017-01-28 20:48:05,241 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 1ms)
2017-01-28 20:48:05,250 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2017-01-28 20:48:05,251 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 0ms)
2017-01-28 20:48:05,252 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
2017-01-28 20:48:05,253 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 1ms)
2017-01-28 20:48:05,255 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2017-01-28 20:48:05,256 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 1ms)
2017-01-28 20:48:05,256 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2017-01-28 20:48:05,257 [P14900/D5/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 0ms)

robgha01 avatar Jan 28 '17 19:01 robgha01

I managed to fix the text usage when the data was not in xml: using $date[1,' '] $time['',' '] $ctx1['[',']'] $level['',' '] $class['',' '] $msg

Great application! i dont need the xml output but it dide throw for some odd reason :)

robgha01 avatar Jan 28 '17 20:01 robgha01

Ok, someting else happen when i used that pattern while out of preview... it loaded ctx1 ctx2 ..3 ..4 without stop xD then crashed. this only happens when i have the log file opened and change the pattern at "Edit Log Settings" image then it results to: image image

when i reopen the file it all seams to work and shows: image however ctx is gone.

robgha01 avatar Jan 28 '17 20:01 robgha01

Ok, i cant seam to get this to work how should the pattern look like this "$date[0,12] $time[12,' '] $ctx1['[','] '] $level['',' '] $class['',' '] $msg" clearly only work in the preview but not in the actual view... as i get this in the view image

robgha01 avatar Jan 28 '17 20:01 robgha01