ELK - APM 7.0 - No data recevied from Java agent

java
(Freddy Raj ) #1

If you are asking about a problem you are experiencing, please use the following template, as it will help us help you. If you have a different problem, please delete all of this text :slight_smile:

Kibana version: 7.0

Elasticsearch version: 7.0

APM Server version: 7.0

APM Agent language and version: 7.0

Browser version: Chrome Version 73.0.3683.86 (Official Build) (64-bit)

Original install method (e.g. download page, yum, deb, from source, etc.) and version: all are unix tar packages from download page

Fresh install or upgraded from other version? Fresh

Is there anything special in your setup?
ELK was set up with basic installation steps. So no issues in the stack.
Index pattern: logstash.*
Apm server: runs on port 8200

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant):
ELK and Apm server all are running on 1 server - "otp102". No issues status are GREEN

APM agent: Java agent set up on a weblogic application server 12213 version.
Server name is WEB101
In setDomainEnv.sh file, i added below:

apmAgent="-javaagent:/app01/ELK/filebeat-ThankYou/elastic-apm-agent-1.6.0.jar -Delastic.apm.service_name=TYUAT-WEB101
-Delastic.apm.server_url=http://otp102:8200"
export apmAgent

Steps to reproduce:

  1. Kibana
  2. click APM
  3. APM Server status --> You have correctly setup APM Server
  4. Make sure your application is running and the agents are sending data.
    Click on "Check agent status --> No data has been received from agents yet

Errors in browser console (if relevant):
Click on "Check agent status --> No data has been received from agents yet

Provide logs and/or server output (if relevant):
Connection between web101 where java agent is set up on weblogic server to Apm server is successful on port 8200.

Application on web101 is running as well i.e. weblogic status is "RUNNING" with javaagent flag

2 issue i see:
a. in kibana APM section --> Click on "Check agent status --> No data has been received from agents yet

b. netstat -anp | grep 8200 on apm server i.e. otp102, shows below
tcp 0 0 127.0.0.1:8200 0.0.0.0:* LISTEN 28708/./apm-server
tcp 1 0 127.0.0.1:52962 127.0.0.1:8200 CLOSE_WAIT 28876/./apm-server

Please advise!

(gonindzya) #2

Hello @Freddy.Raj, can you enable debugging and send logs?
Which version of weblogic do you use?

(Freddy Raj ) #3

