[jboss-jira] [JBoss JIRA] (WFLY-7462) Do not log common CLI failures for Elytron to server log

Fri Nov 4 04:22:00 EDT 2016

    [ https://issues.jboss.org/browse/WFLY-7462?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13317306#comment-13317306 ] 

Ondrej Lukas commented on WFLY-7462:
------------------------------------

[~brian.stansberry] It is interesting. I see this issue also in current WildFly build from master (SHA of last commit - {{a0038b04fef3c1822abd823ed35944be7650f8ab}}). 

I am starting WildFly with standalone-elytron.xml. Start jboss-cli.sh and execute command mentioned in "Steps to Reproduce". Following occurs in server log:
{code}
ERROR [org.jboss.as.controller.management-operation] (management-handler-thread - 1) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "elytron"),
    ("properties-realm" => "realm")
]) - failure description: "WFLYCTL0155: path may not be null"
{code}

I looked again on this issue and it starts to be a little tricky here. Probably some validation occurs on CLI level which sometimes does not propagete exception to server log.

In case, when some required attribute of resource is missing, then it is probably validate by CLI and exception does not occurs in server log. Example:
{code}
/subsystem=elytron/properties-realm=realm:add()
{
    "outcome" => "failed",
    "failure-description" => "WFLYCTL0155: users-properties may not be null",
    "rolled-back" => true
}
{code}
Attribute {{users-properties}} from resource {{properties-realm}} is missing, but no exception occurs.

In case when some required attribute of any attribute of resource is missing, then exception occurs in server log. Example:
{code}
/subsystem=elytron/properties-realm=realm:add(users-properties={})   
{
    "outcome" => "failed",
    "failure-description" => "WFLYCTL0155: path may not be null",
    "rolled-back" => true
}
{code}
Attribute {{path}} from attribute {{users-properties}} from resource {{properties-realm}} is missing and server log contains:
{code}
ERROR [org.jboss.as.controller.management-operation] (management-handler-thread - 1) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "elytron"),
    ("properties-realm" => "realm")
]) - failure description: "WFLYCTL0155: path may not be null"
{code}

One of another possibility how to reproduce this issue is use the duplicate service (when I reported this issue, I incorrectly thought that duplicate resource causes ERROR in server log. It is caused by duplicate service - I will fix description). In case when you add ldap-realm with the same name as some properties-realm, then ERROR message also occurs in server log. Run server with standalone-elytron.xml (which already includes properties-realm=ManagementRealm) and run following commands:
{code}
/subsystem=elytron/dir-context=dir:add(url=localhost)
/subsystem=elytron/ldap-realm=ManagementRealm:add(dir-context=dir,identity-mapping={rdn-identifier=uid})
{
    "outcome" => "failed",
    "failure-description" => "WFLYCTL0158: Operation handler failed: org.jboss.msc.service.DuplicateServiceException: Service org.wildfly.security.security-realm.ManagementRealm is already registered",
    "rolled-back" => true
}
{code}
you will see in server log:
{code}
ERROR [org.jboss.as.controller.management-operation] (management-handler-thread - 8) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "elytron"),
    ("ldap-realm" => "ManagementRealm")
]): org.jboss.msc.service.DuplicateServiceException: Service org.wildfly.security.security-realm.ManagementRealm is already registered
	at org.jboss.msc.service.ServiceRegistrationImpl.setInstance(ServiceRegistrationImpl.java:158)
	at org.jboss.msc.service.ServiceControllerImpl.startInstallation(ServiceControllerImpl.java:239)
	at org.jboss.msc.service.ServiceContainerImpl.install(ServiceContainerImpl.java:768)
	at org.jboss.msc.service.ServiceTargetImpl.install(ServiceTargetImpl.java:223)
	at org.jboss.msc.service.ServiceControllerImpl$ChildServiceTarget.install(ServiceControllerImpl.java:2416)
	at org.jboss.msc.service.ServiceTargetImpl.install(ServiceTargetImpl.java:223)
	at org.jboss.msc.service.ServiceControllerImpl$ChildServiceTarget.install(ServiceControllerImpl.java:2416)
	at org.jboss.msc.service.ServiceBuilderImpl.install(ServiceBuilderImpl.java:317)
	at org.jboss.as.controller.OperationContextImpl$ContextServiceBuilder.install(OperationContextImpl.java:2174)
	at org.wildfly.extension.elytron.LdapRealmDefinition$RealmAddHandler.performRuntime(LdapRealmDefinition.java:378)
	at org.jboss.as.controller.AbstractAddStepHandler.performRuntime(AbstractAddStepHandler.java:337)
	at org.jboss.as.controller.AbstractAddStepHandler$1.execute(AbstractAddStepHandler.java:151)
	at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:940)
	at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:683)
	at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:382)
	at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1361)
	at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:411)
	at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:233)
	at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler.doExecute(ModelControllerClientOperationHandler.java:213)
	at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler.access$300(ModelControllerClientOperationHandler.java:136)
	at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1$1.run(ModelControllerClientOperationHandler.java:157)
	at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1$1.run(ModelControllerClientOperationHandler.java:153)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:422)
	at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:149)
	at org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1.execute(ModelControllerClientOperationHandler.java:153)
	at org.jboss.as.protocol.mgmt.ManagementRequestContextImpl$1.doExecute(ManagementRequestContextImpl.java:70)
	at org.jboss.as.protocol.mgmt.ManagementRequestContextImpl$AsyncTaskRunner.run(ManagementRequestContextImpl.java:160)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
	at org.jboss.threads.JBossThread.run(JBossThread.java:320)
{code}

> Do not log common CLI failures for Elytron to server log
> --------------------------------------------------------
>
>                 Key: WFLY-7462
>                 URL: https://issues.jboss.org/browse/WFLY-7462
>             Project: WildFly
>          Issue Type: Bug
>          Components: Security
>    Affects Versions: 11.0.0.Alpha1
>            Reporter: Ondrej Lukas
>            Assignee: Darran Lofthouse
>            Priority: Critical
>              Labels: user_experience
>
> Almost every common CLI command failure from Elytron subsystem is logged as ERROR to server log. For example this means:
> * trying to add duplicate resource -> ERROR in server log
> * missing required attribute of any resource attribute in CLI command -> ERROR in server log
> * missing capability -> ERROR in server log
> * ...
> Some reasons why these logs should not be logged to server log:
> * Adding useless messages to server log.
> * This is inconsistent with other subsystems (e.g. PicketBox). It can be confusing.
> These common CLI command failures should be removed from the log, or logged on low level (i.e. DEBUG)

--
This message was sent by Atlassian JIRA
(v7.2.3#72005)