Instrument name is invalid with Spring Security 6

[der-eismann]

Describe the bug
We upgraded one of our applications to Spring Boot 3 including Sprint Security 6, now we are getting lots of warnings like this:

[otel.javaagent 2022-12-19 11:24:36:651 +0100] [http-nio-8080-exec-1] WARN io.opentelemetry.ApiUsageLogging - Instrument name "spring.security.filterchains.DisableEncodeUrlFilter before" is invalid, returning noop instrument. Instrument names must consist of 63 or fewer characters including alphanumeric, _, ., -, and start with a letter.
java.lang.AssertionError
	at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.internal.ValidationUtil.log(ValidationUtil.java:55)
	at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.internal.ValidationUtil.checkValidInstrumentName(ValidationUtil.java:72)
	at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.internal.ValidationUtil.checkValidInstrumentName(ValidationUtil.java:61)
	at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.metrics.DefaultMeter.counterBuilder(DefaultMeter.java:42)
	at io.opentelemetry.javaagent.shaded.instrumentation.micrometer.v1_5.OpenTelemetryCounter.<init>(OpenTelemetryCounter.java:36)
	at io.opentelemetry.javaagent.shaded.instrumentation.micrometer.v1_5.OpenTelemetryMeterRegistry.newCounter(OpenTelemetryMeterRegistry.java:76)
	at io.micrometer.core.instrument.MeterRegistry.lambda$registerMeterIfNecessary$5(MeterRegistry.java:570)
	at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:625)
	at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:577)
	at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:570)
	at io.micrometer.core.instrument.MeterRegistry.counter(MeterRegistry.java:299)
	at io.micrometer.core.instrument.Counter$Builder.register(Counter.java:131)
	at io.micrometer.core.instrument.composite.CompositeCounter.registerNewMeter(CompositeCounter.java:49)
	at io.micrometer.core.instrument.composite.CompositeCounter.registerNewMeter(CompositeCounter.java:23)
	at io.micrometer.core.instrument.composite.AbstractCompositeMeter.add(AbstractCompositeMeter.java:68)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at java.base/java.util.Collections$SetFromMap.forEach(Collections.java:5700)
	at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lambda$new$0(CompositeMeterRegistry.java:67)
	at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lock(CompositeMeterRegistry.java:189)
	at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lambda$new$1(CompositeMeterRegistry.java:67)
	at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:634)
	at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:577)
	at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:570)
	at io.micrometer.core.instrument.MeterRegistry.counter(MeterRegistry.java:299)
	at io.micrometer.core.instrument.Counter$Builder.register(Counter.java:131)
	at io.micrometer.core.instrument.observation.DefaultMeterObservationHandler.onEvent(DefaultMeterObservationHandler.java:69)
	at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.lambda$onEvent$3(ObservationHandler.java:144)
	at java.base/java.util.Optional.ifPresent(Optional.java:178)
	at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.onEvent(ObservationHandler.java:144)
	at io.micrometer.observation.SimpleObservation.lambda$notifyOnEvent$4(SimpleObservation.java:198)
	at java.base/java.util.ArrayDeque.forEach(ArrayDeque.java:888)
	at io.micrometer.observation.SimpleObservation.notifyOnEvent(SimpleObservation.java:198)
	at io.micrometer.observation.SimpleObservation.event(SimpleObservation.java:127)
	at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:184)
	at org.springframework.security.web.ObservationFilterChainDecorator$AroundFilterObservation$SimpleAroundFilterObservation.lambda$wrap$0(ObservationFilterChainDecorator.java:278)
	at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:170)
	at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:134)
	at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:233)
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:191)
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:351)
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
	at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:109)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:119)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:741)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:400)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1739)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Thread.java:833)

Steps to reproduce

• Create a service with Spring Boot 3 & Spring Security 6
• Run them with the Java Agent attached

What did you expect to see?
No warnings

What did you see instead?
The above mentioned warning

What version are you using?
v1.21.0

Environment
Compiler: AWS Corretto 17.0.5.8.1
OS: AlmaLinux 9

[rschlick]

Hello,

I can confirm the problem. We have the same issue with Sping Boot 3 + Spring Security 6 with OT version 1.21.0