Hello @nugusbayevkk, weblogic version 12.2.1.3
Debug logs:
INFO instance/beat.go:571 Home path: [/app01/ELK/apm-server] Config path: [/app01/ELK/apm-server] Data path: [/app01/ELK/apm-server/data] Logs path: [/app01/ELK/apm-server/logs]
DEBUG [beat] instance/beat.go:623 Beat metadata path: /app01/ELK/apm-server/data/meta.json
INFO instance/beat.go:579 Beat ID: dda33433-b6d7-4b0e-91fe-b06bf3d3e9df
DEBUG [processors] processors/processor.go:66 Processors:
INFO [seccomp] seccomp/seccomp.go:93 Syscall filter could not be installed because the kernel does not support seccomp
INFO [beat] instance/beat.go:827 Beat info {"system_info": {"beat": {"path": {"config": "/app01/ELK/apm-server", "data": "/app01/ELK/apm-server/data", "home": "/app01/ELK/apm-server", "logs": "/app01/ELK/apm-server/logs"}, "type": "apm-server", "uuid": "dda33433-b6d7-4b0e-91fe-b06bf3d3e9df"}}}
INFO [beat] instance/beat.go:836 Build info {"system_info": {"build": {"commit": "1f7ad059a0bbf0174b90e07c80c0274d152f1155", "libbeat": "7.0.0", "time": "2019-04-05T21:50:06.000Z", "version": "7.0.0"}}}
INFO [beat] instance/beat.go:839 Go runtime info {"system_info": {"go": {"os":"linux","arch":"amd64","max_procs":4,"version":"go1.11.5"}}}
INFO [beat] instance/beat.go:843 Host info {"system_info": {"host": {"architecture":"x86_64","boot_time":"2019-04-24T00:40:02-05:00","containerized":true,"name":"otp102.cbgrus.uat2","ip":["127.0.0.1/8","::1/128","10.211.12.120/26","fe80::250:56ff:feae:554/64","10.212.81.47/20","fe80::250:56ff:feae:5039/64"],"kernel_version":"2.6.32-754.12.1.el6.x86_64","mac":["00:50:56:ae:05:54","00:50:56:ae:50:39"],"os":{"family":"redhat","platform":"redhat","name":"Red","version":"6.10 (Santiago)","major":6,"minor":10,"patch":0,"codename":"Santiago"},"timezone":"CDT","timezone_offset_sec":-18000,"id":"7d37aa306eda1ba1e00c374e00000015"}}}
INFO [beat] instance/beat.go:872 Process info {"system_info": {"process": {"capabilities": {"inheritable":null,"permitted":null,"effective":null,"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend","audit_read","38","39","40","41","42","43","44","45","46","47","48","49","50","51","52","53","54","55","56","57","58","59","60","61","62","63"],"ambient":null}, "cwd": "/lfs/app01/ELK/apm-server", "exe": "/lfs/app01/ELK/apm-server/apm-server", "name": "apm-server", "pid": 3884, "ppid": 3853, "seccomp": {"mode":""}, "start_time": "2019-05-15T12:38:03.060-0500"}}}
INFO instance/beat.go:280 Setup Beat: apm-server; Version: 7.0.0
DEBUG [beat] instance/beat.go:301 Initializing output plugins
DEBUG [conditions] conditions/conditions.go:95 New condition contains: map
DEBUG [conditions] conditions/conditions.go:95 New condition contains: map
DEBUG [conditions] conditions/conditions.go:95 New condition contains: map
DEBUG [conditions] conditions/conditions.go:95 New condition contains: map
DEBUG [conditions] conditions/conditions.go:95 New condition contains: map
DEBUG [conditions] conditions/conditions.go:95 New condition contains: map
INFO elasticsearch/client.go:165 Elasticsearch url: http://localhost:9200
DEBUG [publisher] pipeline/consumer.go:137 start pipeline event consumer
INFO [publisher] pipeline/module.go:97 Beat name: otp102.cbgrus.uat2
INFO [beater] beater/beater.go:93 Falling back to elasticsearch output for sourcemap storage
INFO [beater] beater/beater.go:118 No pipeline callback registered
INFO instance/beat.go:391 apm-server start running.
INFO [beater] beater/beater.go:216 self instrumentation is disabled
INFO [beater] beater/beater.go:154 host resolved from 0.0.0.0:8200 to [::]:8200
INFO [handler] beater/route_config.go:94 Path /assets/v1/sourcemaps added to request handler
DEBUG [sourcemap] sourcemap/accessor.go:39 creating NewSmapAccessor for index: apm--sourcemap
INFO elasticsearch/client.go:165 Elasticsearch url: http://localhost:9200
INFO [handler] beater/route_config.go:99 Path /intake/v2/rum/events added to request handler
INFO [handler] beater/route_config.go:99 Path /intake/v2/events added to request handler
INFO [server] beater/server.go:66 Starting apm-server [1f7ad059a0bbf0174b90e07c80c0274d152f1155 built 2019-04-05 21:50:06 +0000 UTC]. Hit CTRL-C to stop it.
INFO [server] beater/server.go:67 Listening on: [::]:8200
INFO [server] beater/server.go:70 RUM endpoints enabled!
INFO [request] beater/common_handler.go:172 handled request {"request_id": "e9b1b52c-90dc-46fb-8087-39d520673dfd", "method": "GET", "URL": "/", "content_length": 0, "remote_address": "::1", "user-agent": "Go-http-client/1.1", "response_code": 200}
INFO [http_client] beater/client.go:49 HTTP Server ready
INFO [onboarding] beater/onboarding.go:36 Publishing onboarding document
DEBUG [processors] processing/processors.go:183 Publish event: {
"@timestamp": "2019-05-15T17:38:03.356Z",
"@metadata": {
"beat": "",
"type": "_doc",
"version": ""
},
"processor": {
"name": "onboarding",
"event": "onboarding"
},
"observer": {
"ephemeral_id": "88db7d5e-f86b-4290-aac9-75bb3ffbb919",
"type": "apm-server",
"hostname": "otp102.cbgrus.uat2",
"version": "7.0.0",
"version_major": 7,
"listening": "[::]:8200",
"id": "dda33433-b6d7-4b0e-91fe-b06bf3d3e9df"
},
"ecs": {
"version": "1.1.0-dev"
}
}

(Freddy Raj ) #4

