Spring Boot + Apache Camel = no transaction

Hi!

I'am installed elastic+ APM Server in OKD 4.7. All work ok.

Added agent to application deployment by manifest

      containers:
        - env:
            - name: JAVA_TOOL_OPTIONS 
              value: -javaagent:/elastic/apm/agent/elastic-apm-agent.jar
            - name: ELASTIC_APM_SERVER_URLS
              value: http://xxx.xxx.xxx.xxx:8200/
            - name: ELASTIC_APM_LOG_LEVEL 
              value: INFO 
            - name: ELASTIC_APM_SERVICE_NAME 
              value: "test-status" 
            - name: ELASTIC_APM_SECRET_TOKEN
              value: ***********
            - name: ELASTIC_APM_APPLICATION_PACKAGES
              value: com.mytestapp.card

Test Java App class

package com.mytestapp.card;

import org.apache.camel.spring.boot.CamelSpringBootApplicationController;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.boot.context.properties.EnableConfigurationProperties;
import org.springframework.context.ApplicationContext;

/**
 * Main app class.
 */
@EnableConfigurationProperties
@SpringBootApplication
public class CardApp {

	public static void main(String[] args) {

		ApplicationContext applicationContext = new SpringApplication(CardApp.class).run(args);
		CamelSpringBootApplicationController applicationController = applicationContext
				.getBean(CamelSpringBootApplicationController.class);
		applicationController.run();

	}

}

Java Agent is running and connected,

2021-09-02 10:59:40,983 [main] INFO  co.elastic.apm.agent.util.JmxUtils - Found JVM-specific OperatingSystemMXBean interface: com.sun.management.OperatingSystemMXBean
2021-09-02 10:59:41,277 [main] INFO  co.elastic.apm.agent.configuration.StartupInfo - Starting Elastic APM 1.25.0 as test-status on Java 1.8.0_212 Runtime version: 1.8.0_212-b04 VM version: 25.212-b04 (Oracle Corporation) Linux 5.13.4-200.fc34.x86_64
2021-09-02 10:59:41,278 [main] INFO  co.elastic.apm.agent.configuration.StartupInfo - service_name: 'test-status' (source: Environment Variables)
2021-09-02 10:59:41,278 [main] INFO  co.elastic.apm.agent.configuration.StartupInfo - secret_token: 'XXXX' (source: Environment Variables)
2021-09-02 10:59:41,279 [main] INFO  co.elastic.apm.agent.configuration.StartupInfo - server_urls: 'http://xxx.xxx.xxx.xxx:8200' (source: Environment Variables)
2021-09-02 10:59:41,279 [main] INFO  co.elastic.apm.agent.configuration.StartupInfo - application_packages: 'com.mytestapp.card' (source: Environment Variables)
2021-09-02 10:59:47,657 [main] INFO  co.elastic.apm.agent.impl.ElasticApmTracer - Tracer switched to RUNNING state
2021-09-02 10:59:47,927 [elastic-apm-server-healthcheck] INFO  co.elastic.apm.agent.report.ApmServerHealthChecker - Elastic APM server is available: {  "build_date": "2021-07-29T19:55:24Z",  "build_sha": "af26b5a744b6af9bcccb04fade6435241ab91f43",  "version": "7.14.0"}


  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.1.1.RELEASE)

2021-09-02 10:59:51.024  INFO 8 --- [           main] com.mytestapp.card.CardApp   : Starting CardApp on test-status-1-tmj2h with PID 8 (/opt/app/app.jar started by 1000680000 in /)
2021-09-02 10:59:51.037 DEBUG 8 --- [           main] com.mytestapp.card.CardApp   : Running with Spring Boot v2.1.1.RELEASE, Spring v5.1.3.RELEASE
2021-09-02 10:59:51.037  INFO 8 --- [           main] com.mytestapp.card.CardApp   : The following profiles are active: test-dev
........

In kibana i see Service test-status and all default parameters

But no any transactions. Why??? What i do wrong???

Kibana version: 7.14
Elasticsearch version: 7.14
APM Server version: 7.14
APM Agent language and version: 1.25

Hi @TidalPoo ,
What types of transactions do you expect to see? (http requests or something else)?

yes, i want to see http requests, method calls, maybe db requests.

my app it's simple microservice
POST request, and receive json answer
microservice is worked well

Can you set ELASTIC_APM_LOG_LEVEL to DEBUG level and share logs with at least one sent http request?

i tryed it early, but not found any information what can help me

for safety, some lines have been changed or hidden

