Sporadic failure of DNS resolution - kong 0.11.1 in OpenShift

[abustya]

Summary

Opening a new issue after this one has been closed: https://github.com/Kong/kong/issues/2524

I am running kong in an OpenShift cluster, and I am still encountering random DNS resolution errors with version 0.11.1.

Steps To Reproduce

Error occurs when calling either the admin api (e.g. '/apis') or one of the proxied apis.

Additional Details & Logs

Error occurs for about 2% of calls. When running lots of calls subsequently, I see that the errors mostly occur in batches: for about 0.5-1 second all the calls fail, and then all is well again.

• Kong version: 0.11.1
• Kong error logs:

  2017/12/02 14:52:21 [debug] 1#0: [lua] globalpatches.lua:9: installing the globalpatches
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:343: init(): [dns-client] (re)configuring dns client
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:367: init(): [dns-client] query order: LAST, SRV, A, CNAME
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:399: init(): [dns-client] adding from 'hosts' file: kong-6-s1tqc = 10.129.6.255
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-mcastprefix = fe00::0
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-localnet = fe00::0
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:399: init(): [dns-client] adding from 'hosts' file: localhost = 127.0.0.1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: localhost = ::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-localhost = ::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-loopback = ::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-allnodes = fe00::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-allrouters = fe00::2
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:452: init(): [dns-client] nameserver 10.1.0.5
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:452: init(): [dns-client] nameserver 168.63.129.16
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:456: init(): [dns-client] attempts 5
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:465: init(): [dns-client] timeout 2000 ms
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:475: init(): [dns-client] badTtl 30 s
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:477: init(): [dns-client] emptyTtl 1 s
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:343: init(): [dns-client] (re)configuring dns client
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:367: init(): [dns-client] query order: LAST, SRV, A, CNAME
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:399: init(): [dns-client] adding from 'hosts' file: kong-6-s1tqc = 10.129.6.255
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-mcastprefix = fe00::0
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-localnet = fe00::0
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:399: init(): [dns-client] adding from 'hosts' file: localhost = 127.0.0.1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: localhost = ::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-localhost = ::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-loopback = ::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-allnodes = fe00::1
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:414: init(): [dns-client] adding from 'hosts' file: ip6-allrouters = fe00::2
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:452: init(): [dns-client] nameserver 10.1.0.5
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:452: init(): [dns-client] nameserver 168.63.129.16
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:456: init(): [dns-client] attempts 5
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:465: init(): [dns-client] timeout 2000 ms
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:475: init(): [dns-client] badTtl 30 s
  2017/12/02 14:52:21 [debug] 1#0: [lua] client.lua:477: init(): [dns-client] emptyTtl 1 s
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:76: load_plugins(): Discovering used plugins
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: response-transformer
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: correlation-id
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: statsd
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: jwt
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: cors
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: basic-auth
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: key-auth
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: ldap-auth
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: oauth2
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: http-log
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: ip-restriction
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: hmac-auth
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: request-size-limiting
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: datadog
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: tcp-log
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: request-transformer
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: file-log
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: acl
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: bot-detection
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: loggly
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: galileo
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: syslog
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: udp-log
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: response-ratelimiting
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: aws-lambda
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: runscope
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: rate-limiting
  2017/12/02 14:52:21 [debug] 1#0: [lua] init.lua:104: load_plugins(): Loading plugin: request-termination
  2017/12/02 14:52:21 [notice] 1#0: using the "epoll" event method
  2017/12/02 14:52:21 [notice] 1#0: openresty/1.11.2.4
  2017/12/02 14:52:21 [notice] 1#0: built by gcc 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC) 
  2017/12/02 14:52:21 [notice] 1#0: OS: Linux 3.10.0-693.el7.x86_64
  2017/12/02 14:52:21 [notice] 1#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576
  2017/12/02 14:52:21 [notice] 1#0: start worker processes
  2017/12/02 14:52:21 [notice] 1#0: start worker process 49
  2017/12/02 14:52:21 [notice] 1#0: start worker process 50
  2017/12/02 14:52:21 [notice] 1#0: start worker process 51
  2017/12/02 14:52:21 [notice] 1#0: start worker process 52
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] globalpatches.lua:220: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] globalpatches.lua:246: randomseed(): random seed: 151121251915 for worker nb 0
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] globalpatches.lua:220: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] globalpatches.lua:246: randomseed(): random seed: 254135822481 for worker nb 1
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] globalpatches.lua:220: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] globalpatches.lua:246: randomseed(): random seed: 170939813518 for worker nb 2
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] globalpatches.lua:220: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] globalpatches.lua:246: randomseed(): random seed: 187136189472 for worker nb 3
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "bot-detection": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "cors": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "jwt": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "oauth2": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "key-auth": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "ldap-auth": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "basic-auth": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "hmac-auth": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "ip-restriction": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-size-limiting": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "acl": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "rate-limiting": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-ratelimiting": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-transformer": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-transformer": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "aws-lambda": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "http-log": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "statsd": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "datadog": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "file-log": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "udp-log": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-termination": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "loggly": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "runscope": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "syslog": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "galileo": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "tcp-log": init_worker
  2017/12/02 14:52:21 [debug] 50#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "correlation-id": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "bot-detection": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "cors": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "jwt": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "oauth2": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "key-auth": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "ldap-auth": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "basic-auth": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "hmac-auth": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "ip-restriction": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-size-limiting": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "acl": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "rate-limiting": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-ratelimiting": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-transformer": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-transformer": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "aws-lambda": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "http-log": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "statsd": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "datadog": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "file-log": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "udp-log": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-termination": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "loggly": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "runscope": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "syslog": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "galileo": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "tcp-log": init_worker
  2017/12/02 14:52:21 [debug] 52#0: *4 [lua] base_plugin.lua:12: init_worker(): executing plugin "correlation-id": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "bot-detection": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "cors": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "jwt": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "oauth2": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "key-auth": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "ldap-auth": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "basic-auth": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "hmac-auth": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "ip-restriction": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-size-limiting": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "acl": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "rate-limiting": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-ratelimiting": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-transformer": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-transformer": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "aws-lambda": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "http-log": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "statsd": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "datadog": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "file-log": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "udp-log": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-termination": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "loggly": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "runscope": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "syslog": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "galileo": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "tcp-log": init_worker
  2017/12/02 14:52:21 [debug] 51#0: *3 [lua] base_plugin.lua:12: init_worker(): executing plugin "correlation-id": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "bot-detection": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "cors": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "jwt": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "oauth2": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "key-auth": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "ldap-auth": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "basic-auth": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "hmac-auth": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "ip-restriction": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-size-limiting": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "acl": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "rate-limiting": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-ratelimiting": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-transformer": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-transformer": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "aws-lambda": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "http-log": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "statsd": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "datadog": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "file-log": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "udp-log": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-termination": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "loggly": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "runscope": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "syslog": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "galileo": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "tcp-log": init_worker
  2017/12/02 14:52:21 [debug] 49#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "correlation-id": init_worker
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:122: Loading Admin API endpoints
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: response-transformer
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: correlation-id
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: statsd
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:139: Loading API endpoints for plugin: jwt
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: cors
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:139: Loading API endpoints for plugin: basic-auth
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:139: Loading API endpoints for plugin: key-auth
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: ldap-auth
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:139: Loading API endpoints for plugin: oauth2
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: http-log
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: ip-restriction
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:139: Loading API endpoints for plugin: hmac-auth
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: request-size-limiting
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: datadog
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: tcp-log
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: request-transformer
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: file-log
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:139: Loading API endpoints for plugin: acl
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: bot-detection
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: loggly
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: galileo
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: syslog
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: udp-log
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: response-ratelimiting
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: aws-lambda
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: runscope
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: rate-limiting
  2017/12/02 14:52:51 [debug] 50#0: *238 [lua] init.lua:143: No API endpoints loaded for plugin: request-termination
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:122: Loading Admin API endpoints
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: response-transformer
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: correlation-id
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: statsd
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:139: Loading API endpoints for plugin: jwt
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: cors
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:139: Loading API endpoints for plugin: basic-auth
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:139: Loading API endpoints for plugin: key-auth
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: ldap-auth
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:139: Loading API endpoints for plugin: oauth2
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: http-log
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: ip-restriction
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:139: Loading API endpoints for plugin: hmac-auth
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: request-size-limiting
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: datadog
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: tcp-log
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: request-transformer
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: file-log
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:139: Loading API endpoints for plugin: acl
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: bot-detection
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: loggly
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: galileo
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: syslog
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: udp-log
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: response-ratelimiting
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: aws-lambda
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: runscope
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: rate-limiting
  2017/12/02 14:53:01 [debug] 51#0: *404 [lua] init.lua:143: No API endpoints loaded for plugin: request-termination
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:122: Loading Admin API endpoints
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: response-transformer
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: correlation-id
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: statsd
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:139: Loading API endpoints for plugin: jwt
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: cors
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:139: Loading API endpoints for plugin: basic-auth
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:139: Loading API endpoints for plugin: key-auth
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: ldap-auth
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:139: Loading API endpoints for plugin: oauth2
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: http-log
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: ip-restriction
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:139: Loading API endpoints for plugin: hmac-auth
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: request-size-limiting
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: datadog
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: tcp-log
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: request-transformer
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: file-log
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:139: Loading API endpoints for plugin: acl
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: bot-detection
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: loggly
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: galileo
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: syslog
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: udp-log
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: response-ratelimiting
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: aws-lambda
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: runscope
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: rate-limiting
  2017/12/02 14:53:10 [debug] 49#0: *580 [lua] init.lua:143: No API endpoints loaded for plugin: request-termination
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:122: Loading Admin API endpoints
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: response-transformer
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: correlation-id
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: statsd
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:139: Loading API endpoints for plugin: jwt
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: cors
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:139: Loading API endpoints for plugin: basic-auth
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:139: Loading API endpoints for plugin: key-auth
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: ldap-auth
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:139: Loading API endpoints for plugin: oauth2
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: http-log
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: ip-restriction
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:139: Loading API endpoints for plugin: hmac-auth
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: request-size-limiting
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: datadog
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: tcp-log
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: request-transformer
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: file-log
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:139: Loading API endpoints for plugin: acl
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: bot-detection
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: loggly
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: galileo
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: syslog
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: udp-log
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: response-ratelimiting
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: aws-lambda
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: runscope
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: rate-limiting
  2017/12/02 14:53:16 [debug] 52#0: *696 [lua] init.lua:143: No API endpoints loaded for plugin: request-termination
  2017/12/02 14:54:21 [error] 50#0: *1746 [lua] postgres.lua:197: [postgres] could not cleanup TTLs: [toip() name lookup failed]: dns server error: 3 name error, context: ngx.timer
  2017/12/02 14:55:21 [error] 49#0: *2440 [lua] postgres.lua:197: [postgres] could not cleanup TTLs: [toip() name lookup failed]: dns server error: 3 name error, context: ngx.timer
  2017/12/02 14:55:51 [error] 52#0: *2739 [lua] responses.lua:107: handler(): [toip() name lookup failed]: dns server error: 2 server failure, client: 10.129.4.1, server: kong_admin, request: "GET /apis HTTP/1.1", host: "kong-admin-ci.apps.mydomain.com"
  2017/12/02 14:56:21 [error] 49#0: *2950 [lua] postgres.lua:197: [postgres] could not cleanup TTLs: [toip() name lookup failed]: dns server error: 3 name error, context: ngx.timer
  2017/12/02 14:57:03 [error] 50#0: *3560 [lua] responses.lua:107: handler(): [toip() name lookup failed]: dns server error: 3 name error, client: 10.130.4.1, server: kong_admin, request: "GET /apis HTTP/1.1", host: "kong-admin-ci.apps.mydomain.com"
  2017/12/02 14:58:09 [debug] 50#0: *4059 [lua] balancer.lua:32: fetching all upstreams
  2017/12/02 14:58:21 [error] 49#0: *4271 [lua] postgres.lua:197: [postgres] could not cleanup TTLs: [toip() name lookup failed]: dns server error: 3 name error, context: ngx.timer
  2017/12/02 14:58:41 [error] 50#0: *4620 [lua] balancer.lua:310: execute(): name resolution failed for 'exchange-api': dns server error: 3 name error, client: 10.129.4.1, server: kong, request: "GET /exchange/swagger HTTP/1.1", host: "kong-ci.apps.mydomain.com"

