Kong / kong

🦍 The Cloud-Native API Gateway and AI Gateway.
https://konghq.com/install/
Apache License 2.0
39.36k stars 4.82k forks source link

connect to unix socked failed #3626

Closed rucciva closed 6 years ago

rucciva commented 6 years ago

NOTE: GitHub issues are reserved for bug reports only. For anything else, please join the conversation in Kong Nation https://discuss.konghq.com/.

Please read the CONTRIBUTING.md guidelines to learn on which channels you can seek for help and ask general questions:

https://github.com/Kong/kong/blob/master/CONTRIBUTING.md#where-to-seek-for-help

Summary

tcpsocket return bad argument #2 to 'connect' (number expected, got nil) whan calling connect method with UNIX socket address, unlike what stated in ngx.socket.tcp documentation,

Steps To Reproduce

  1. create custom plugin based on tcp-log and modify the call to connect method by ommiting the port parameter when the host start with unix:
  2. start another program that listen in the unix socket
  3. create api and then add the custom plugin to the api
  4. invoke the api

Additional Details & Logs

kong_1         | preparation done. Executing command: ./bin/kong start -vv -c ./bin/kong.conf
kong_1         | 2018/07/17 08:36:46 [verbose] Kong: 0.14.0
kong_1         | 2018/07/17 08:36:46 [debug] ngx_lua: 10013
kong_1         | 2018/07/17 08:36:46 [debug] nginx: 1013006
kong_1         | 2018/07/17 08:36:46 [warn] the 'custom_plugins' configuration property is deprecated, use 'plugins' instead
kong_1         | 2018/07/17 08:36:46 [debug] Lua: LuaJIT 2.1.0-beta3
kong_1         | 2018/07/17 08:36:46 [verbose] reading config file at ./bin/kong.conf
kong_1         | 2018/07/17 08:36:46 [debug] reading environment variables
kong_1         | 2018/07/17 08:36:46 [debug] KONG_ADMIN_LISTEN ENV found with "0.0.0.0:8001"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_TRUSTED_IPS ENV found with "0.0.0.0/0,::/0"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_PREFIX ENV found with "/prefix"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_CUSTOM_PLUGINS ENV found with "mobdebug,mainapi_log"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_PG_HOST ENV found with "postgres"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_DATABASE ENV found with "postgres"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_ADMIN_ERROR_LOG ENV found with "/proc/1/fd/2"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_ADMIN_ACCESS_LOG ENV found with "/proc/1/fd/2"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_LOG_LEVEL ENV found with "debug"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_PROXY_ERROR_LOG ENV found with "/proc/1/fd/2"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_NGINX_DAEMON ENV found with "off"
kong_1         | 2018/07/17 08:36:46 [debug] KONG_PROXY_ACCESS_LOG ENV found with "/proc/1/fd/1"
kong_1         | 2018/07/17 08:36:46 [debug] admin_access_log = "/proc/1/fd/2"
kong_1         | 2018/07/17 08:36:46 [debug] admin_error_log = "/proc/1/fd/2"
kong_1         | 2018/07/17 08:36:46 [debug] admin_listen = {"0.0.0.0:8001"}
kong_1         | 2018/07/17 08:36:46 [debug] anonymous_reports = true
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_consistency = "ONE"
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_contact_points = {"127.0.0.1"}
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_data_centers = {"dc1:2","dc2:3"}
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_keyspace = "kong"
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_lb_policy = "RoundRobin"
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_port = 9042
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_repl_factor = 1
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_repl_strategy = "SimpleStrategy"
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_schema_consensus_timeout = 10000
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_ssl = false
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_ssl_verify = false
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_timeout = 5000
kong_1         | 2018/07/17 08:36:46 [debug] cassandra_username = "kong"
kong_1         | 2018/07/17 08:36:46 [debug] client_body_buffer_size = "8k"
kong_1         | 2018/07/17 08:36:46 [debug] client_max_body_size = "0"
kong_1         | 2018/07/17 08:36:46 [debug] client_ssl = false
kong_1         | 2018/07/17 08:36:46 [debug] custom_plugins = {"mobdebug","mainapi_log"}
kong_1         | 2018/07/17 08:36:46 [debug] database = "postgres"
kong_1         | 2018/07/17 08:36:46 [debug] db_cache_ttl = 0
kong_1         | 2018/07/17 08:36:46 [debug] db_resurrect_ttl = 30
kong_1         | 2018/07/17 08:36:46 [debug] db_update_frequency = 5
kong_1         | 2018/07/17 08:36:46 [debug] db_update_propagation = 0
kong_1         | 2018/07/17 08:36:46 [debug] dns_error_ttl = 1
kong_1         | 2018/07/17 08:36:46 [debug] dns_hostsfile = "/etc/hosts"
kong_1         | 2018/07/17 08:36:46 [debug] dns_no_sync = false
kong_1         | 2018/07/17 08:36:46 [debug] dns_not_found_ttl = 30
kong_1         | 2018/07/17 08:36:46 [debug] dns_order = {"LAST","SRV","A","CNAME"}
kong_1         | 2018/07/17 08:36:46 [debug] dns_resolver = {}
kong_1         | 2018/07/17 08:36:46 [debug] dns_stale_ttl = 4
kong_1         | 2018/07/17 08:36:46 [debug] error_default_type = "text/plain"
kong_1         | 2018/07/17 08:36:46 [debug] headers = {"server_tokens","latency_tokens"}
kong_1         | 2018/07/17 08:36:46 [debug] log_level = "debug"
kong_1         | 2018/07/17 08:36:46 [debug] lua_package_cpath = ""
kong_1         | 2018/07/17 08:36:46 [debug] lua_package_path = "./?.lua;./?/init.lua;"
kong_1         | 2018/07/17 08:36:46 [debug] lua_socket_pool_size = 30
kong_1         | 2018/07/17 08:36:46 [debug] lua_ssl_verify_depth = 1
kong_1         | 2018/07/17 08:36:46 [debug] mem_cache_size = "128m"
kong_1         | 2018/07/17 08:36:46 [debug] nginx_admin_directives = {}
kong_1         | 2018/07/17 08:36:46 [debug] nginx_daemon = "off"
kong_1         | 2018/07/17 08:36:46 [debug] nginx_http_directives = {}
kong_1         | 2018/07/17 08:36:46 [debug] nginx_optimizations = true
kong_1         | 2018/07/17 08:36:46 [debug] nginx_proxy_directives = {}
kong_1         | 2018/07/17 08:36:46 [debug] nginx_user = "nobody nobody"
kong_1         | 2018/07/17 08:36:46 [debug] nginx_worker_processes = "auto"
kong_1         | 2018/07/17 08:36:46 [debug] pg_database = "kong"
kong_1         | 2018/07/17 08:36:46 [debug] pg_host = "postgres"
kong_1         | 2018/07/17 08:36:46 [debug] pg_port = 5432
kong_1         | 2018/07/17 08:36:46 [debug] pg_ssl = false
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] globalpatches.lua:9: installing the globalpatches
kong_1         | 2018/07/17 08:36:47 [warn] 33#0: [lua] log.lua:63: log(): the 'custom_plugins' configuration property is deprecated, use 'plugins' instead
kong_1         | nginx: [warn] [lua] log.lua:63: log(): the 'custom_plugins' configuration property is deprecated, use 'plugins' instead
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:431: init(): [dns-client] (re)configuring dns client
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:435: init(): [dns-client] staleTtl = 4
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:438: init(): [dns-client] noSynchronisation = false
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:457: init(): [dns-client] query order = LAST, SRV, A, CNAME
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:489: init(): [dns-client] adding A-record from 'hosts' file: bedbf0bf7230 =172.16.1.4
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-mcastprefix = [ff00::0]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-localnet = [fe00::0]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:489: init(): [dns-client] adding A-record from 'hosts' file: localhost = 127.0.0.1
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: localhost =[::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-localhost = [::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-loopback = [::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-allnodes = [ff02::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-allrouters = [ff02::2]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:548: init(): [dns-client] nameserver 127.0.0.11
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:553: init(): [dns-client] attempts = 5
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:562: init(): [dns-client] timeout = 2000 ms
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:566: init(): [dns-client] ndots = 0
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:568: init(): [dns-client] search = telkom.co.id
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:574: init(): [dns-client] badTtl = 30 s
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:576: init(): [dns-client] emptyTtl = 1 s
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:98: load_plugins(): Discovering used plugins
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: correlation-id
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: pre-function
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: cors
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: rate-limiting
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: loggly
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: hmac-auth
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: zipkin
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: request-size-limiting
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: azure-functions
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: request-transformer
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: oauth2
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: response-transformer
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: ip-restriction
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: statsd
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: jwt
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: basic-auth
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: key-auth
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: http-log
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: mainapi_log
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: datadog
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: tcp-log
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: post-function
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: acl
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: mobdebug
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: prometheus
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: syslog
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: response-ratelimiting
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: udp-log
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: file-log
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: aws-lambda
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: bot-detection
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: ldap-auth
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] init.lua:132: load_plugins(): Loading plugin: request-termination
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:431: init(): [dns-client] (re)configuring dns client
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:435: init(): [dns-client] staleTtl = 4
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:438: init(): [dns-client] noSynchronisation = false
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:457: init(): [dns-client] query order = LAST, SRV, A, CNAME
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:489: init(): [dns-client] adding A-record from 'hosts' file: bedbf0bf7230 =172.16.1.4
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-mcastprefix = [ff00::0]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-localnet = [fe00::0]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:489: init(): [dns-client] adding A-record from 'hosts' file: localhost = 127.0.0.1
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: localhost =[::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-localhost = [::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-loopback = [::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-allnodes = [ff02::1]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:504: init(): [dns-client] adding AAAA-record from 'hosts' file: ip6-allrouters = [ff02::2]
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:548: init(): [dns-client] nameserver 127.0.0.11
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:553: init(): [dns-client] attempts = 5
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:562: init(): [dns-client] timeout = 2000 ms
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:566: init(): [dns-client] ndots = 0
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:568: init(): [dns-client] search = telkom.co.id
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:574: init(): [dns-client] badTtl = 30 s
kong_1         | 2018/07/17 08:36:47 [debug] 33#0: [lua] client.lua:576: init(): [dns-client] emptyTtl = 1 s
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: using the "epoll" event method
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: openresty/1.13.6.2
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: built by gcc 4.8.4 (Ubuntu 4.8.4-2ubuntu1~14.04.4)
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: OS: Linux 4.9.60-linuxkit-aufs
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: start worker processes
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: start worker process 41
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] globalpatches.lua:224: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] globalpatches.lua:250: randomseed(): random seed: 203298166148 for worker nb 0
kong_1         | 2018/07/17 08:36:47 [notice] 33#0: start worker process 42
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] globalpatches.lua:224: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] globalpatches.lua:250: randomseed(): random seed: 125129314158 for worker nb 1
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] events.lua:192: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=41, data=nil
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] events.lua:192: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=42, data=nil
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "pre-function": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "pre-function": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "opentracing": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "mobdebug": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "bot-detection": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "cors": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "jwt": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "oauth2": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "key-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "ldap-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "basic-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:24: access(): executing plugin "mainapi_log": access
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "hmac-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "ip-restriction": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-size-limiting": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "acl": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "rate-limiting": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-ratelimiting": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-transformer": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-transformer": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "aws-lambda": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "azure-functions": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "prometheus": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "http-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "statsd": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "datadog": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "file-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "udp-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "tcp-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "loggly": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "syslog": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-termination": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "correlation-id": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 42#0: *2 [lua] base_plugin.lua:12: init_worker(): executing plugin "post-function": init_worker
kong_1         | 2018/07/17 08:36:49 [debug] 42#0: *3 [lua] balancer.lua:464: fetching all upstreams
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "opentracing": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "mobdebug": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "bot-detection": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "cors": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "jwt": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "oauth2": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "key-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "ldap-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "basic-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:24: access(): executing plugin "mainapi_log": access
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "hmac-auth": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "ip-restriction": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-size-limiting": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "acl": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "rate-limiting": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-ratelimiting": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-transformer": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "response-transformer": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "aws-lambda": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "azure-functions": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "prometheus": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "http-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "statsd": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "datadog": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "file-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "udp-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "tcp-log": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "loggly": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "syslog": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "request-termination": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "correlation-id": init_worker
kong_1         | 2018/07/17 08:36:47 [debug] 41#0: *1 [lua] base_plugin.lua:12: init_worker(): executing plugin "post-function": init_worker
kong_1         | 2018/07/17 08:36:49 [debug] 41#0: *8 [lua] events.lua:192: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started, pid=42, data=nil
kong_1         | 2018/07/17 08:36:52 [debug] 42#0: *15 [lua] cluster_events.lua:222: [cluster_events] polling events from: 1531816607.559 to: 1531816612.561
kong_1         | 2018/07/17 08:36:54 [crit] 41#0: *7 [lua] balancer.lua:710: init(): failed loading initial list of upstreams: failed to get from node cache: could not acquire callback lock: timeout, context: ngx.timer
kong_1         | 2018/07/17 08:37:09 [debug] 42#0: *3 [lua] balancer.lua:725: init(): initialized 0 balancer(s), 0 error(s)
kong_1         | 2018/07/17 08:37:12 [debug] 41#0: *73 [lua] cluster_events.lua:222: [cluster_events] polling events from: 1531816607.559 to: 1531816632.567
2018/07/17 08:37:26 [error] 41#0: *122 [lua] handler.lua:31: unix:/var/run/logagent/tcp.sock, context: ngx.timer, client: 172.16.1.1, server: 0.0.0.0:8000