2021-09-02 14:57:46,017 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.impl.ElasticApmTracerBuilder - Beginning scheduled configuration reload (interval is 30 sec)...
2021-09-02 14:57:46,018 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.impl.ElasticApmTracerBuilder - Finished scheduled configuration reload
2021-09-02 14:57:52,851 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 406)
2021-09-02 14:57:52,851 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Starting new request to http://xxx.xxx.xxx.xxx:8200/intake/v2/events
2021-09-02 14:57:52,853 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Scheduling request timeout in 10s
2021-09-02 14:57:52,854 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 407)
2021-09-02 14:57:52,854 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 408)
2021-09-02 14:57:52,854 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 409)
2021-09-02 14:57:52,854 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 410)
2021-09-02 14:57:52,854 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 411)
2021-09-02 14:57:55.729 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.r.PrepareCardStatusRequest     : process.
body: { "status": "LOST", "cardId": "592844671" }
2021-09-02 14:57:55.729 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.r.PrepareCardStatusRequest     : process.
newBody: {"cardId":"592844671","status":"CHST6"}
2021-09-02 14:57:56.239 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.route.AfterCall   : process.
body: {"messageInfo":{"errorCode":0,"messageId":"sync:ID-test-status-1-gr8qq-1630592909961-0-62850"},"cardId":"592844671","result":"accept","message":"accept"}
2021-09-02 14:57:56.240 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.route.AfterCall   : process.
 result: {"messageInfo":{"errorCode":0},"result":{"cardId":"592844671","resultCode":"accept","message":"accept"}}
2021-09-02 14:58:02,854 [elastic-apm-request-timeout-timer] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler$FlushOnTimeoutTimerTask - Request flush because the request timeout occurred
2021-09-02 14:58:02,859 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving FLUSH event (sequence 412)
2021-09-02 14:58:02,860 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Flushing 2377 uncompressed 867 compressed bytes
2021-09-02 14:58:13.908 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.r.PrepareCardStatusRequest     : process.
body: { "status": "LOST", "cardId": "592844671" }
2021-09-02 14:58:13.908 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.r.PrepareCardStatusRequest     : process.
newBody: {"cardId":"592844671","status":"CHST6"}
2021-09-02 14:58:14.417 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.route.AfterCall   : process.
body: {"messageInfo":{"errorCode":0,"messageId":"sync:ID-test-status-1-gr8qq-1630592909961-0-62865"},"cardId":"592844671","result":"accept","message":"accept"}
2021-09-02 14:58:14.417 DEBUG 7 --- [ntExecutorGroup] com.mytestapp.card.route.AfterCall   : process.
 result: {"messageInfo":{"errorCode":0},"result":{"cardId":"592844671","resultCode":"accept","message":"accept"}}
2021-09-02 14:58:16,017 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.impl.ElasticApmTracerBuilder - Beginning scheduled configuration reload (interval is 30 sec)...
2021-09-02 14:58:16,018 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.impl.ElasticApmTracerBuilder - Finished scheduled configuration reload
2021-09-02 14:58:22,863 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 413)
2021-09-02 14:58:22,864 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Starting new request to http://xxx.xxx.xxx.xxx:8200/intake/v2/events
2021-09-02 14:58:22,875 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Scheduling request timeout in 10s
2021-09-02 14:58:22,875 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 414)
2021-09-02 14:58:22,875 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 415)
2021-09-02 14:58:22,875 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 416)
2021-09-02 14:58:22,875 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 417)
2021-09-02 14:58:22,875 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 418)
2021-09-02 14:58:23,386 [elastic-apm-remote-config-poller] DEBUG co.elastic.apm.agent.configuration.ApmServerConfigurationSource - Reloading configuration from APM Server http://xxx.xxx.xxx.xxx:8200/config/v1/agents
2021-09-02 14:58:23,885 [elastic-apm-remote-config-poller] DEBUG co.elastic.apm.agent.configuration.ApmServerConfigurationSource - Central configuration is disabled. Set kibana.enabled: true in your APM Server configuration.
2021-09-02 14:58:23,909 [elastic-apm-remote-config-poller] DEBUG co.elastic.apm.agent.configuration.ApmServerConfigurationSource - Scheduling next remote configuration reload in 300s
2021-09-02 14:58:32,875 [elastic-apm-request-timeout-timer] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler$FlushOnTimeoutTimerTask - Request flush because the request timeout occurred
2021-09-02 14:58:32,881 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving FLUSH event (sequence 419)
2021-09-02 14:58:32,882 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Flushing 2377 uncompressed 868 compressed bytes
2021-09-02 14:58:46,018 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.impl.ElasticApmTracerBuilder - Beginning scheduled configuration reload (interval is 30 sec)...
2021-09-02 14:58:46,018 [elastic-apm-configuration-reloader] DEBUG co.elastic.apm.agent.impl.ElasticApmTracerBuilder - Finished scheduled configuration reload

additional information)
maybe important)))