part 2 of debug logs:

INFO pipeline/output.go:95 Connecting to backoff(elasticsearch(http://localhost:9200))
DEBUG [elasticsearch] elasticsearch/client.go:710 ES Ping(url=http://localhost:9200)
DEBUG [elasticsearch] elasticsearch/client.go:733 Ping status code: 200
INFO elasticsearch/client.go:734 Attempting to connect to Elasticsearch version 7.0.0
DEBUG [elasticsearch] elasticsearch/client.go:752 GET http://localhost:9200/_xpack?human=false
DEBUG [elasticsearch] elasticsearch/client.go:752 HEAD http://localhost:9200/_template/apm-7.0.0
INFO template/load.go:129 Template already exists and will not be overwritten.
INFO [index-management] idxmgmt/supporter.go:196 Loaded index template.
INFO pipeline/output.go:105 Connection to backoff(elasticsearch(http://localhost:9200)) established
DEBUG [elasticsearch] elasticsearch/client.go:338 PublishEvents: 1 events have been published to elasticsearch in 3.383698ms.
DEBUG [publisher] memqueue/ackloop.go:160 ackloop: receive ack [0: 0, 1]
DEBUG [publisher] memqueue/eventloop.go:535 broker ACK events: count=1, start-seq=1, end-seq=1

DEBUG [publisher] memqueue/ackloop.go:128 ackloop: return ack to broker loop:1
DEBUG [publisher] memqueue/ackloop.go:131 ackloop: done send ack

(gonindzya) #5

@Freddy.Raj, can you send logs of your application from weblogic server with debug log_level enabled?

(Freddy Raj ) #6

I requested developer to enabled debug log and restart weblogic app server instance.
But unable to see any reference of apm in the log file.

Would want to know if my agent configuration is correct or not for java agent on a weblogic app server?

(gonindzya) #7

@Freddy.Raj
add the following lines after the setDomainEnv.sh call:
https://www.elastic.co/guide/en/apm/agent/java/current/setup-javaagent.html#setup-weblogic-unix

(gonindzya) #8

@Freddy.Raj ,
I launched weblogic 12.2.1.3 on docker, set parameters :

DOMAIN_HOME="/u01/oracle/user_projects/domains/abc_domain"

. ${DOMAIN_HOME}/bin/setDomainEnv.sh $*

export JAVA_OPTIONS="$JAVA_OPTIONS -javaagent:/u01/oracle/user_projects/domains/abc_domain/elastic-apm-agent-1.6.2-SNAPSHOT.jar"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.service_name=gullele-service"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.application_packages=com.gullele"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.server_urls=http://192.168.0.121:8200"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.log_level=DEBUG"

SAVE_JAVA_OPTIONS="${JAVA_OPTIONS}"

and at first, you can find success healthcheck information:

2019-05-16 20:51:48.384 [apm-server-healthcheck] INFO co.elastic.apm.agent.report.ApmServerHealthChecker - Elastic APM server is available: {"ok":{"build_date":"2019-01-24T10:23:10Z","build_sha":"7357ed8334b76d54c5b9a75f1e7c4cb7b308880e","version":"6.6.0"}}

and all log:

***************************************************
*  To start WebLogic Server, use a username and   *
*  password assigned to an admin-level user.  For *
*  server administration, use the WebLogic Server *
*  console at http://hostname:port/console        *
***************************************************
Starting WLS with line:
/usr/java/jdk1.8.0_211/bin/java -server   -Djava.security.egd=file:/dev/./urandom -cp /u01/oracle/wlserver/server/lib/weblogic-launcher.jar -Dlaunch.use.env.classpath=true -Dweblogic.Name=AdminServer -Djava.security.policy=/u01/oracle/wlserver/server/lib/weblogic.policy  -Djava.system.class.loader=com.oracle.classloader.weblogic.LaunchClassLoader  -javaagent:/u01/oracle/wlserver/server/lib/debugpatch-agent.jar -da -Dwls.home=/u01/oracle/wlserver/server -Dweblogic.home=/u01/oracle/wlserver/server     -javaagent:/u01/oracle/user_projects/domains/abc_domain/elastic-apm-agent-1.6.2-SNAPSHOT.jar -Delastic.apm.service_name=gullele-service -Delastic.apm.application_packages=com.gullele -Delastic.apm.server_urls=http://192.168.0.121:8200 -Delastic.apm.log_level=DEBUG  weblogic.Server
2019-05-16 20:51:48.296 [apm-server-healthcheck] DEBUG co.elastic.apm.agent.report.ApmServerHealthChecker - Starting healthcheck to http://192.168.0.121:8200/
2019-05-16 20:51:48.326 [main] DEBUG co.elastic.apm.agent.impl.payload.SystemInfo - container ID is 738c2de440839b8576ce29eb770a9c0ecbbce38a7a058ee1ee85960e01679551
2019-05-16 20:51:48.353 [main] INFO co.elastic.apm.agent.configuration.StartupInfo - Starting Elastic APM 1.6.2-SNAPSHOT as gullele-service on Java 1.8.0_211 (Oracle Corporation) Linux 5.0.0-13-generic
2019-05-16 20:51:48.353 [main] DEBUG co.elastic.apm.agent.configuration.StartupInfo - service_name: 'gullele-service' (source: Java System Properties)
2019-05-16 20:51:48.353 [main] DEBUG co.elastic.apm.agent.configuration.StartupInfo - server_urls: 'http://192.168.0.121:8200' (source: Java System Properties)
2019-05-16 20:51:48.354 [main] DEBUG co.elastic.apm.agent.configuration.StartupInfo - application_packages: 'com.gullele' (source: Java System Properties)
2019-05-16 20:51:48.354 [main] DEBUG co.elastic.apm.agent.configuration.StartupInfo - log_level: 'DEBUG' (source: Java System Properties)
2019-05-16 20:51:48.384 [apm-server-healthcheck] INFO co.elastic.apm.agent.report.ApmServerHealthChecker - Elastic APM server is available: {"ok":{"build_date":"2019-01-24T10:23:10Z","build_sha":"7357ed8334b76d54c5b9a75f1e7c4cb7b308880e","version":"6.6.0"}}
2019-05-16 20:51:48.415 [main] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Applying advice co.elastic.apm.agent.httpclient.ApacheHttpClientInstrumentation
...
2019-05-16 20:56:48.378 [apm-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving METRICS event (sequence 19)
2019-05-16 20:56:49.868 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to '' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) (1)
2019-05-16 20:56:49.868 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - startTransaction '' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) {
2019-05-16 20:56:49.868 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to '' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) (2)
2019-05-16 20:56:49.868 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Activating '' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) on thread 33
2019-05-16 20:56:49.869 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Deactivating 'LightServlet#doGet' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) on thread 33
2019-05-16 20:56:49.869 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'LightServlet#doGet' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) (1)
2019-05-16 20:56:49.869 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - } endTransaction 'LightServlet#doGet' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48)
2019-05-16 20:56:49.872 [apm-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving TRANSACTION event (sequence 20)
2019-05-16 20:56:49.872 [apm-reporter] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'LightServlet#doGet' 00-371d995851d09cadbcfed47b2fde61f4-3a38505c8854e4d0-01 (4ad60c48) (0)
2019-05-16 20:56:58.142 [apm-request-timeout-timer] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Request flush because the request timeout occurred
2019-05-16 20:56:58.149 [apm-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving FLUSH event (sequence 21)
2019-05-16 20:56:58.150 [apm-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEve

(gonindzya) #9

I found, that you have mistake in parameter: server_url, it should be server_urls

and secondly, you need to append the parameters to JAVA_OPTIONS(repeat here):

DOMAIN_HOME="/u01/oracle/user_projects/domains/abc_domain"

. ${DOMAIN_HOME}/bin/setDomainEnv.sh $*

export JAVA_OPTIONS="$JAVA_OPTIONS -javaagent:/u01/oracle/user_projects/domains/abc_domain/elastic-apm-agent-1.6.2-SNAPSHOT.jar"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.service_name=gullele-service"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.application_packages=com.gullele"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.server_urls=http://192.168.0.121:8200"
export JAVA_OPTIONS="$JAVA_OPTIONS -Delastic.apm.log_level=DEBUG"

SAVE_JAVA_OPTIONS="${JAVA_OPTIONS}"
(Freddy Raj ) #10

thank you @nugusbayevkk for all the suggestions and corrections.

I will update my setting as needed at agent side and restart weblogic application to see how the change looks. Will update once done.

(Freddy Raj ) #11

hi @nugusbayevkk.
Thank you so much for your help. I was able to follow above set up process and now data is visible in kibana.

Thanks again!