Getting HTTP 502 Bad Gateway from the APM agent

Elastic Observability APM
1

hi there,

We've built a docker image for the apm-server and got it running on cloudfoundry.
We then provisionned an elastic cluster.
Finally we pushed the agent to a basic nodejs application.
It seems to work between the agents and the apm-server; nevertheless, we see 'ERR Elastic APM HTTP error (502): 502 Bad Gateway: Registered endpoint failed to handle the request.'
Furthermore, it might be related to this 502 error, the thing is we don't see anything in Kibana.

Can you help to troubleshoot that 502 error please?

We enabled the DEBUG level environment variable to get more info. This is what we see from our demo app logs;

   2018-01-11T13:28:49.26+0000 [RTR/2] OUT default-app-nodejs.ourdomain.io - [2018-01-11T13:28:49.264+0000] "GET /public/favicon.ico HTTP/1.1" 200 0 1150 "http://default-app-nodejs.ourdomain.io/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" "100.xxx.xx.x:60902" "100.xxx.xxx.xx:61002" x_forwarded_for:"88.xxx.xx.xxx" x_forwarded_proto:"http" vcap_request_id:"c112927f-372f-4b2f-6bf7-b40847ab0ea3" response_time:0.002469495 app_id:"0bf8480d-dde9-48da-b30a-2d2d7b14c8fe" app_index:"0"
   2018-01-11T13:28:49.26+0000 [RTR/2] OUT 
   2018-01-11T13:28:48.67+0000 [RTR/1] OUT default-app-nodejs.ourdomain.io - [2018-01-11T13:28:48.664+0000] "GET / HTTP/1.1" 200 0 13891 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" "100.104.71.6:60901" "100.104.194.17:61002" x_forwarded_for:"88.xxx.xx.xxx" x_forwarded_proto:"http" vcap_request_id:"73193229-c729-4002-4140-fdfcf256c0fa" response_time:0.008735051 app_id:"0bf8480d-dde9-48da-b30a-2d2d7b14c8fe" app_index:"0"
   2018-01-11T13:28:48.67+0000 [RTR/1] OUT 
   2018-01-11T13:28:48.75+0000 [RTR/1] OUT default-app-nodejs.ourdomain.io - [2018-01-11T13:28:48.752+0000] "GET /public/sdx/css/sdx.min.css HTTP/1.1" 304 0 0 "http://default-app-nodejs.ourdomain.io/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" "100.xxx.xx.x:60901" "100.xxx.xxx.xx:61002" x_forwarded_for:"88.xxx.xx.xxx" x_forwarded_proto:"http" vcap_request_id:"d3de805e-ad9a-4cf7-50aa-411432ca2d0e" response_time:0.006003591 app_id:"0bf8480d-dde9-48da-b30a-2d2d7b14c8fe" app_index:"0"
   2018-01-11T13:28:48.75+0000 [RTR/1] OUT 
   2018-01-11T13:28:49.05+0000 [RTR/1] OUT default-app-nodejs.ourdomain.io - [2018-01-11T13:28:49.046+0000] "GET /public/sdx/fonts/TheSans/TheSansB_400_.woff2 HTTP/1.1" 304 0 0 "http://default-app-nodejs.ourdomain.io/public/sdx/css/sdx.min.css" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" "100.xxx.xx.x:60901" "100.xxx.xxx.xx:61002" x_forwarded_for:"88.xxx.xx.xxx" x_forwarded_proto:"http" vcap_request_id:"ad15035d-b838-4bde-5b89-97b91a610ec1" response_time:0.006060858 app_id:"0bf8480d-dde9-48da-b30a-2d2d7b14c8fe" app_index:"0"
   2018-01-11T13:28:49.05+0000 [RTR/1] OUT 
   2018-01-11T13:29:47.09+0000 [APP/PROC/WEB/0] ERR 2018-01-11T13:29:47.092Z elastic-apm flushing queue
   2018-01-11T13:29:47.09+0000 [APP/PROC/WEB/0] ERR 2018-01-11T13:29:47.094Z elastic-apm no active transaction found - cannot build new trace
   2018-01-11T13:29:47.09+0000 [APP/PROC/WEB/0] ERR 2018-01-11T13:29:47.093Z elastic-apm sending transactions payload
   2018-01-11T13:29:47.09+0000 [APP/PROC/WEB/0] ERR 2018-01-11T13:29:47.094Z elastic-apm intercepted call to http.request { id: null }
   2018-01-11T13:29:47.14+0000 [APP/PROC/WEB/0] ERR Elastic APM HTTP error (502): 502 Bad Gateway: Registered endpoint failed to handle the request.

You'll find below the logs of the apm-server;

   2018-01-11T13:29:48.28+0000 [RTR/2] OUT apm-server.ourdomain.io - [2018-01-11T13:29:48.280+0000] "POST /v1/transactions HTTP/1.1" 502 0 67 "-" "elastic-apm-node/0.10.0 elastic-apm-http-client/5.1.0" "100.xxx.xx.xx:47510" "100.xxx.xxx.xx:61006" x_forwarded_for:"212.xxx.xxx.xxx" x_forwarded_proto:"http" vcap_request_id:"90c114cb-f8fc-4ebc-4f9c-a2692d74671d" response_time:0.007585014 app_id:"cbb70351-7de3-473c-9cc5-8c959f525518" app_index:"0"
   2018-01-11T13:29:48.28+0000 [RTR/2] OUT 
   2018-01-11T13:29:48.74+0000 [APP/PROC/WEB/0] ERR 2018-01-11T13:29:48.745Z	DEBUG	[processes]	process/process.go:401	Filtered top processes down to 1 processes

We can see that the apm-server config looks OK:

root@926e11f4-c5d0-4944-43f9-ddf5:/go/src/github.com/elastic/apm-server# ./apm-server test config
Config OK

root@926e11f4-c5d0-4944-43f9-ddf5:/go/src/github.com/elastic/apm-server# ./apm-server test output
elasticsearch: http://f77113ca60b54ec293dadc7243c74e65.mc-sc1-lab-fornax-911.appcloud.swisscom.com:9200...
  parse url... OK
  connection...
    parse host... OK
    dns lookup... OK
    addresses: 212.243.87.240
    dial up... OK
  TLS... WARN secure connection disabled
  talk to server... OK
  version: 6.0.0

Versions;

Elastic Cluster:
Version: 6.0.0
Healthy instances: 1
Capacity: 1 GB

NodeJS:
"express": "^4.16.2"

2

Hi Orhan,

Thank you for trying out ElasticAPM. Do you mind sharing the full log from APM Server here?

best
Ron Cohen

3

Hi Ron,

Thanks for your quick reply.
Because of the limitation to 7000 characters for one post in the forum, I uploaded it to the internet.

Please follow the link below:
https://www.mycloud.ch/s/S001F432DF90F0863D0F1D7CE91EB62A027ED9ACDC8

Actually, I restarted the apm-server so that you get the entire log from the start.

Best ,
Orhan

4

Any chance to look at the apm server log @Ron?

5

Orhan,

I can see it's listening on localhost:80. If you're connecting from another machine/container, you'll need to change it to 0.0.0.0:80 or just :80. You can do that by setting the apm-server.host property: ./apm-server -E apm-server.host=:80

Let me know if that helps!

6

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.