[otel.javaagent 2023-01-05 09:57:49:468 +0000] [http-nio-9090-exec-1] WARN io.opentelemetry.ApiUsageLogging - Instrument name "spring.security.filterchains.DisableEncodeUrlFilter before" is invalid, returning noop instrument. Instrument names must consist of 63 or fewer characters including alphanumeric, _, ., -, and start with a letter.
--
  | java.lang.AssertionError
  | at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.internal.ValidationUtil.log(ValidationUtil.java:55)
  | at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.internal.ValidationUtil.checkValidInstrumentName(ValidationUtil.java:72)
  | at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.internal.ValidationUtil.checkValidInstrumentName(ValidationUtil.java:61)
  | at io.opentelemetry.javaagent.shaded.io.opentelemetry.api.metrics.DefaultMeter.counterBuilder(DefaultMeter.java:42)
  | at io.opentelemetry.javaagent.shaded.instrumentation.micrometer.v1_5.OpenTelemetryCounter.(OpenTelemetryCounter.java:36)
  | at io.opentelemetry.javaagent.shaded.instrumentation.micrometer.v1_5.OpenTelemetryMeterRegistry.newCounter(OpenTelemetryMeterRegistry.java:76)
  | at io.micrometer.core.instrument.MeterRegistry.lambda$registerMeterIfNecessary$5(MeterRegistry.java:570)
  | at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:625)
  | at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:577)
  | at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:570)
  | at io.micrometer.core.instrument.MeterRegistry.counter(MeterRegistry.java:299)
  | at io.micrometer.core.instrument.Counter$Builder.register(Counter.java:131)
  | at io.micrometer.core.instrument.composite.CompositeCounter.registerNewMeter(CompositeCounter.java:49)
  | at io.micrometer.core.instrument.composite.CompositeCounter.registerNewMeter(CompositeCounter.java:23)
  | at io.micrometer.core.instrument.composite.AbstractCompositeMeter.add(AbstractCompositeMeter.java:68)
  | at java.base/java.lang.Iterable.forEach(Unknown Source)
  | at java.base/java.util.Collections$SetFromMap.forEach(Unknown Source)
  | at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lambda$new$0(CompositeMeterRegistry.java:67)
  | at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lock(CompositeMeterRegistry.java:189)
  | at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lambda$new$1(CompositeMeterRegistry.java:67)
  | at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:634)
  | at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:577)
  | at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:570)
  | at io.micrometer.core.instrument.MeterRegistry.counter(MeterRegistry.java:299)
  | at io.micrometer.core.instrument.Counter$Builder.register(Counter.java:131)
  | at io.micrometer.core.instrument.observation.DefaultMeterObservationHandler.onEvent(DefaultMeterObservationHandler.java:69)
  | at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.lambda$onEvent$3(ObservationHandler.java:144)
  | at java.base/java.util.Optional.ifPresent(Unknown Source)
  | at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.onEvent(ObservationHandler.java:144)
  | at io.micrometer.observation.SimpleObservation.lambda$notifyOnEvent$4(SimpleObservation.java:198)
  | at java.base/java.util.ArrayDeque.forEach(Unknown Source)
  | at io.micrometer.observation.SimpleObservation.notifyOnEvent(SimpleObservation.java:198)
  | at io.micrometer.observation.SimpleObservation.event(SimpleObservation.java:127)
  | at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:185)
  | at org.springframework.security.web.ObservationFilterChainDecorator$AroundFilterObservation$SimpleAroundFilterObservation.lambda$wrap$0(ObservationFilterChainDecorator.java:280)
  | at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:170)
  | at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:134)
  | at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:233)
  | at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:191)
  | at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:351)
  | at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267)
  | at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
  | at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
  | at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:177)
  | at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
  | at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
  | at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:119)
  | at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
  | at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
  | at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
  | at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:400)
  | at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
  | at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:859)
  | at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1734)
  | at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
  | at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
  | at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
  | at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
  | at java.base/java.lang.Thread.run(Unknown Source)

[mateuszrzeszutek]

It looks like this name is produced by Spring Security itself:
https://github.com/spring-projects/spring-security/blob/65b9dbf031fddff61fb8e13baa67d55131c99055/web/src/main/java/org/springframework/security/web/ObservationFilterChainDecorator.java#L185

parent.before().event(Observation.Event.of(this.name + " before"));

@der-eismann @rschlick can you create an issue in the Spring repo? I believe that this sort of naming pattern (whitespaces) might not be accepted by at least some of the monitoring systems supported by Micrometer; it's not just OpenTelemetry that'll trip on this.

[rschlick]

@mateuszrzeszutek I have a created a bug ticket in the Spring Security project there : spring-projects/spring-security#12490

[mateuszrzeszutek]

Cool, looks like they fixed that already.
I think we can close this issue - please reopen it or open a new one if you find some other bug/issue in spring 6.0.2.

[odoihc]

Hi, the warning is still present with Spring Security 6.1.0, please let's fix it if possible

[otel.javaagent 2023-06-06 09:21:36:206 +0200] [http-nio-8082-exec-1] WARN io.opentelemetry.sdk.metrics.SdkMeter - Instrument name "spring.security.filterchains.WebAsyncManagerIntegrationFilter.before" is invalid, returning noop instrument. Instrument names must consist of 63 or fewer characters including alphanumeric, _, ., -, and start with a letter.
java.lang.AssertionError
	at io.opentelemetry.sdk.metrics.SdkMeter.checkValidInstrumentName(SdkMeter.java:161)
	at io.opentelemetry.sdk.metrics.SdkMeter.counterBuilder(SdkMeter.java:85)
	at io.opentelemetry.javaagent.shaded.instrumentation.micrometer.v1_5.OpenTelemetryCounter.<init>(OpenTelemetryCounter.java:36)
	at io.opentelemetry.javaagent.shaded.instrumentation.micrometer.v1_5.OpenTelemetryMeterRegistry.newCounter(OpenTelemetryMeterRegistry.java:76)