Logs for 502 errors are always indicating GET, even if POST was used #4751
Comments
|
Hi, Thank you for the report. This is a known issue, which comes from an Nginx limitation. This has already been reported in #4025, which also proposes an Nginx patch that will be shipped with an upcoming release of Kong (and OpenResty, eventually). Closing this in the meantime so we can keep the conversation focused on #4025. Best, |
thibaultcha
added a commit
that referenced
this issue
Sep 26, 2019
…errors This commit fixes the outstanding caveat of using logging plugins to log NGINX-produced errors. The caveat - described in e709c95 - causes some request properties (i.e. method and uri args) to be incorrectly logged. Since e709c95, Kong executes plugins on NGINX-produced errors. However, as described in the mentioned commit's message, a caveat with the approach (note: the sanest one) is that the request method is overridden by the `error_page` directive during the internal redirect (and the uri args do not survive the redirect either). This commit chooses to rely on the PDK to fix this limitation, and manually parses the request headers when necessary (and possible). Fix #4025 Fix #4751
hishamhm
pushed a commit
that referenced
this issue
Sep 27, 2019
…errors This commit fixes the outstanding caveat of using logging plugins to log NGINX-produced errors. The caveat - described in e709c95 - causes some request properties (i.e. method and uri args) to be incorrectly logged. Since e709c95, Kong executes plugins on NGINX-produced errors. However, as described in the mentioned commit's message, a caveat with the approach (note: the sanest one) is that the request method is overridden by the `error_page` directive during the internal redirect (and the uri args do not survive the redirect either). This commit chooses to rely on the PDK to fix this limitation, and manually parses the request headers when necessary (and possible). Fix #4025 Fix #4751
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Summary
When an upstream server returns no data, kong correctly replies with a 502 error "An invalid response was received from the upstream server". That first part is correct.
However, in the logs (for example with
tcp-logandudp-log), the request always shows up as aGETrequest, even if aPOSTwas sent.Note that it seems to happen ONLY when no byte is sent back by the upstream. The method is correct with a response of 6 bytes (haven't tested with less, but I suspect 1 byte is enough).
Impact
Mild, mostly. We did waste a few hours looking at our code with disbelief, but production still works.
Steps To Reproduce
Clone this repository and follow the steps in the README: https://github.com/aspyct/kong502
You'll need docker and docker-compose.
Additional Details & Logs
$ kong start --vv)<KONG_PREFIX>/logs/error.log)https://docs.konghq.com/latest/admin-api/#retrieve-node-information)
{ "plugins": { "enabled_in_cluster": [ "udp-log" ], "available_on_server": { "correlation-id": true, "pre-function": true, "cors": true, "ldap-auth": 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, "proxy-cache": true, "basic-auth": true, "key-auth": true, "http-log": true, "datadog": true, "tcp-log": true, "post-function": true, "prometheus": true, "acl": true, "kubernetes-sidecar-injector": true, "syslog": true, "file-log": true, "udp-log": true, "response-ratelimiting": true, "aws-lambda": true, "bot-detection": true, "rate-limiting": true, "request-termination": true } }, "tagline": "Welcome to kong", "configuration": { "error_default_type": "text\/plain", "admin_listen": [ "127.0.0.1:8001", "127.0.0.1:8444 ssl" ], "proxy_access_log": "logs\/access.log", "trusted_ips": {}, "prefix": "\/usr\/local\/kong", "loaded_plugins": { "correlation-id": true, "pre-function": true, "cors": true, "rate-limiting": 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, "proxy-cache": true, "basic-auth": true, "key-auth": true, "http-log": true, "datadog": true, "tcp-log": true, "post-function": true, "ldap-auth": true, "acl": true, "kubernetes-sidecar-injector": true, "ip-restriction": true, "file-log": true, "udp-log": true, "response-ratelimiting": true, "aws-lambda": true, "prometheus": true, "request-size-limiting": true, "request-termination": true }, "cassandra_username": "kong", "ssl_cert_key": "\/usr\/local\/kong\/ssl\/kong-default.key", "admin_ssl_cert_key": "\/usr\/local\/kong\/ssl\/admin-kong-default.key", "dns_resolver": {}, "pg_user": "kong", "mem_cache_size": "128m", "cassandra_data_centers": [ "dc1:2", "dc2:3" ], "nginx_admin_directives": {}, "nginx_http_directives": [ { "value": "prometheus_metrics 5m", "name": "lua_shared_dict" } ], "pg_host": "127.0.0.1", "nginx_acc_logs": "\/usr\/local\/kong\/logs\/access.log", "pg_semaphore_timeout": 60000, "proxy_listen": [ "0.0.0.0:8000", "0.0.0.0:8443 ssl" ], "declarative_config": "\/config\/kong-config.yml", "client_ssl_cert_default": "\/usr\/local\/kong\/ssl\/kong-default.crt", "cassandra_ssl": false, "dns_no_sync": false, "db_update_propagation": 0, "stream_listen": [ "off" ], "nginx_err_logs": "\/usr\/local\/kong\/logs\/error.log", "cassandra_port": 9042, "dns_order": [ "LAST", "SRV", "A", "CNAME" ], "dns_error_ttl": 1, "headers": [ "server_tokens", "latency_tokens" ], "cassandra_lb_policy": "RequestRoundRobin", "nginx_optimizations": true, "origins": {}, "database": "off", "pg_database": "kong", "nginx_worker_processes": "auto", "lua_package_cpath": "", "admin_acc_logs": "\/usr\/local\/kong\/logs\/admin_access.log", "admin_ssl_cert": "\/usr\/local\/kong\/ssl\/admin-kong-default.crt", "db_update_frequency": 5, "lua_package_path": ".\/?.lua;.\/?\/init.lua;", "nginx_pid": "\/usr\/local\/kong\/pids\/nginx.pid", "upstream_keepalive": 60, "lua_socket_pool_size": 30, "nginx_conf": "\/usr\/local\/kong\/nginx.conf", "dns_stale_ttl": 4, "router_consistency": "strict", "admin_access_log": "logs\/admin_access.log", "admin_ssl_cert_default": "\/usr\/local\/kong\/ssl\/admin-kong-default.crt", "nginx_kong_stream_conf": "\/usr\/local\/kong\/nginx-kong-stream.conf", "proxy_listeners": [ { "transparent": false, "ssl": false, "ip": "0.0.0.0", "proxy_protocol": false, "port": 8000, "http2": false, "listener": "0.0.0.0:8000" }, { "transparent": false, "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, "client_ssl": false, "db_cache_warmup_entities": [ "services", "plugins" ], "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 }, "stream_listeners": {}, "plugins": [ "bundled" ], "db_resurrect_ttl": 30, "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_consistency": "ONE", "client_max_body_size": "0", "admin_error_log": "logs\/error.log", "pg_ssl_verify": false, "dns_not_found_ttl": 30, "pg_ssl": false, "nginx_proxy_directives": {}, "kong_env": "\/usr\/local\/kong\/.kong_env", "cassandra_repl_strategy": "SimpleStrategy", "ssl_cipher_suite": "modern", "proxy_error_log": "logs\/error.log", "log_level": "notice", "pg_timeout": 60000, "nginx_kong_conf": "\/usr\/local\/kong\/nginx-kong.conf", "real_ip_header": "X-Real-IP", "dns_hostsfile": "\/etc\/hosts", "admin_listeners": [ { "transparent": false, "ssl": false, "ip": "127.0.0.1", "proxy_protocol": false, "port": 8001, "http2": false, "listener": "127.0.0.1:8001" }, { "transparent": false, "ssl": true, "ip": "127.0.0.1", "proxy_protocol": false, "port": 8444, "http2": false, "listener": "127.0.0.1:8444 ssl" } ], "pg_max_concurrent_queries": 0, "ssl_cert": "\/usr\/local\/kong\/ssl\/kong-default.crt", "cassandra_timeout": 60000, "admin_ssl_cert_key_default": "\/usr\/local\/kong\/ssl\/admin-kong-default.key", "cassandra_ssl_verify": false, "cassandra_schema_consensus_timeout": 60000, "cassandra_contact_points": [ "127.0.0.1" ], "real_ip_recursive": "off", "cassandra_repl_factor": 1, "client_ssl_cert_key_default": "\/usr\/local\/kong\/ssl\/kong-default.key", "nginx_daemon": "off", "anonymous_reports": true, "nginx_sproxy_directives": {}, "nginx_stream_directives": {}, "pg_port": 5432, "admin_ssl_enabled": true, "client_body_buffer_size": "8k", "ssl_preread_enabled": true, "ssl_cert_csr_default": "\/usr\/local\/kong\/ssl\/kong-default.csr", "lua_ssl_verify_depth": 1, "cassandra_keyspace": "kong", "ssl_cert_default": "\/usr\/local\/kong\/ssl\/kong-default.crt", "ssl_cert_key_default": "\/usr\/local\/kong\/ssl\/kong-default.key", "db_cache_ttl": 0 }, "version": "1.2.0", "node_id": "78152aff-94ce-4106-a6f4-0eb0bc2610f5", "lua_version": "LuaJIT 2.1.0-beta3", "prng_seeds": { "pid: 31": 113224819215, "pid: 23": 601951812101, "pid: 32": 991042399176 }, "timers": { "pending": 5, "running": 0 }, "hostname": "f356717e9dae" }The text was updated successfully, but these errors were encountered: