[logback-user] Too much time for processing logback.xml

[Arioco]

Hello.

I  have  just  discovered  SLF4J  and  Logback  and  I  am  testing  it  in 
local  before  using  it  in  my  projects.

I  downloaded  SLF4J  1.7.5  and  Logback  1.0.13,  created  a  new  project 
in  Eclipse  with  workspace  in  local,  put  slf4j-api-1.7.5.jar, 
logback-classic-1.0.13.jar  and  logback-core-1.0.13.jar  in  CLASSPATH  and 
wrote  a  very  simple  test  class:

package  com.compa.prueba.logging.slf4j;

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

public  class  Pruebas  {
	private  final  static  Logger  logger  = 
LoggerFactory.getLogger(Pruebas.class);
	
	public  static  void  main(String...  args)  {
		logger.info("let  me  see...");
		logger.debug("\\{}  {}  {}  {}  {}  {}",  "1",  2, new  Double(3),  "4", 
"5");
	}
}

Everything  was  just  fine,  execution  time  was  almost  nothing  (of 
course)  until  I  added  a  logback.xml  file.  Since  then  I  got  a  10 
secs  longer  startup  time.

I  found  a  post  with  a  problem  very  similar  to  mine,  but  with  no 
answer  to  me:

http://logback.10977.n7.nabble.com/Elongated-system-startup-time-because-of-Logback-configuration-td1151.html  

I  have  been  doing  a  bunch  of  tests  and  I  think  problem  is 
XML-processing-time,  and  I  don't  have  a  clue  about  why.  Briefing:

*  Replace  Logback  with  NOP:  execution  time  0.x  milisecs
*  Delete  logback.xml  file  from  classpath:  execution  time  0.x 
milisecs
*  Adding  debug="true"  to  configuration  tag.  Here  is  where  I  am 
now.

My  actual  logback.xml  file  is:

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %logger{36} -
%msg%n</pattern>
		</encoder>
	</appender>
	
	<root level="debug">
		<appender-ref ref="STDOUT" />
	</root>
</configuration>

And  after  execution  my  console  shows  this:

12:55:41,819 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could
NOT find resource [logback.groovy]
12:55:41,819 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could
NOT find resource [logback-test.xml]
*12:55:41,819* |-INFO in ch.qos.logback.classic.LoggerContext[default] -
Found resource [logback.xml] at
[file:/Volumes/Macintosh%20HD/workspace/PruebaLogging/bin/logback.xml]
*12:55:51,925* |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
12:55:51,929 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
Naming appender as [STDOUT]
12:55:51,951 |-INFO in
ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default
type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder]
property
12:55:51,998 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction
- Setting level of ROOT logger to DEBUG
12:55:51,999 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction -
Attaching appender named [STDOUT] to Logger[ROOT]
12:55:51,999 |-INFO in
ch.qos.logback.classic.joran.action.ConfigurationAction - End of
configuration.
12:55:52,001 |-INFO in
ch.qos.logback.classic.joran.JoranConfigurator at 4b9237a - Registering current
configuration as safe fallback point
2013-07-13 12:55:52.005 INFO  c.compa.prueba.logging.slf4j.Pruebas - let  me 
see...
2013-07-13 12:55:52.008 DEBUG c.compa.prueba.logging.slf4j.Pruebas - {}  1 
2  3.0  4  5

I  highlighted  two  timestamps  in  log  output  just  for  pointing  the 
10  secs  difference.  A  very  curious  fact  is  that  delay  is  always 
10  secs,  no  matter  how  many  times  I  execute.

I  hope  I  have  write  information  enough  for  you  to  help  me.

Thank  you  very  much  to  all.

Regards

Carlos



--
View this message in context: http://logback.10977.n7.nabble.com/Too-much-time-for-processing-logback-xml-tp12674.html
Sent from the Users mailing list archive at Nabble.com.