2018/07/17 08:37:46 [error] 41#0: *122 lua entry thread aborted: runtime error: ./kong/plugins/mainapi_log/handler.lua:32: badargument #2 to 'connect' (number expected, got nil)

stack traceback:

coroutine 0:

       [C]: in function 'connect'

       ./kong/plugins/mainapi_log/handler.lua:32: in function <./kong/plugins/mainapi_log/handler.lua:15>, context: ngx.timer,client: 172.16.1.1, server: 0.0.0.0:8000
{"plugins":{"enabled_in_cluster":["mainapi_log"],"available_on_server":{"correlation-id":true,"pre-function":true,"cors":true,"rate-limiting":true,"loggly":true,"hmac-auth":true,"zipkin":true,"request-size-limiting":true,"azure-functions":true,"request-transformer":true,"oauth2":true,"response-transformer":true,"ip-restriction":true,"statsd":true,"jwt":true,"basic-auth":true,"key-auth":true,"http-log":true,"mainapi_log":true,"datadog":true,"tcp-log":true,"post-function":true,"acl":true,"mobdebug":true,"prometheus":true,"syslog":true,"response-ratelimiting":true,"udp-log":true,"file-log":true,"aws-lambda":true,"bot-detection":true,"ldap-auth":true,"request-termination":true}},"tagline":"Welcome to kong","configuration":{"plugins":["bundled"],"admin_ssl_enabled":false,"lua_ssl_verify_depth":1,"trusted_ips":["0.0.0.0\/0","::\/0"],"prefix":"\/prefix","loaded_plugins":{"correlation-id":true,"pre-function":true,"cors":true,"ldap-auth":true,"loggly":true,"hmac-auth":true,"zipkin":true,"bot-detection":true,"azure-functions":true,"request-transformer":true,"oauth2":true,"response-transformer":true,"syslog":true,"statsd":true,"jwt":true,"basic-auth":true,"key-auth":true,"http-log":true,"mainapi_log":true,"datadog":true,"tcp-log":true,"post-function":true,"rate-limiting":true,"acl":true,"ip-restriction":true,"response-ratelimiting":true,"mobdebug":true,"udp-log":true,"file-log":true,"aws-lambda":true,"prometheus":true,"request-size-limiting":true,"request-termination":true},"cassandra_username":"kong","admin_ssl_cert_csr_default":"\/prefix\/ssl\/admin-kong-default.csr","ssl_cert_key":"\/prefix\/ssl\/kong-default.key","dns_resolver":{},"pg_user":"kong","mem_cache_size":"128m","cassandra_data_centers":["dc1:2","dc2:3"],"nginx_admin_directives":{},"custom_plugins":["mobdebug","mainapi_log"],"pg_host":"postgres","nginx_acc_logs":"\/prefix\/logs\/access.log","proxy_listen":["0.0.0.0:8000","0.0.0.0:8443 ssl"],"client_ssl_cert_default":"\/prefix\/ssl\/kong-default.crt","ssl_cert_key_default":"\/prefix\/ssl\/kong-default.key","dns_no_sync":false,"db_update_propagation":0,"nginx_err_logs":"\/prefix\/logs\/error.log","cassandra_port":9042,"dns_order":["LAST","SRV","A","CNAME"],"dns_error_ttl":1,"headers":["server_tokens","latency_tokens"],"dns_stale_ttl":4,"nginx_optimizations":true,"database":"postgres","pg_database":"kong","nginx_worker_processes":"auto","lua_package_cpath":"","admin_acc_logs":"\/prefix\/logs\/admin_access.log","lua_package_path":".\/?.lua;.\/?\/init.lua;","nginx_pid":"\/prefix\/pids\/nginx.pid","upstream_keepalive":60,"admin_access_log":"\/proc\/1\/fd\/2","client_ssl_cert_csr_default":"\/prefix\/ssl\/kong-default.csr","proxy_listeners":[{"ssl":false,"ip":"0.0.0.0","proxy_protocol":false,"port":8000,"http2":false,"listener":"0.0.0.0:8000"},{"ssl":true,"ip":"0.0.0.0","proxy_protocol":false,"port":8443,"http2":false,"listener":"0.0.0.0:8443 ssl"}],"proxy_ssl_enabled":true,"cassandra_contact_points":["127.0.0.1"],"enabled_headers":{"latency_tokens":true,"X-Kong-Proxy-Latency":true,"Via":true,"server_tokens":true,"Server":true,"X-Kong-Upstream-Latency":true,"X-Kong-Upstream-Status":false},"ssl_ciphers":"ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256","cassandra_ssl":false,"db_resurrect_ttl":30,"ssl_cert_csr_default":"\/prefix\/ssl\/kong-default.csr","cassandra_consistency":"ONE","client_max_body_size":"0","admin_error_log":"\/proc\/1\/fd\/2","pg_ssl_verify":false,"dns_not_found_ttl":30,"pg_ssl":false,"cassandra_schema_consensus_timeout":10000,"client_ssl":false,"cassandra_repl_strategy":"SimpleStrategy","db_update_frequency":5,"nginx_kong_conf":"\/prefix\/nginx-kong.conf","cassandra_repl_factor":1,"nginx_http_directives":[{"value":"prometheus_metrics 5m","name":"lua_shared_dict"}],"kong_env":"\/prefix\/.kong_env","real_ip_header":"X-Real-IP","dns_hostsfile":"\/etc\/hosts","log_level":"debug","error_default_type":"text\/plain","ssl_cert":"\/prefix\/ssl\/kong-default.crt","cassandra_lb_policy":"RoundRobin","admin_ssl_cert_key_default":"\/prefix\/ssl\/admin-kong-default.key","cassandra_ssl_verify":false,"proxy_access_log":"\/proc\/1\/fd\/1","ssl_cipher_suite":"modern","real_ip_recursive":"off","proxy_error_log":"\/proc\/1\/fd\/2","client_ssl_cert_key_default":"\/prefix\/ssl\/kong-default.key","nginx_daemon":"off","anonymous_reports":true,"nginx_proxy_directives":{},"cassandra_timeout":5000,"pg_port":5432,"admin_listeners":[{"ssl":false,"ip":"0.0.0.0","proxy_protocol":false,"port":8001,"http2":false,"listener":"0.0.0.0:8001"}],"client_body_buffer_size":"8k","lua_socket_pool_size":30,"admin_ssl_cert_default":"\/prefix\/ssl\/admin-kong-default.crt","db_cache_ttl":0,"cassandra_keyspace":"kong","ssl_cert_default":"\/prefix\/ssl\/kong-default.crt","nginx_conf":"\/prefix\/nginx.conf","admin_listen":["0.0.0.0:8001"]},"version":"0.14.0","node_id":"64d5f381-57a1-4616-ab53-636618cc5df5","lua_version":"LuaJIT 2.1.0-beta3","prng_seeds":{"pid: 42":125129314158,"pid: 41":203298166148},"timers":{"pending":5,"running":0},"hostname":"bedbf0bf7230"}
Tieske commented 6 years ago

