0

I wrote crawlers for 3 different sites and run the crawlers in 3 threads. For each crawler I use single logger. My 'log4j.properties' file looks like:

log4j.rootLogger=TRACE, ZDNET, CNET, GOOGLEPLAY

log4j.appender.ZDNET=org.apache.log4j.RollingFileAppender
log4j.appender.ZDNET.File=logs/zdnet.log
log4j.appender.ZDNET.MaxFileSize=20MB
log4j.appender.ZDNET.MaxBackupIndex=100
log4j.appender.ZDNET.layout=org.apache.log4j.PatternLayout
log4j.appender.ZDNET.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p - %m%n

log4j.appender.CNET=org.apache.log4j.RollingFileAppender
log4j.appender.CNET.File=logs/cnet.log
log4j.appender.CNET.MaxFileSize=20MB
log4j.appender.CNET.MaxBackupIndex=100
log4j.appender.CNET.layout=org.apache.log4j.PatternLayout
log4j.appender.CNET.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p - %m%n

log4j.appender.GOOGLEPLAY=org.apache.log4j.RollingFileAppender
log4j.appender.GOOGLEPLAY.File=logs/googlePlay.log
log4j.appender.GOOGLEPLAY.MaxFileSize=20MB
log4j.appender.GOOGLEPLAY.MaxBackupIndex=100
log4j.appender.GOOGLEPLAY.layout=org.apache.log4j.PatternLayout
log4j.appender.GOOGLEPLAY.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p - %m%n

log4j.category.zdNetLogger=DEBUG, ZDNET
log4j.additivity.zdNetLogger=false

log4j.category.cNetLogger=DEBUG, CNET
log4j.additivity.cNetLogger=false

log4j.category.googlePlayLogger=DEBUG, GOOGLEPLAY
log4j.additivity.googlePlayLogger=false

In java, i use the following code for writing my logs

final Logger APK_LOG = Logger.getLogger("googlePlayLogger");
final Logger C_NET_LOG = Logger.getLogger("cNetLogger");
final Logger ZD_NET_LOG = Logger.getLogger("zdNetLogger");
....
ZD_NET_LOG.info("1");
C_NET_LOG.info("2");
APK_LOG.info("3");

Everything worked fine, until I began to use Selenium + HtmlUnit + HtmlUnitDriver. After that, when i run my program, 3 log files (zdnet.log, cnet.log, googlePlay.log) filled by logs from HtmlUnitDriver. Log info from my files (zdnet.log, cnet.log, googlePlay.log) after that:

2015-06-16 02:47:08 DEBUG - Get page for window named '', using WebRequest[<url="about:blank", GET, EncodingType[name=application/x-www-form-urlencoded], [], {Accept=image/gif, image/jpeg, image/pjpeg, image/pjpeg, */*, Accept-Encoding=gzip, deflate}, null>]
2015-06-16 02:47:08 DEBUG - setEnclosedPage: HtmlPage(about:blank)@945834833
2015-06-16 02:47:08 DEBUG - destroyChildren
2015-06-16 02:47:08 DEBUG - Encoding found in HTTP headers: 'UTF-8'.
2015-06-16 02:47:08 DEBUG - Mapping java.lang.Object to HTMLCollection
2015-06-16 02:47:08 DEBUG - Mapping com.gargoylesoftware.htmlunit.html.HtmlSpan to HTMLSpanElement

Any ideas why it happens?

Yakiv Holovko
  • 421
  • 2
  • 5
  • 11

1 Answers1

0

Because both HttpClient and HtmlUnit uses log4j to also write their logs.

Your rootLogger defines trace level, so it writes everything.

Please add the below to allow only error level messages for HttpClient and HtmlUnit.

log4j.logger.com.gargoylesoftware.htmlunit=error
log4j.logger.org.apache.http=error
Ahmed Ashour
  • 5,179
  • 10
  • 35
  • 56
  • Ok, thanks. But it's not good for me. Because in first 10 seconds i got ~100 lines with 'error' logs (but all works fine). `log4j.logger.com.gargoylesoftware.htmlunit=OFF` `log4j.logger.org.apache.http=OFF` solved my problem. – Yakiv Holovko Jun 16 '15 at 09:50