Bug 1017881

Summary: /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler can't run under batch mode
Product: [JBoss] JBoss Enterprise Application Platform 6 Reporter: Rafael Benevides <benevides>
Component: LoggingAssignee: James Perkins <jperkins>
Status: CLOSED CURRENTRELEASE QA Contact: Nikoleta Hlavickova <nziakova>
Severity: medium Docs Contact: Russell Dickenson <rdickens>
Priority: unspecified    
Version: 6.2.0CC: brian.stansberry, jdoyle, jsenshar, kkhan, myarboro, rafael.ruiz, rsvoboda, smumford
Target Milestone: DR0Keywords: Reopened
Target Release: EAP 6.3.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
In previous versions of JBoss EAP 6, the name attribute in composite logging operations was being added to and read from the model. As a result, the last name on a composite operation was the only handler name used, resulting in the same handler naming being added multiple times. In this release, the name attribute is no longer copied to the model and is read from the operation itself. Adding handlers in a composite operation now works as expected.
Story Points: ---
Clone Of:
: 1032627 (view as bug list) Environment:
Last Closed: 2014-11-25 17:31:20 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:

Description Rafael Benevides 2013-10-10 16:45:34 UTC
Description of problem:

Any attempt to run /subsystem=logging/logger=org.jboss.as.quickstarts.logging:assign-handler(xxx on CLI under the batch gives the following error:

{"JBAS014653: Composite operation failed and was rolled back. Steps that failed:" => {"Operation step-2" => "JBAS011536: Handler XXXX is already assigned."}}

This error doens't happen if the commands are not under a batch transaction


Steps to Reproduce:
1. Checkout https://github.com/jboss-developer/jboss-eap-quickstarts/tree/master/logging
2. Execute JBOSS_HOME/bin/jboss-cli.sh --connect --file=configure-logging.cli


Actual results:
{"JBAS014653: Composite operation failed and was rolled back. Steps that failed:" => {"Operation step-2" => "JBAS011536: Handler FATAL_QS_ASYNC is already assigned."}}

Expected results:
The batch executed successfully


Additional info:

Comment 1 James Perkins 2013-10-29 16:38:10 UTC
I'm giving this a devel_ack+, but I don't think we should target EAP 6.2 for the fix. I can see what the issue is, but it needs to be thought through a bit. We can work around it by using the handlers property.

Example:
/subsystem=logging/logger=org.jboss.as.quickstarts.logging:add(level=TRACE, handlers=[TRACE_QS_ASYNC,DEBUG_QS_ASYNC,INFO_QS_ASYNC,WARN_QS_ASYNC,ERROR_QS_ASYNC,FATAL_QS_ASYNC])

One additional note about the scripts, the :reload isn't needed. All logging operations, minus a write-attribute to the asyn-handler's queue-length, are applied at runtime.

Comment 2 James Perkins 2013-10-29 16:45:44 UTC
I forgot to add. I think we should delay from EAP 6.2 because the workaround is easy enough. The error is only going to occur in composite operations when using multiple add-handler operations to the same logger. 

If we need to get this into 6.2 it is possible, but at this stage I'm not sure it's worth the change for the simple workaround. Also I doubt this use-case, adding handlers to the same logger in a composite operation, is used all that often. This same issue is present in EAP 6.1.x and it's the first time I've seen it.

Comment 4 James Perkins 2013-10-29 18:03:39 UTC
A selected the incorrect flag, I should have nack'd this one. I apologize for that.

Comment 6 Rafael Ruiz 2013-11-20 12:19:06 UTC
I have same error with EAP 6.1.1. Regardless which category you add. Putting it outside batch it works.

Comment 8 Nikoleta Hlavickova 2014-02-24 14:25:22 UTC
Verified with EAP 6.3.0 DR0

Comment 12 James Perkins 2014-11-25 17:31:20 UTC
We'll need a new issue filed for this, but FWIW I will nack it :)

The issue is operations run in phases. With these two operations we're only concerned about the MODEL phase and the RUNTIME phase. The first operation runs it's model stage and updates the model with default values. The second operation runs it's model stage and updates adds the FILE handler to the handler attribute in the model.

Next the first operations runtime phase us executed which since the model contains the attribute handlers=["FILE"] it updates the logging configuration. When the second operation executes it's runtime phase it sees the handler has already been assigned and fails. If these weren't run in a batch it would work fine.

The simple workaround is to either not batch the operations or assign a value to the handlers attribute in the add operation.

Also my original fix is wrong. I used the operation to resolve the values that need to be written. This is incorrect. I should have stuck with using the model in the runtime phase as that's the appropriate value to use.