elastic / apm-agent-java

https://www.elastic.co/guide/en/apm/agent/java/current/index.html
Apache License 2.0
567 stars 320 forks source link

KafkaProducerHeadersInstrumentation logging error #3698

Closed mhmtonrn closed 2 months ago

mhmtonrn commented 3 months ago

hi I use kafka in my app, When I try send message to kafka my application throws this trace

java.lang.StringIndexOutOfBoundsException: offset 31, count -1179454, length 34 at java.lang.String.checkBoundsOffCount(String.java:4591) ~[?:?] at java.lang.StringUTF16.checkBoundsOffCount(StringUTF16.java:1636) ~[?:?] at java.lang.StringUTF16.inflate(StringUTF16.java:1462) ~[?:?] at java.lang.StringLatin1.inflate(StringLatin1.java:788) ~[?:?] at java.lang.String.getBytes(String.java:4481) ~[?:?] at java.lang.AbstractStringBuilder.putStringAt(AbstractStringBuilder.java:1720) ~[?:?] at java.lang.AbstractStringBuilder.putStringAt(AbstractStringBuilder.java:1724) ~[?:?] at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:583) ~[?:?] at java.lang.StringBuilder.append(StringBuilder.java:179) ~[?:?] at org.apache.kafka.common.utils.LogContext$AbstractKafkaLogger.addPrefix(LogContext.java:66) ~[kafka-clients-3.1.2.jar!/:?] at org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.writeLog(LogContext.java:434) ~[kafka-clients-3.1.2.jar!/:?] at org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.info(LogContext.java:422) ~[kafka-clients-3.1.2.jar!/:?] at co.elastic.apm.agent.kafka.KafkaProducerHeadersInstrumentation$KafkaProducerHeadersAdvice.afterSend(KafkaProducerHeadersInstrumentation.java:115) ~[elastic-apm-agent-1.46.0.jar:1.46.0] at org.apache.kafka.clients.producer.KafkaProducer.doSend(KafkaProducer.java:1038) [kafka-clients-3.1.2.jar!/:?] at org.apache.kafka.clients.producer.KafkaProducer.send(KafkaProducer.java:914) [kafka-clients-3.1.2.jar!/:?] at org.springframework.kafka.core.DefaultKafkaProducerFactory$CloseSafeProducer.send(DefaultKafkaProducerFactory.java:1087) [spring-kafka-2.8.11.jar!/:2.8.11] at org.springframework.kafka.core.KafkaTemplate.doSend(KafkaTemplate.java:655) [spring-kafka-2.8.11.jar!/:2.8.11] at org.springframework.kafka.core.KafkaTemplate.send(KafkaTemplate.java:403) [spring-kafka-2.8.11.jar!/:2.8.11] at io.mhmtonrn.CekimController.cihazAyaktanCekim(CekimController.java:63) [classes!/:2.1-SNAPSHOT] at io.mhmtonrn.CekimController$$FastClassBySpringCGLIB$$ca964b83.invoke() [classes!/:2.1-SNAPSHOT] at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) [spring-core-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.validation.beanvalidation.MethodValidationInterceptor.invoke(MethodValidationInterceptor.java:123) [spring-context-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:61) [spring-security-core-5.7.10.jar!/:5.7.10] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) [spring-aop-5.3.29.jar!/:5.3.29] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708) [spring-aop-5.3.29.jar!/:5.3.29]

error.log

JonasKunz commented 3 months ago

Can you provide a minimal project to reproduce the issue? The weird thing is that the line

co.elastic.apm.agent.kafka.KafkaProducerHeadersInstrumentation$KafkaProducerHeadersAdvice.afterSend(KafkaProducerHeadersInstrumentation.java:115)

doesn't call into anything relevant that could be producing that stacktrace on 1.46.0.

mhmtonrn commented 3 months ago

I can't create minimal project, because this error occours in production

JonasKunz commented 3 months ago

Without a way to reproduce it, we likely won't be able to help you here, because like I said the stacktrace by itself doesn't make sense. Is there any other kind of javaagent involved maybe, which would be an explanation for the strange stacktrace?

jackshirazi commented 3 months ago

That stack trace is mental. The log line is

                logger.info("Adding header to Kafka record is not allowed with the used broker, attempting to resend record");

Then it's kafka

        protected String addPrefix(final String message) {
            return prefix + message;
        }

which is being converted by the compiler to a StringBuilder.append() that results in a count -1179454 !

Probably some text encoding that exposes a bug in the JVM. You could try changing your text encoding

mhmtonrn commented 3 months ago

@JonasKunz we use glowroot and elastic agent same time

mhmtonrn commented 3 months ago

@jackshirazi we use default text encoding, and I can't understant what can I do

JonasKunz commented 3 months ago

Could you try without glowroot and see if the error still occurs?

mhmtonrn commented 2 months ago

I have tried removing gloowroot agen yes it worked finely. Gloowroot and elastic-apm-agent can not not works on same app.

jackshirazi commented 2 months ago

I'm closing this as it seems resolved. Feel free to comment if it needs reopening