Kong: Unhelpful error when no `dns_resolver` set

[nathanl]

Summary

After installing Kong on MacOS 10.12 via the .pkg installer, I set up the necessary database and ran curl localhost:8001. This resulted in a 500 response with the message "An unexpected error occurred", as did every other request to localhost:8001. The response gave me no clue about the nature of the problem.

Only the fact that my colleague had once gotten a DNS-related error message during setup gave us the idea to try setting a dns_resolver in the configuration. Simply setting dns_resolver = 8.8.8.8 fixed the issue.

If a dns_resolver is required, kong start should error helpfully, or kong check should point out the problem. Both behave as if everything is fine.

Steps To Reproduce

1. Install Kong from kong-0.10.1.osx.pkg
2. sudo cp /etc/kong/kong.conf.default /etc/kong/kong.conf
3. In psql, CREATE USER kong; CREATE DATABASE kong OWNER kong;
4. kong start
5. curl localhost:8001 - see 500 error

Additional Details & Logs

Kong version ($ kong version): 0.10.1

Kong debug-level startup logs ($ kong start --vv)

2017/04/14 06:24:11 [verbose] Kong: 0.10.1
2017/04/14 06:24:11 [debug] ngx_lua: 10007
2017/04/14 06:24:11 [debug] nginx: 1011002
2017/04/14 06:24:11 [debug] Lua: LuaJIT 2.1.0-beta2
2017/04/14 06:24:11 [verbose] reading config file at /etc/kong/kong.conf
2017/04/14 06:24:11 [debug] admin_listen = "0.0.0.0:8001"
2017/04/14 06:24:11 [debug] admin_listen_ssl = "0.0.0.0:8444"
2017/04/14 06:24:11 [debug] admin_ssl = true
2017/04/14 06:24:11 [debug] anonymous_reports = true
2017/04/14 06:24:11 [debug] cassandra_consistency = "ONE"
2017/04/14 06:24:11 [debug] cassandra_contact_points = {"127.0.0.1"}
2017/04/14 06:24:11 [debug] cassandra_data_centers = {"dc1:2","dc2:3"}
2017/04/14 06:24:11 [debug] cassandra_keyspace = "kong"
2017/04/14 06:24:11 [debug] cassandra_lb_policy = "RoundRobin"
2017/04/14 06:24:11 [debug] cassandra_port = 9042
2017/04/14 06:24:11 [debug] cassandra_repl_factor = 1
2017/04/14 06:24:11 [debug] cassandra_repl_strategy = "SimpleStrategy"
2017/04/14 06:24:11 [debug] cassandra_ssl = false
2017/04/14 06:24:11 [debug] cassandra_ssl_verify = false
2017/04/14 06:24:11 [debug] cassandra_timeout = 5000
2017/04/14 06:24:11 [debug] cassandra_username = "kong"
2017/04/14 06:24:11 [debug] cluster_listen = "0.0.0.0:7946"
2017/04/14 06:24:11 [debug] cluster_listen_rpc = "127.0.0.1:7373"
2017/04/14 06:24:11 [debug] cluster_profile = "wan"
2017/04/14 06:24:11 [debug] cluster_ttl_on_failure = 3600
2017/04/14 06:24:11 [debug] custom_plugins = {}
2017/04/14 06:24:11 [debug] database = "postgres"
2017/04/14 06:24:11 [debug] dns_hostsfile = "/etc/hosts"
2017/04/14 06:24:11 [debug] dns_resolver = {}
2017/04/14 06:24:11 [debug] log_level = "notice"
2017/04/14 06:24:11 [debug] lua_code_cache = "on"
2017/04/14 06:24:11 [debug] lua_package_cpath = ""
2017/04/14 06:24:11 [debug] lua_package_path = "?/init.lua;./kong/?.lua"
2017/04/14 06:24:11 [debug] lua_socket_pool_size = 30
2017/04/14 06:24:11 [debug] lua_ssl_verify_depth = 1
2017/04/14 06:24:11 [debug] mem_cache_size = "128m"
2017/04/14 06:24:11 [debug] nginx_daemon = "on"
2017/04/14 06:24:11 [debug] nginx_optimizations = true
2017/04/14 06:24:11 [debug] nginx_worker_processes = "auto"
2017/04/14 06:24:11 [debug] pg_database = "kong"
2017/04/14 06:24:11 [debug] pg_host = "127.0.0.1"
2017/04/14 06:24:11 [debug] pg_port = 5432
2017/04/14 06:24:11 [debug] pg_ssl = false
2017/04/14 06:24:11 [debug] pg_ssl_verify = false
2017/04/14 06:24:11 [debug] pg_user = "kong"
2017/04/14 06:24:11 [debug] prefix = "/usr/local/kong/"
2017/04/14 06:24:11 [debug] proxy_listen = "0.0.0.0:8000"
2017/04/14 06:24:11 [debug] proxy_listen_ssl = "0.0.0.0:8443"
2017/04/14 06:24:11 [debug] serf_path = "serf"
2017/04/14 06:24:11 [debug] ssl = true
2017/04/14 06:24:11 [debug] upstream_keepalive = 60
2017/04/14 06:24:11 [verbose] prefix in use: /usr/local/kong
2017/04/14 06:24:11 [verbose] preparing nginx prefix directory at /usr/local/kong
2017/04/14 06:24:11 [verbose] saving serf identifier to /usr/local/kong/serf/serf.id
2017/04/14 06:24:11 [debug] searching for OpenResty 'resty' executable
2017/04/14 06:24:11 [debug] /usr/local/openresty/bin/resty -V: 'nginx version: openresty/1.11.2.2'
2017/04/14 06:24:11 [debug] found OpenResty 'resty' executable at /usr/local/openresty/bin/resty
2017/04/14 06:24:11 [verbose] saving serf shell script handler to /usr/local/kong/serf/serf_event.sh
2017/04/14 06:24:11 [verbose] SSL enabled, no custom certificate set: using default certificate
2017/04/14 06:24:11 [verbose] default SSL certificate found at /usr/local/kong/ssl/kong-default.crt
2017/04/14 06:24:11 [verbose] Admin SSL enabled, no custom certificate set: using default certificate
2017/04/14 06:24:11 [verbose] admin SSL certificate found at /usr/local/kong/ssl/admin-kong-default.crt
2017/04/14 06:24:11 [warn] ulimit is currently set to "1024". For better performance set it to at least "4096" using "ulimit -n"
2017/04/14 06:24:11 [verbose] running datastore migrations
2017/04/14 06:24:11 [verbose] migrations up to date
2017/04/14 06:24:11 [verbose] serf agent not running, deleting /usr/local/kong/pids/serf.pid
2017/04/14 06:24:11 [debug] searching for 'serf' executable
2017/04/14 06:24:11 [debug] serf version: 'Serf v0.8.1'
2017/04/14 06:24:11 [debug] found 'serf' executable at serf
2017/04/14 06:24:11 [debug] starting serf agent: nohup serf agent -profile 'wan' -bind '0.0.0.0:7946' -log-level 'err' -rpc-addr '127.0.0.1:7373' -event-handler 'member-join,member-leave,member-failed,member-update,member-reap,user:kong=/usr/local/kong/serf/serf_event.sh' -node 'Nathans-MBP-2_0.0.0.0:7946_a5901bbedbd8454bb52c072bcf4e1f98' > /usr/local/kong/logs/serf.log 2>&1 & echo $! > /usr/local/kong/pids/serf.pid
2017/04/14 06:24:11 [verbose] waiting for serf agent to be running
2017/04/14 06:24:11 [debug] sending signal to pid at: /usr/local/kong/pids/serf.pid
2017/04/14 06:24:11 [debug] kill -0 `cat /usr/local/kong/pids/serf.pid` >/dev/null 2>&1
2017/04/14 06:24:11 [verbose] serf agent started
2017/04/14 06:24:11 [verbose] auto-joining serf cluster
2017/04/14 06:24:11 [verbose] no other nodes found in the cluster
2017/04/14 06:24:11 [verbose] registering serf node in datastore
2017/04/14 06:24:11 [verbose] cluster joined and node registered in datastore
2017/04/14 06:24:11 [debug] searching for OpenResty 'nginx' executable
2017/04/14 06:24:11 [debug] /usr/local/openresty/nginx/sbin/nginx -v: 'nginx version: openresty/1.11.2.2'
2017/04/14 06:24:11 [debug] found OpenResty 'nginx' executable at /usr/local/openresty/nginx/sbin/nginx
2017/04/14 06:24:11 [debug] starting nginx: /usr/local/openresty/nginx/sbin/nginx -p /usr/local/kong -c nginx.conf
2017/04/14 06:24:12 [debug] nginx started
2017/04/14 06:24:12 [info] Kong started