2021-09-02 14:28:32.616  INFO 7 --- [           main] o.a.kafka.common.utils.AppInfoParser     : Kafka version : 2.1.0
2021-09-02 14:28:32.616  INFO 7 --- [           main] o.a.kafka.common.utils.AppInfoParser     : Kafka commitId : ****************
2021-09-02 14:28:32.634  INFO 7 --- [es-event-topic]] o.a.camel.component.kafka.KafkaConsumer  : Subscribing references-event-topic-Thread 0 to topic references-event-topic
2021-09-02 14:28:32.632  INFO 7 --- [           main] o.a.camel.spring.SpringCamelContext      : Route: route2 started and consuming from: kafka://references-event-topic?allowManualCommit=true&autoOffsetReset=earliest&brokers=xxx.xxx.xxx.xxx%3A9092&consumersCount=1&groupId=test-status
2021-09-02 14:28:32.714  INFO 7 --- [           main] c.n.SingleTCPNettyServerBootstrapFactory : ServerBootstrap binding to 0.0.0.0:8081
2021-09-02 14:28:32.897  INFO 7 --- [           main] o.a.c.component.netty4.NettyConsumer     : Netty consumer bound to: 0.0.0.0:8081
2021-09-02 14:28:32.905  INFO 7 --- [           main] o.a.camel.spring.SpringCamelContext      : Route: route3 started and consuming from: http://0.0.0.0:8081/healthCheck?httpMethodRestrict=GET%2COPTIONS
2021-09-02 14:28:32.910  INFO 7 --- [           main] o.a.c.component.netty4.NettyConsumer     : Netty consumer bound to: 0.0.0.0:8081
2021-09-02 14:28:32.911  INFO 7 --- [           main] o.a.camel.spring.SpringCamelContext      : Route: route4 started and consuming from: http://0.0.0.0:8081/cardStatusChange?httpMethodRestrict=POST%2COPTIONS
2021-09-02 14:28:32.913  INFO 7 --- [           main] o.a.c.component.netty4.NettyConsumer     : Netty consumer bound to: 0.0.0.0:8081
2021-09-02 14:28:32.913  INFO 7 --- [           main] o.a.camel.spring.SpringCamelContext      : Route: swagger started and consuming from: http://0.0.0.0:8081/swagger?httpMethodRestrict=GET%2COPTIONS
2021-09-02 14:28:32.914  INFO 7 --- [           main] o.a.camel.spring.SpringCamelContext      : Total 5 routes, of which 5 are started
2021-09-02 14:28:32.915  INFO 7 --- [           main] o.a.camel.spring.SpringCamelContext      : Apache Camel 2.25.1 (CamelContext: camel-1) started in 1.673 seconds
2021-09-02 14:28:32.937  INFO 7 --- [           main] com.mytestapp.card.CardApp   : Started CardApp in 7.841 seconds (JVM running for 18.363)

@TidalPoo Do you use webflux?
Webflux at current time is experimental. You need enable experimental instrumentations via configuration

i don't think so)

<dependency>
			<groupId>org.apache.camel</groupId>
			<artifactId>camel-http</artifactId>
			<version>${camel.version}</version>
		</dependency>
		<dependency>
			<groupId>org.apache.camel</groupId>
			<artifactId>camel-swagger-java</artifactId>
			<version>${camel.version}</version>
		</dependency>
		<!-- need to camel-swagger-java -->
		<dependency>
			<groupId>org.hibernate.validator</groupId>
			<artifactId>hibernate-validator</artifactId>
			<version>6.0.13.Final</version>
		</dependency>
		<!-- test -->
		<dependency>
			<groupId>org.apache.camel</groupId>
			<artifactId>camel-test</artifactId>
			<version>${camel.version}</version>
			<scope>test</scope>
		</dependency>
		<dependency>
			<groupId>org.springframework</groupId>
			<artifactId>spring-test</artifactId>
			<version>${spring.version}</version>
			<scope>test</scope>
		</dependency>
		<dependency>
			<groupId>org.powermock</groupId>
			<artifactId>powermock-api-mockito</artifactId>
			<version>1.7.4</version>
			<scope>test</scope>
		</dependency>

Hi @TidalPoo , one way to check if Webflux and/or Servlets are being used here is to use mvn dependency:tree on your project, this will generate an ASCII tree with project dependencies, hence making it easy to check which framework is used to handle HTTP requests in your project.

Hi @Sylvain_Juge
thx. I will try to ask our programmers this question

i can't ask developers, but that i found in project

poms

camel-netty4-http
camel-spring-boot-starter

imports

org.apache.camel.builder.RouteBuilder;
org.apache.commons.httpclient.HttpClient;

webflux not found

any ideas?

Hi @TidalPoo

  1. What version of camel do you use?
  2. Can you send list of all dependencies from your pom file ?
  3. Previously, you sent the cropped logs. To understand the problem, you need to send all the logs associated with the agent. In order to hide logs related to business data, you can set the logging level for your application package, for example, ERROR.
logging.level.com.mytestapp.card=ERROR

1-2) dependencies

  1. uploaded the loading log of the agent and its components. for http requests, the log is the same as before, the agent does not process requests and passes them.

You may try using the Apache Camel OpenTracing component and our OpenTracing bridge. Since 1.22.0, this doesn't even require the minimal code change that was required before, as explain in the docs.

Similarly, you may try using the Apache Camel OpenTelemetry component and rely on our OpenTelemetry integration.