(BSM) Support Tip : BSM 9.26 IP1 - <BSM>\log\opr-backend_boot.log is flooded with Autopass messages

After upgrading to BSM 9.26 IP1 a change in the behavior of the <process>_boot.log has been observed.
In previous versions, after the process started successfully, the corresponding *_boot.log remained more or less “quiet”.

Now with 9.26, one can find a huge number of messages in opr-backend_boot.log AFTER the process has been started:

2016-04-22 10:20:26,431 - - [com.hp.autopassj.core.enforce.Enforcer : com.hp.autopassj.core.enforce.Enforcer] :: productDefinition is not null
2016-04-22 10:20:26,431 - - [com.hp.autopassj.core.license.LicenseStore : getLicenses] :: Reading Liceneses from Memory Store as Data Source is not Modifed since Last read
2016-04-22 10:20:26,431 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Process rules
2016-04-22 10:20:26,432 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Applying feature rule for rule number: '1'
2016-04-22 10:20:26,432 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Applying feature rule for rule number: '2'
2016-04-22 10:20:26,432 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Applying capacity rule for rule number: '2'
..
2016-04-22 10:20:26,433 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Applying feature rule for rule number: '7'
2016-04-22 10:20:26,433 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Applying capacity rule for rule number: '7'
2016-04-22 10:20:26,433 - - [com.hp.autopassj.core.enforce.engine.RuleEngine : getFinalLicenses] :: Processing rules ends successfully
2016-04-22 10:20:26,433 - - [com.hp.autopassj.core.LicenseHandler : getLicenseDetail] :: Getting detail license status done successfully
2016-04-22 10:20:26,434 - - Finished to load cache for customers:[1] it took:2440 milis
2016-04-22 10:22:25,985 - - jdbc[3]
2016-04-22 10:22:25,985 - /*SQL l:281 #:1 t:1*/SELECT \"a.id\", \"a.timeCreated\" FROM IMDB_EVENTS WHERE ((\"a.state\" in (?, ?, ?)) and (not (((\"a1.key\" is null and \"a0.key\" = ?) or (\"a1.key\" is not null and \"a1.key\" = ?))))) AND (((\"a0.key\" like ?))) AND \"a.sequenceNumber\" < ? ORDER BY \"a.timeCreated\" DESC, \"a.sequenceNumber\" DESC {1: 0, 2: 1, 3: 2, 4: '', 5: NULL, 6: '`454c5d76e98228f5e3b2998929bd17:Synthetic_User_Transaction_Performance%', 7: 486791};
2016-04-22 10:22:25,985 - - jdbc[5]

One logfile can reach the 2 MB size limit within seconds, so the logs are rewritten over and over again, potentially harming the performance.


This is a known issue and reported via
 QCCR8D41264 CHO Testing: DPS writes lots of log entries to opr-backend_boot.log

As a workaround one can change the loglevel of Autopass to Error

There are four log4j properties files which deal with Autopass,
  <HPBSM>\conf\core\Tools\log4j\configserver\license.properties
  <HPBSM>\conf\core\Tools\log4j\hpbsm_upgrade_wizard\license.properties
  <HPBSM>\conf\core\Tools\log4j\postinstall\license.properties
  <HPBSM>\conf\core\Tools\log4j\EJB\license.properties

Edit <HPBSM>\conf\core\Tools\log4j\EJB\license.properties and change the two lines

 licensemgr.loglevel=WARN
and
 log4j.category.com.hp.autopassj=WARN, autopass.appender

to
 licensemgr.loglevel=ERROR
and
 log4j.category.com.hp.autopassj=ERROR, autopass.appender

Save the changes.
After two minutes these entries will no longer be written to the logfile.

Note:
It turned out that this not / not always works.
Here is the complete workaround:

the logging config for autopass is missing from the opr-backend log4j directory.
As not even some rules for the root logger have been specified, logging targets without any rule are written to stdout. And stdout (by default) is captured by nanny and put into the ..._boot.log.

