[WFCORE-6476] Reduce failed step logging to DEBUG for read-only inter…

[bstansberry]

…nal calls

https://issues.redhat.com/browse/WFCORE-6476

@jasondlee Says this resolves the WFLY-14509 issue -- https://wildfly.zulipchat.com/#narrow/stream/174184-wildfly-developers/topic/WFLY-14509.20-.20Exception.20while.20exporting.20metrics.20during.20boot/near/390574862.

[wildfly-ci]

Core -> Full Integration Build 12969 outcome was FAILURE using a merge of 1995a75
Summary: Tests failed: 1 (1 new), passed: 7185, ignored: 133 Build time: 03:40:38

Failed tests

org.jboss.as.test.manualmode.messaging.ha.ReplicatedFailoverTestCase.testBackupFailoverAfterFailback: javax.naming.NameNotFoundException: jms -- service jboss.naming.context.java.jboss.exported.jms
	at [email protected]//org.jboss.as.naming.ServiceBasedNamingStore.lookup(ServiceBasedNamingStore.java:106)
	at [email protected]//org.jboss.as.naming.NamingContext.lookup(NamingContext.java:207)
	at [email protected]//org.jboss.as.naming.NamingContext.lookup(NamingContext.java:193)
	at [email protected]//org.jboss.as.naming.NamingContext.lookup(NamingContext.java:189)
	at [email protected]//org.wildfly.naming.client.remote.RemoteServerTransport.handleLookup(RemoteServerTransport.java:200)
	at [email protected]//org.wildfly.naming.client.remote.RemoteServerTransport$1.handleMessage(RemoteServerTransport.java:120)
	at [email protected]//org.jboss.remoting3.remote.RemoteConnectionChannel.lambda$handleMessageData$3(RemoteConnectionChannel.java:432)
	at [email protected]//org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:993)
	at [email protected]//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at [email protected]//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at [email protected]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at [email protected]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at [email protected]//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
	at java.base/java.lang.Thread.run(Thread.java:829)