This might be related to the global patches that override the ngx socket functions. See https://github.com/Kong/kong/blob/master/kong/globalpatches.lua#L308-L309 for example. The UDP code checks for unix: but the TCP code does not. Though I would have expected a different stacktrace if that were the case.

rucciva commented 6 years ago

hi @Tieske, i've tried to modify the tcp_resolve_connect to mimic the udp_resolve_setpeername yet it showed the same error

screen shot 2018-07-17 at 16 32 04
rucciva commented 6 years ago

i think it is also related to https://github.com/openresty/lua-nginx-module/issues/860. So i changed the patch into this and it works

local function tcp_resolve_connect(sock, host, port, sock_opts)
            if sub(host, 1, 5) == 'unix:' then
                target_ip = host -- unix domain socket, so just maintain the named values
            else
                target_ip, target_port = toip(host, port)

                if not target_ip then
                    return nil, '[toip() name lookup failed]: ' .. tostring(target_port) -- err
                end
            end

            if type(port) ~= 'number' then
                if not sock_opts then
                    return old_tcp_connect(sock, target_ip)
                end
                return old_tcp_connect(sock, target_ip, sock_opts)
            end

            if not sock_opts then
                return old_tcp_connect(sock, target_ip, target_port)
            end

            return old_tcp_connect(sock, target_ip, target_port, sock_opts)
        end

Thanks for pointing that out @Tieske

Tieske commented 6 years ago

@rucciva Mind sending a PR?

rucciva commented 6 years ago

sure, will do it soon

Tieske commented 6 years ago

closing this in favour of #3633