Security: audit event not properly logged/audited

[ggma]

Environment Details

• Helidon Version: 1.1.2
• Helidon MP
• JDK version: 11.0.2
• OS: Windows 10
• Docker version (if applicable):

---

Problem Description

Audit event can fail, when number of expected parameters does not match the number of real parameters.

AM io.helidon.microprofile.server.ServerImpl$1 toResponse WARNING: Internal server error io.helidon.security.SecurityException: Failure while executing asynchronous security at io.helidon.security.SecurityResponse.get(SecurityResponse.java:67) at io.helidon.security.SecurityClient.get(SecurityClient.java:46) at io.helidon.security.SecurityClientBuilder.buildAndGet(SecurityClientBuilder.java:61) at io.helidon.security.integration.jersey.SecurityFilterCommon.processAuthorization(SecurityFilterCommon.java:313) at io.helidon.security.integration.jersey.SecurityFilterCommon.authorize(SecurityFilterCommon.java:299) at io.helidon.security.integration.jersey.SecurityFilter.processSecurity(SecurityFilter.java:184) at io.helidon.security.integration.jersey.SecurityFilterCommon.doFilter(SecurityFilterCommon.java:140) at io.helidon.security.integration.jersey.SecurityFilter.filter(SecurityFilter.java:155) at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:108) at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:44) at org.glassfish.jersey.process.internal.Stages.process(Stages.java:173) at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:245) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) at org.glassfish.jersey.internal.Errors.process(Errors.java:292) at org.glassfish.jersey.internal.Errors.process(Errors.java:274) at org.glassfish.jersey.internal.Errors.process(Errors.java:244) at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:679) at io.helidon.webserver.jersey.JerseySupport$JerseyHandler.lambda$doAccept$3(JerseySupport.java:265) at io.helidon.common.context.Contexts.runInContext(Contexts.java:98) at io.helidon.common.context.ContextAwareExecutorImpl.lambda$wrap$1(ContextAwareExecutorImpl.java:129) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: java.util.concurrent.ExecutionException: java.util.MissingFormatArgumentException: Format specifier '%s' at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2022) at io.helidon.security.SecurityResponse.get(SecurityResponse.java:63) ... 25 more Caused by: java.util.MissingFormatArgumentException: Format specifier '%s' at java.base/java.util.Formatter.format(Formatter.java:2672) at java.base/java.util.Formatter.format(Formatter.java:2609) at java.base/java.lang.String.format(String.java:2897) at io.helidon.security.DefaultAuditProvider.formatMessage(DefaultAuditProvider.java:109) at io.helidon.security.DefaultAuditProvider.logEvent(DefaultAuditProvider.java:96) at io.helidon.security.DefaultAuditProvider.audit(DefaultAuditProvider.java:63) at io.helidon.security.Security.audit(Security.java:232) at io.helidon.security.SecurityContextImpl.audit(SecurityContextImpl.java:179) at io.helidon.security.AuthorizationClientImpl.lambda$submit$1(AuthorizationClientImpl.java:84) at java.base/java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:986) at java.base/java.util.concurrent.CompletableFuture$UniExceptionally.tryFire(CompletableFuture.java:970) at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1705) ... 3 more

Received AuditEvent:
event.messageFormat() returned "Provider %s, Description %s, Request %s. Subject %s. %s: %s"
event.params returned 5 params