To fix this issue for autopass alone, create a .properties file (for example autopass.properties) in the log4j\opr-backend directory with this content:

..
### autopass - log Properties

log.file.path=log/${log.folder.path.output}
autopass.loglevel=ERROR
def.file.max.size=10MB
def.files.backup.count=5
msg.layout=%d [%t] (%F:%L) %-5p - %m%n

log4j.category.com.hp.autopassj=${autopass.loglevel}, autopass.appender
log4j.additivity.com.hp.autopassj=false

###############################################
### define appender: autopass.appender ###
###############################################
log4j.appender.autopass.appender=org.apache.log4j.RollingFileAppender
log4j.appender.autopass.appender.File=${merc.home}/${log.file.path}/autopass.log
log4j.appender.autopass.appender.MaxFileSize=${def.file.max.size}
log4j.appender.autopass.appender.MaxBackupIndex=${def.files.backup.count}
log4j.appender.autopass.appender.layout=org.apache.log4j.PatternLayout
log4j.appender.autopass.appender.layout.ConversionPattern=${msg.layout}
..

To fix this for autopass and the license manager, create a .properties file (for example license.properties) in the log4j\opr-backend directory with this content:

..
### license manager - log Properties
log.file.path=log/${log.folder.path.output}
#loglevel can be any of DEBUG INFO WARN ERROR FATAL
licensemgr.loglevel=ERROR
def.file.max.size=900KB
def.files.backup.count=5
msg.layout=%d [%t] (%F:%L) %-5p - %m%n
simple.msg.layout=%d  %m%n

log4j.category.com.hp.bsm.platform.license=${licensemgr.loglevel}, licensemgr.appender
log4j.category.com.hp.autopassj=ERROR, autopass.appender
log4j.additivity.com.hp.autopassj=false
#license management UI
log4j.category.com.hp.bsm.platform.license.server=${licensemgr.loglevel}, licensemgr.appender
###############################################
### define appender: licensemgr.appender ###
###############################################
log4j.appender.licensemgr.appender=org.apache.log4j.RollingFileAppender
log4j.appender.licensemgr.appender.File=${merc.home}/${log.file.path}/licensemgr.log
log4j.appender.licensemgr.appender.MaxFileSize=${def.file.max.size}
log4j.appender.licensemgr.appender.MaxBackupIndex=${def.files.backup.count}
log4j.appender.licensemgr.appender.layout=org.apache.log4j.PatternLayout
log4j.appender.licensemgr.appender.layout.ConversionPattern=${msg.layout}
###############################################
### define appender: autopass.appender ###
###############################################
log4j.appender.autopass.appender=org.apache.log4j.RollingFileAppender
log4j.appender.autopass.appender.File=${merc.home}/${log.file.path}/autopass.log
log4j.appender.autopass.appender.MaxFileSize=${def.file.max.size}
log4j.appender.autopass.appender.MaxBackupIndex=${def.files.backup.count}
log4j.appender.autopass.appender.layout=org.apache.log4j.PatternLayout
log4j.appender.autopass.appender.layout.ConversionPattern=${msg.layout}
..
To fix it for all possibly lost classes, define a root logger like this (put this in a file named root.properties, for example):

..
### root logger

log.file.path=log/${log.folder}
root.loglevel=ERROR
def.file.max.size=10MB
def.files.backup.count=5
msg.layout=%d [%t] (%F:%L) %-5p - %m%n

log4j.rootCategory=${root.loglevel}, root.appender

###########################################
### root.appender                       ###
###########################################
log4j.appender.root.appender=org.apache.log4j.RollingFileAppender
log4j.appender.root.appender.File=${merc.home}/${log.file.path}/root.log
log4j.appender.root.appender.MaxFileSize=${def.file.max.size}
log4j.appender.root.appender.MaxBackupIndex=${def.files.backup.count}
log4j.appender.root.appender.layout=org.apache.log4j.PatternLayout
log4j.appender.root.appender.layout.ConversionPattern=${msg.layout}
..

Greetings
Siggi