diff --git a/controller/src/main/java/org/jboss/as/controller/AbstractOperationContext.java b/controller/src/main/java/org/jboss/as/controller/AbstractOperationContext.java index e280e2ea6f6..e16013e498d 100644 --- a/controller/src/main/java/org/jboss/as/controller/AbstractOperationContext.java +++ b/controller/src/main/java/org/jboss/as/controller/AbstractOperationContext.java @@ -97,9 +97,11 @@ import org.jboss.as.controller.registry.NotificationEntry; import org.jboss.as.controller.registry.OperationEntry; import org.jboss.as.controller.registry.Resource; +import org.jboss.as.core.security.AccessMechanism; import org.jboss.as.protocol.StreamUtils; import org.jboss.dmr.ModelNode; import org.jboss.dmr.Property; +import org.jboss.logging.Logger; import org.jboss.msc.service.ServiceController; import org.jboss.msc.service.ServiceTarget; import org.wildfly.common.Assert; @@ -1063,9 +1065,8 @@ private void executeStep(final Step step) { try { step.handler.execute(this, step.operation); // AS7-6046 - if (isErrorLoggingNecessary() && step.hasFailed()) { - MGMT_OP_LOGGER.operationFailed(step.operation.get(OP), step.operation.get(OP_ADDR), - step.response.get(FAILURE_DESCRIPTION)); + if (step.hasFailed()) { + logStepFailure(step, false); } if (step.serviceVerificationHelper != null) { addStep(step.serviceVerificationHelper, Stage.VERIFY); @@ -1077,21 +1078,15 @@ private void executeStep(final Step step) { } } catch (Throwable t) { - // If t doesn't implement OperationClientException marker interface, throw it on to outer catch block + // If it doesn't implement OperationClientException marker interface, throw it on to outer catch block if (!(t instanceof OperationClientException)) { throw t; } // Handler threw OCE; that's equivalent to a request that we set the failure description final ModelNode failDesc = OperationClientException.class.cast(t).getFailureDescription(); step.response.get(FAILURE_DESCRIPTION).set(failDesc); - if (isErrorLoggingNecessary()) { - MGMT_OP_LOGGER.operationFailed(step.operation.get(OP), step.operation.get(OP_ADDR), - step.response.get(FAILURE_DESCRIPTION)); - } else { - // A client-side mistake post-boot that only affects model, not runtime, is logged at DEBUG - MGMT_OP_LOGGER.operationFailedOnClientError(step.operation.get(OP), step.operation.get(OP_ADDR), - step.response.get(FAILURE_DESCRIPTION)); - } + + logStepFailure(step, true); } } catch (Throwable t) { // Handling for throwables that don't implement OperationClientException marker interface @@ -1134,15 +1129,45 @@ void addModifiedResourcesForModelValidation(Set modifiedResources) } } - /** Whether ERROR level logging is appropriate for any operation failures*/ - private boolean isErrorLoggingNecessary() { - // Log for any boot failure or for any failure that may affect this processes' runtime services. + private void logStepFailure(Step step, boolean clienterror) { + + // The level we log at depends on the situation + Logger.Level level; + + // Use ERROR for any boot failure or for any failure that may affect this processes' runtime services. + // Stage.RUNTIME failures in read-only steps haven't affected runtime services so don't require ERROR + // logging if they came from an internal caller that presumably will handle a failure response without + // the aid of the log. // Post-boot MODEL failures aren't ERROR logged as they have no impact outside the scope of // the soon-to-be-abandoned OperationContext. - // TODO consider logging Stage.DOMAIN problems if it's clear the message will be comprehensible. - // Currently Stage.DOMAIN failure handling involves message manipulation before sending the - // failure data to the client; logging stuff before that is done is liable to just produce a log mess. - return isBooting() || currentStage == Stage.RUNTIME || currentStage == Stage.VERIFY; + if (isBooting() || currentStage == Stage.VERIFY + || (currentStage == Stage.RUNTIME && (step.requiresDoneStage || isExternalClient()))) { + level = Logger.Level.ERROR; + } else if (clienterror || currentStage != Stage.DOMAIN) { + level = Logger.Level.DEBUG; + } else { // Stage.DOMAIN problems not due to catching OperationClientException + // TODO consider ERROR or DEBUG logging Stage.DOMAIN problems if it's clear the message will be comprehensible. + // Currently Stage.DOMAIN failure handling involves message manipulation before sending the + // failure data to the client; logging stuff before that is done is liable to just produce a log mess. + level = Logger.Level.TRACE; + } + + if (MGMT_OP_LOGGER.isEnabled(level)) { + // Historically we've used a different message id for client problems even though the rest of the message + // was the same, so continue with that. + String msg = level != Logger.Level.ERROR && clienterror + ? MGMT_OP_LOGGER.operationFailedOnClientError(step.operation.get(OP), step.operation.get(OP_ADDR), + step.response.get(FAILURE_DESCRIPTION)) + : MGMT_OP_LOGGER.operationFailed(step.operation.get(OP), step.operation.get(OP_ADDR), + step.response.get(FAILURE_DESCRIPTION)); + MGMT_OP_LOGGER.log(level, msg); + + } + } + + private boolean isExternalClient() { + AccessMechanism am = operationHeaders.getAccessMechanism(); + return am != null && am != AccessMechanism.IN_VM_USER; } private void handleContainerStabilityFailure(ModelNode response, Exception cause) { diff --git a/controller/src/main/java/org/jboss/as/controller/logging/ControllerLogger.java b/controller/src/main/java/org/jboss/as/controller/logging/ControllerLogger.java index 554ce8c4f2f..94d4b7074b0 100644 --- a/controller/src/main/java/org/jboss/as/controller/logging/ControllerLogger.java +++ b/controller/src/main/java/org/jboss/as/controller/logging/ControllerLogger.java @@ -276,15 +276,14 @@ public interface ControllerLogger extends BasicLogger { void operationFailed(@Cause Throwable cause, ModelNode op, ModelNode opAddress); /** - * Logs an error message indicating operation failed. + * Provides an error message indicating operation failed. * * @param op the operation that failed. * @param opAddress the address the operation failed on. * @param failureDescription the failure description. */ - @LogMessage(level = ERROR) @Message(id = Message.INHERIT, value = "Operation (%s) failed - address: (%s) - failure description: %s") - void operationFailed(ModelNode op, ModelNode opAddress, ModelNode failureDescription); + String operationFailed(ModelNode op, ModelNode opAddress, ModelNode failureDescription); // WFCORE-792 -- no longer used // /** @@ -319,15 +318,14 @@ public interface ControllerLogger extends BasicLogger { void noFinalProxyOutcomeReceived(ModelNode op, ModelNode opAddress, ModelNode proxyAddress); /** - * Logs an error message indicating operation failed due to a client error (e.g. an invalid request). + * Provides an error message indicating operation failed due to a client error (e.g. an invalid request). * * @param op the operation that failed. * @param opAddress the address the operation failed on. * @param failureDescription the failure description. */ - @LogMessage(level = Logger.Level.DEBUG) @Message(id = 17, value = "Operation (%s) failed - address: (%s) - failure description: %s") - void operationFailedOnClientError(ModelNode op, ModelNode opAddress, ModelNode failureDescription); + String operationFailedOnClientError(ModelNode op, ModelNode opAddress, ModelNode failureDescription); // /** // * Logs an error indicating that createWrapper should be called