Bug 1017762

Summary: Errors in logging quickstart example
Product: [JBoss] JBoss Enterprise Application Platform 6 Reporter: Vladimir Rastseluev <vrastsel>
Component: QuickstartsAssignee: Rafael Benevides <benevides>
Status: CLOSED CURRENTRELEASE QA Contact: Vladimir Rastseluev <vrastsel>
Severity: medium Docs Contact: Russell Dickenson <rdickens>
Priority: unspecified    
Version: 6.2.0CC: bsutter, dosoudil, jkudrnac, myarboro, pmuir, pslavice, sgilda, vrastsel
Target Milestone: ER7   
Target Release: EAP 6.2.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-12-15 16:23:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1010473    

Description Vladimir Rastseluev 2013-10-10 13:11:38 UTC
Version:
EAP 6.2.0 ER5.1

Description of problem:
Following instructions from logging quickstart example README file I tried to change logging on server as described.
After adding lines to the logging.properties file I started server and I see in log these lines:
Handler FILEFILE_QS_WARN is not defined
Formatter PATTERN is not defined
Formatter PATTERN is not defined
Formatter PATTERN is not defined
Formatter PATTERN is not defined
Formatter PATTERN is not defined

Moreover, when I tried to execute cli script it failed:
[vrastsel@war logging]$ /home/vrastsel/jboss-eap-6.2/bin/jboss-cli.sh --connect --file=configure-logging.cli
#1 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_TRACE:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.trace.log", "relative-to"=>"jboss.server.log.dir"})
#2 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_DEBUG:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.debug.log", "relative-to"=>"jboss.server.log.dir"})
#3 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_INFO:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.info.log", "relative-to"=>"jboss.server.log.dir"})
#4 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_WARN:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.warn.log", "relative-to"=>"jboss.server.log.dir"})
#5 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_ERROR:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.error.log", "relative-to"=>"jboss.server.log.dir"})
#6 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_FATAL:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.fatal.log", "relative-to"=>"jboss.server.log.dir"})
#7 /subsystem=logging/async-handler=TRACE_QS_ASYNC:add(level=TRACE,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_TRACE"])
#8 /subsystem=logging/async-handler=DEBUG_QS_ASYNC:add(level=DEBUG,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_DEBUG"])
#9 /subsystem=logging/async-handler=INFO_QS_ASYNC:add(level=INFO,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_INFO"])
#10 /subsystem=logging/async-handler=WARN_QS_ASYNC:add(level=WARN,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_WARN"])
#11 /subsystem=logging/async-handler=ERROR_QS_ASYNC:add(level=ERROR,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_ERROR"])
#12 /subsystem=logging/async-handler=FATAL_QS_ASYNC:add(level=FATAL,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_FATAL"])
#13 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:add(level=TRACE)
The batch executed successfully
#1 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="TRACE_QS_ASYNC")
#2 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="DEBUG_QS_ASYNC")
#3 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="INFO_QS_ASYNC")
#4 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="WARN_QS_ASYNC")
#5 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="ERROR_QS_ASYNC")
#6 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="FATAL_QS_ASYNC")
{"JBAS014653: Composite operation failed and was rolled back. Steps that failed:" => {"Operation step-2" => "JBAS011536: Handler FATAL_QS_ASYNC is already assigned."}}

Comment 1 sgilda 2013-10-10 15:13:49 UTC
Rafael agreed to look at this one for me.

Comment 2 Rafael Benevides 2013-10-10 15:57:47 UTC
I've opened the following PR: https://github.com/jboss-developer/jboss-eap-quickstarts/pull/667

But it seems that there's a BUG on EAP 6.2 that avoid running these commands [1] on a batch. So I've commented it.

[1] https://github.com/rafabene/jboss-eap-quickstarts/blob/3a3749a73a22034f558b25b73cfcc034632941a4/logging/configure-logging.cli#L30-L42

Comment 3 Rafael Benevides 2013-10-10 16:46:41 UTC
This Quickstart was designed to run on JBoss AS 7.1 that comes with the following lines on logging.properties

# Formatter pattern configuration
formatter.PATTERN=org.jboss.logmanager.formatters.PatternFormatter
formatter.PATTERN.properties=pattern
formatter.PATTERN.pattern=%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n

On EAP 6.1 and 6.2 this line isn't present which caused the quickstarts to fail. So I changed it to use formatter FILE instead of PATTERN.

The following FILE formatter is present in EAP:

formatter.FILE=org.jboss.logmanager.formatters.PatternFormatter
formatter.FILE.properties=pattern
formatter.FILE.constructorProperties=pattern
formatter.FILE.pattern=%d{HH\:mm\:ss,SSS} %-5p [%c] (%t) %s%E%n

Comment 4 sgilda 2013-10-15 11:35:02 UTC
This quickstart was removed from the beta build so it should no longer be a beta blocking bug. However, this was fixed and the quickstart will be returned to the build for ER6 and this must remain open for verification.

Comment 5 Vladimir Rastseluev 2013-10-18 10:21:34 UTC
Tested on EAP 6.2. ER6.
CLI script execution is still failing and there aren't handlers in standalone.xml:
[vrastsel@war logging]$ /home/vrastsel/jboss-eap-6.2/bin/jboss-cli.sh --connect --file=configure-logging.cli
#1 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_TRACE:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.trace.log", "relative-to"=>"jboss.server.log.dir"})
#2 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_DEBUG:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.debug.log", "relative-to"=>"jboss.server.log.dir"})
#3 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_INFO:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.info.log", "relative-to"=>"jboss.server.log.dir"})
#4 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_WARN:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.warn.log", "relative-to"=>"jboss.server.log.dir"})
#5 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_ERROR:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.error.log", "relative-to"=>"jboss.server.log.dir"})
#6 /subsystem=logging/periodic-rotating-file-handler=FILE_QS_FATAL:add(suffix=".yyyy.MM.dd", file={"path"=>"quickstart.fatal.log", "relative-to"=>"jboss.server.log.dir"})
#7 /subsystem=logging/async-handler=TRACE_QS_ASYNC:add(level=TRACE,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_TRACE"])
#8 /subsystem=logging/async-handler=DEBUG_QS_ASYNC:add(level=DEBUG,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_DEBUG"])
#9 /subsystem=logging/async-handler=INFO_QS_ASYNC:add(level=INFO,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_INFO"])
#10 /subsystem=logging/async-handler=WARN_QS_ASYNC:add(level=WARN,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_WARN"])
#11 /subsystem=logging/async-handler=ERROR_QS_ASYNC:add(level=ERROR,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_ERROR"])
#12 /subsystem=logging/async-handler=FATAL_QS_ASYNC:add(level=FATAL,queue-length=1024,overflow-action=BLOCK,subhandlers=["FILE_QS_FATAL"])
#13 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:add(level=TRACE)
The batch executed successfully
#1 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="TRACE_QS_ASYNC")
#2 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="DEBUG_QS_ASYNC")
#3 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="INFO_QS_ASYNC")
#4 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="WARN_QS_ASYNC")
#5 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="ERROR_QS_ASYNC")
#6 /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(name="FATAL_QS_ASYNC")
{"JBAS014653: Composite operation failed and was rolled back. Steps that failed:" => {"Operation step-2" => "JBAS011536: Handler FATAL_QS_ASYNC is already assigned."}}

Comment 6 Rafael Benevides 2013-10-18 13:43:22 UTC
For the CLI failure I opened the following BUG: https://bugzilla.redhat.com/show_bug.cgi?id=1017881.

Comment 9 Vladimir Rastseluev 2013-11-01 14:23:21 UTC
Verified on EAP 6.2 ER7