• Kong error logs (<KONG_PREFIX>/logs/error.log):

Only when creating this issue did I find the error log, which actually would have clued me in to the issue. I should have thought to look for this. It does contain lines like this after I run kong start:

2017/04/14 06:33:51 [error] 37777#0: *58 lua entry thread aborted: runtime error: /usr/local/openresty/lualib/resty/dns/resolver.lua:133:bad argument #1 to 'setpeername' (string expected, got nil)
stack traceback:
coroutine 0:
        [C]: in function 'setpeername'
        /usr/local/openresty/lualib/resty/dns/resolver.lua:133: in function 'new'

• Operating System: MacOS 10.12.4

[nathanl]

Arguably, you could close this issue and say, "whenever something goes wrong, you should obviously check the error log". I will have some satisfaction just knowing that this issue can now be found via web search.

[Tieske]

@nathanl can you post the contents of your resolv.conf and hosts files?

[nathanl]

@Tieske

# /etc/resolv.conf
#
# Mac OS X Notice
#
# This file is not used by the host name and address resolution
# or the DNS query routing mechanisms used by most processes on
# this Mac OS X system.
#
# This file is automatically generated.
#
domain attlocal.net
nameserver 2602:306:bca8:1ac0::1
nameserver 192.168.1.254

and

# /etc/hosts
##
# Host Database
#
# localhost is used to configure the loopback interface
# when the system is booting.  Do not change this entry.
##
127.0.0.1   localhost
255.255.255.255 broadcasthost
::1             localhost 

127.0.0.1   nathanmlong.dev

[Tieske]

The problem is related to the ipv6 nameserver, which isn't parsed correctly. If you change the order of the nameservers in your resolv.conf file it should work as expected.

[Tieske]

fixed in the dns lib version 0.5.0 scheduled to be released with Kong 0.11