• Operating System: Running in OpenShift cluster from docker image created from official kong image. The only changes are made to allow OpenShift users to access directories where kong needs to write to:

  FROM kong:0.11.1
  RUN mkdir /usr/local/kong
  RUN chgrp -R 0 /usr/local/kong && \
  chmod -R g=u /usr/local/kong
  USER 1001

[subnetmarco]

Pinging @Tieske

[Tieske]

@abustya dns server error: 3 name error means the server did send an answer, but the answer was either empty or didn't contain the requested name. dns server error: 2 server failure indicates that your dns server ran into an error.

From the logs it appears as if this only happens when looking up the postgres database.

1. Do you see other occurrences in the logs?
2. What is the dns part of your Kong config file?
3. and what environment variables on top of that are you using, if any?
4. can you share the resolv.conf file you have on your system?
5. you have 2 name servers (10.1.0.5 and 168.63.129.16), does the error persist if you disable either one of those?

In all honesty, looks like a problem with your nameservers.

[abustya]

1. Yes, the last line in the log: name resolution failed for 'exchange-api': dns server error: 3 name error. This is one of the backend api-s configured to be proxied.

2. None of the dns_* properties are customized. (Actually, I don't even have a kong.conf file, only the kong.conf.default, untouched.)

3. Env vars:

   KONG_DATABASE=postgres
   KONG_LUA_SSL_TRUSTED_CERTIFICATE=/etc/pki/tls/certs/ca-bundle.crt
   KONG_LUA_SSL_VERIFY_DEPTH=3
   KONG_PG_HOST=kong-database
   KONG_PG_PASSWORD=kong
   KONG_PG_USER=kong

4. resolv.conf contents:

   search ci.svc.cluster.local svc.cluster.local cluster.local ua5hp3m0b0butcqmu5iwql5ykd.ax.internal.cloudapp.net
   nameserver 10.1.0.5
   nameserver 168.63.129.16
   options ndots:5

5. The first nameserver is responsible for resolution of domains inside the cluster, the secord for outside. If I only leave the one for inside resolution, the error no longer occurs. If I only leave the one for outside, the error occurs constantly.

Only leaving the fist nameserver actually seems like a viable workaround at the moment, though I think later I will also need to add api-s from outsige the cluster.

[Tieske]

You should reconfigure your dns, this will never work.

Actually it appears because of a bug in the dns resolver, if that bug wouldn't have been around, it might have worked, but only because of retries being done. So it would only have masked the bad configuration, and you'd have very high dns resolution latency.

The dns client will randomly pick a dns server to resolve names (to spread the load), so in cases where it picks your "outside" server, it will obviously fail to resolve internal names, because they are unknown at that server.

You should always use the internal server, and configure that server to lookup on your external server (in a chained fashion).

Closing this now. If you think this is not resolved, then please feel free to reopen.