Empty reply from server

Hello All

We’ve got a kong setup in a ECS cluster. When trying to configure kong, we find that accessing http://kong-container-ip:8001/plugins returns “Empty reply from server” intermittently. It’s not only for /plugins, even a simple / fails.

I say intermittently, because when I keep accessing port 8001 with a valid path, sometimes it starts to work. It definitely starts working again if I kong reload.

We’ve enabled debug on kong and inspected the logs for any errors or patterns. And the following patterns for noticed when it didn’t work and when it works.

When it doesn’t work:
2019/10/18 10:35:59 [debug] 589#0: *1871816 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571394867.982 to: 1571394959.529
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:246: Loading Admin API endpoints
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: correlation-id
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: pre-function
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: cors
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: ldap-auth
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: loggly
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: hmac-auth
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: zipkin
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: request-size-limiting
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: azure-functions
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: request-transformer
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: oauth2
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: response-transformer
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: ip-restriction
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: statsd
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: jwt
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:317: Loading API endpoints for plugin: proxy-cache
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: basic-auth
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: key-auth
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: http-log
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: datadog
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: tcp-log
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: rate-limiting
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: post-function
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:317: Loading API endpoints for plugin: prometheus
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: acl
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:317: Loading API endpoints for plugin: kubernetes-sidecar-injector
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: syslog
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: file-log
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: udp-log
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: response-ratelimiting
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: aws-lambda
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: session
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: bot-detection
2019/10/18 10:36:02 [debug] 566#0: *1871916 [lua] init.lua:325: No API endpoints loaded for plugin: request-termination
2019/10/18 10:36:03 [notice] 1#0: signal 17 (SIGCHLD) received from 566
2019/10/18 10:36:03 [alert] 1#0: worker process 566 exited on signal 9
2019/10/18 10:36:03 [notice] 1#0: start worker process 601
2019/10/18 10:36:03 [notice] 1#0: signal 29 (SIGIO) received
2019/10/18 10:36:03 [debug] 601#0: *1871923 [lua] globalpatches.lua:216: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
2019/10/18 10:36:03 [debug] 601#0: *1871923 [lua] globalpatches.lua:242: randomseed(): random seed: 471081641381 for worker nb 6
2019/10/18 10:36:03 [debug] 601#0: *1871923 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:03 [debug] 601#0: *1871924 [lua] balancer.lua:770: init(): initialized 0 balancer(s), 0 error(s)
2019/10/18 10:36:03 [debug] 591#0: *1871925 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:03 [debug] 584#0: *1871928 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:03 [debug] 589#0: *1871929 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:03 [debug] 569#0: *1871934 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:03 [debug] 578#0: *1871937 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:03 [debug] 597#0: *1871940 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:04 [debug] 598#0: *1871943 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=601, data=nil
2019/10/18 10:36:04 [debug] 584#0: *1871949 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571394963.463 to: 1571394964.543

When it works it has the following variations of the log patterns;
Logs 1:
2019/10/18 10:46:16 [debug] 650#0: *1888046 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571395572.281 to: 1571395576.622
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:246: Loading Admin API endpoints
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: correlation-id
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: pre-function
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: cors
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: ldap-auth
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: loggly
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: hmac-auth
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: zipkin
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: request-size-limiting
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: azure-functions
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: request-transformer
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: oauth2
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: response-transformer
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: ip-restriction
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: statsd
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: jwt
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:317: Loading API endpoints for plugin: proxy-cache
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: basic-auth
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: key-auth
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: http-log
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: datadog
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: tcp-log
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: rate-limiting
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: post-function
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:317: Loading API endpoints for plugin: prometheus
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: acl
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:317: Loading API endpoints for plugin: kubernetes-sidecar-injector
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: syslog
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: file-log
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: udp-log
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: response-ratelimiting
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: aws-lambda
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: session
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: bot-detection
2019/10/18 10:46:19 [debug] 650#0: *1888129 [lua] init.lua:325: No API endpoints loaded for plugin: request-termination
2019/10/18 10:46:20 [info] 650#0: *1888129 client 127.0.0.1 closed keepalive connection
2019/10/18 10:46:21 [debug] 650#0: *1888177 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571395572.281 to: 1571395581.654
2019/10/18 10:46:26 [debug] 650#0: *1888310 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571395572.281 to: 1571395586.662
2019/10/18 10:46:31 [debug] 650#0: *1888442 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571395572.281 to: 1571395591.666
2019/10/18 10:46:36 [debug] 650#0: *1888572 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571395572.281 to: 1571395596.68

Logs 2:
2019/10/18 10:47:41 [debug] 650#0: *1890270 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571395572.281 to: 1571395661.833
2019/10/18 10:47:43 [notice] 1#0: signal 17 (SIGCHLD) received from 650
2019/10/18 10:47:43 [alert] 1#0: worker process 650 exited on signal 9
2019/10/18 10:47:43 [notice] 1#0: start worker process 679
2019/10/18 10:47:43 [notice] 1#0: signal 29 (SIGIO) received
2019/10/18 10:47:43 [debug] 655#0: *1890325 [lua] init.lua:246: Loading Admin API endpoints
2019/10/18 10:47:43 [debug] 679#0: *1890326 [lua] globalpatches.lua:216: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
2019/10/18 10:47:43 [debug] 679#0: *1890326 [lua] globalpatches.lua:242: randomseed(): random seed: 211231126151 for worker nb 5
2019/10/18 10:47:43 [debug] 679#0: *1890326 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=679, data=nil
2019/10/18 10:47:43 [debug] 679#0: *1890327 [lua] balancer.lua:770: init(): initialized 0 balancer(s), 0 error(s)
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: correlation-id
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: pre-function
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: cors
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: ldap-auth
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: loggly
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: hmac-auth
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: zipkin
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: request-size-limiting
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: azure-functions
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: request-transformer
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: oauth2
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: response-transformer
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: ip-restriction
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: statsd
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: jwt
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:317: Loading API endpoints for plugin: proxy-cache
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: basic-auth
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: key-auth
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: http-log
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: datadog
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: tcp-log
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: rate-limiting
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: post-function
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:317: Loading API endpoints for plugin: prometheus
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: acl
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:317: Loading API endpoints for plugin: kubernetes-sidecar-injector
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: syslog
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: file-log
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: udp-log
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: response-ratelimiting
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: aws-lambda
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: session
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: bot-detection
2019/10/18 10:47:44 [debug] 655#0: *1890325 [lua] init.lua:325: No API endpoints loaded for plugin: request-termination
2019/10/18 10:47:44 [info] 655#0: *1890325 client 127.0.0.1 closed keepalive connection
2019/10/18 10:47:44 [debug] 661#0: *1890339 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=679, data=nil

Logs 3:
2019/10/18 11:15:40 [debug] 726#0: *1934172 [lua] cluster_events.lua:224: [cluster_events] polling events from: 1571397332.216 to: 1571397340.824
2019/10/18 11:15:41 [info] 720#0: *1934201 client 172.17.0.1 closed keepalive connection

The pattern noticed form the above is when it fails, init.lua gets killed before the client connection is closed.

We are on kong version 1.3.0.

Appreciate any help.

Cheers
– Imran

Answering my own question. It appears that by throwing more memory to the ecs tasks, this problem has gone away.

2019/10/18 10:47:43 [notice] 1#0: signal 17 (SIGCHLD) received from 650
2019/10/18 10:47:43 [alert] 1#0: worker process 650 exited on signal 9

Yes, from here you can see that the worker crashed, which can be caused by memory allocation failures.

Datong