Skip to content

Commit

Permalink
[WFCORE-6476] Reduce failed step logging to DEBUG for read-only inter…
Browse files Browse the repository at this point in the history 
…nal calls
  • Loading branch information
@bstansberry
bstansberry committed Sep 5, 2023
1 parent 71ad163 commit 1995a75
Show file tree
Hide file tree
Showing 2 changed files with 48 additions and 25 deletions.
63 changes: 44 additions & 19 deletions controller/src/main/java/org/jboss/as/controller/AbstractOperationContext.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand All @@ -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
Expand Down Expand Up @@ -1134,15 +1129,45 @@ void addModifiedResourcesForModelValidation(Set<PathAddress> 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) {
Expand Down
10 changes: 4 additions & 6 deletions controller/src/main/java/org/jboss/as/controller/logging/ControllerLogger.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
// /**
Expand Down Expand Up @@ -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
Expand Down

0 comments on commit 1995a75

Please sign in to comment.