------- Stdout: -------
 [0m17:00:43,790 INFO  [org.jboss.modules] (main) JBoss Modules version 2.1.2.Final
 [0m [0m17:00:44,143 INFO  [org.jboss.msc] (main) JBoss MSC version 1.5.1.Final
 [0m [0m17:00:44,151 INFO  [org.jboss.threads] (main) JBoss Threads version 2.4.0.Final
 [0m [0m17:00:44,247 INFO  [org.jboss.as] (MSC service thread 1-1) WFLYSRV0049: WildFly Full 30.0.0.Beta1-SNAPSHOT (WildFly Core 22.0.0.Beta2-SNAPSHOT) starting
 [0mWARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.wildfly.extension.elytron.SSLDefinitions (jar:file:/store/repository/org/wildfly/core/wildfly-elytron-integration/22.0.0.Beta2-SNAPSHOT/wildfly-elytron-integration-22.0.0.Beta2-SNAPSHOT.jar!/) to method com.sun.net.ssl.internal.ssl.Provider.isFIPS()
WARNING: Please consider reporting this to the maintainers of org.wildfly.extension.elytron.SSLDefinitions
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
 [0m17:00:45,198 INFO  [org.wildfly.security] (ServerService Thread Pool -- 31) ELY00001: WildFly Elytron version 2.2.1.Final
 [0m [0m17:00:45,991 INFO  [org.jboss.as.controller.management-deprecated] (ServerService Thread Pool -- 5) WFLYCTL0028: Attribute 'cluster' in the resource at address '/subsystem=ejb3/service=remote' is deprecated, and may be removed in a future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation.
 [0m [33m17:00:46,035 WARN  [org.wildfly.extension.messaging-activemq] (ServerService Thread Pool -- 16) WFLYMSGAMQ0071: There is no resource matching the expiry-address jms.queue.ExpiryQueue for the address-settings #, expired messages from destinations matching this address-setting will be lost!
 [0m [33m17:00:46,049 WARN  [org.wildfly.extension.messaging-activemq] (ServerService Thread Pool -- 16) WFLYMSGAMQ0072: There is no resource matching the dead-letter-address jms.queue.DLQ for the address-settings #, undelivered messages from destinations matching this address-setting will be lost!
 [0m [0m17:00:46,162 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0039: Creating http management service using socket-binding (management-http)
 [0m [0m17:00:46,193 INFO  [org.xnio] (MSC service thread 1-2) XNIO version 3.8.10.Final
 [0m [0m17:00:46,214 INFO  [org.xnio.nio] (MSC service thread 1-2) XNIO NIO Implementation Version 3.8.10.Final
 [0m [0m17:00:46,284 INFO  [org.jboss.remoting] (MSC service thread 1-2) JBoss Remoting version 5.0.27.Final
 [0m [0m17:00:46,369 INFO  [org.wildfly.extension.elytron.oidc._private] (ServerService Thread Pool -- 58) WFLYOIDC0001: Activating WildFly Elytron OIDC Subsystem
 [0m [0m17:00:46,322 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 49) WFLYJCA0004: Deploying JDBC-compliant driver class org.h2.Driver (version 2.1)
 [0m [0m17:00:46,395 INFO  [org.wildfly.extension.health] (ServerService Thread Pool -- 59) WFLYHEALTH0001: Activating Base Health Subsystem
 [0m [0m17:00:46,400 INFO  [org.wildfly.iiop.openjdk] (ServerService Thread Pool -- 60) WFLYIIOP0001: Activating IIOP Subsystem
 [0m [0m17:00:46,487 INFO  [org.wildfly.extension.microprofile.config.smallrye] (ServerService Thread Pool -- 73) WFLYCONF0001: Activating MicroProfile Config Subsystem
 [0m [0m17:00:46,496 INFO  [org.wildfly.extension.microprofile.jwt.smallrye] (ServerService Thread Pool -- 74) WFLYJWT0001: Activating MicroProfile JWT Subsystem
 [0m [0m17:00:46,501 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 76) WFLYNAM0001: Activating Naming Subsystem
 [0m [0m17:00:46,532 INFO  [org.jboss.as.webservices] (ServerService Thread Pool -- 86) WFLYWS0002: Activating WebServices Extension
 [0m [0m17:00:46,543 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 61) WFLYCLINF0001: Activating Infinispan subsystem.
 [0m [0m17:00:46,448 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-1) WFLYJCA0018: Started Driver service with driver-name = h2
 [0m [0m17:00:46,441 INFO  [org.jboss.as.jaxrs] (ServerService Thread Pool -- 63) WFLYRS0016: RESTEasy version 6.2.5.Final
 [0m [0m17:00:46,459 INFO  [org.jboss.as.connector] (MSC service thread 1-3) WFLYJCA0009: Starting Jakarta Connectors Subsystem (WildFly/IronJacamar 3.0.4.Final)
 [0m [0m17:00:46,483 INFO  [org.jboss.as.jsf] (ServerService Thread Pool -- 69) WFLYJSF0007: Activated the following Jakarta Server Faces Implementations: [main]
 [0m [33m17:00:46,523 WARN  [org.jboss.as.txn] (ServerService Thread Pool -- 84) WFLYTX0013: The node-identifier attribute on the /subsystem=transactions is set to the default value. This is a danger for environments running multiple servers. Please make sure the attribute value is unique.
 [0m [0m17:00:46,568 INFO  [org.wildfly.extension.io] (ServerService Thread Pool -- 62) WFLYIO001: Worker 'default' has auto-configured to 8 IO threads with 64 max task threads based on your 4 available processors
 [0m [0m17:00:46,574 INFO  [org.jboss.as.clustering.jgroups] (ServerService Thread Pool -- 66) WFLYCLJG0001: Activating JGroups subsystem. JGroups version 5.2.18
 [0m [0m17:00:46,622 INFO  [org.wildfly.extension.metrics] (ServerService Thread Pool -- 72) WFLYMETRICS0001: Activating Base Metrics Subsystem
 [0m [0m17:00:46,736 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0003: Undertow 2.3.8.Final starting

[bstansberry]

This fails because of

15:08:28,156 ERROR (Controller Boot Thread) [org.jboss.as.controller.management-operation] <AbstractOperationContext.java:1074> WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "elytron"),
    ("trust-manager" => "TestingTrustManagerCrls")
]): java.lang.NoSuchMethodError: 'void org.jboss.as.controller.logging.ControllerLogger.operationFailed(org.jboss.dmr.ModelNode, org.jboss.dmr.ModelNode, org.jboss.dmr.ModelNode)'
	at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:1043)
	at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:779)
	at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:468)
	at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1415)
	at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:503)
	at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:515)
	at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:477)
	at org.jboss.as.model.test.ModelTestModelControllerService.boot(ModelTestModelControllerService.java:308)
	at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:464)
	at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:416)
	at java.base/java.lang.Thread.run(Thread.java:833)

So basically the legacy ControllerLogger

[jasondlee]

I updated WF Core locally and integrated that into my WF workspace. I ran the reproducer with -- now -- over 10530 iterations with no error. So far as the immediate is concerned, this does seem to address my issue (WFLY-14509). As to the correctness with respect to the rest of the system, I'll leave it to those better versed in this area. :)

[yersan]

Thanks @bstansberry @jasondlee