Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Core dump when nginx logs entries including the remote-user or user-agent fields when Kong forwards a call from an internal subrequest and to an upstream service #5726

Closed
chienhsingwu opened this issue Mar 25, 2020 · 11 comments
Closed

Core dump when nginx logs entries including the remote-user or user-agent fields when Kong forwards a call from an internal subrequest and to an upstream service #5726

chienhsingwu opened this issue Mar 25, 2020 · 11 comments
Labels
core/proxy task/needs-investigation Requires investigation and reproduction before classifying it as a bug or not.

Comments

@chienhsingwu
Copy link

chienhsingwu commented Mar 25, 2020 •
edited
Loading

nchan_nginx_with_kong.conf.txt
nchan_nginx_without_kong.conf.txt
nchan_nginx_with_kong.conf.txt
nchan_nginx_without_kong.conf.txt

Summary

nginx setup:

  1. Kong version: 1.4.0 (openresty version: 1.15.8.2)
  2. nginx modules- nchan (https://nchan.io/)

Call path that caused the issue:

  • client->nchan->kong->upstream service->nginx subrequest log->core dump

Kong and nginx are configured to support that call path. The HTTP call is internally forwarded from nchan to Kong inside nginx. After Kong receives the upstream service response, the underlying nginx code base logs the call results with remote-user and user-agent fields included in the default log format before returning the response back to kong side. The attempt to log those two fields caused core dump.

Please note that the following call path would not produce any errors. This indicates that the error was caused by including kong and subrequest call in the call path.

  • client->nchan->upstream service

Please also note that this error does not happen each time.

Configuration details

kong_nginx.template

  1. the highlighted entry caused core dump
    .........
    server {
    server_name kong;

for i = 1, #proxy_listeners do
listen $(proxy_listeners[i].listener);
end
error_page 400 404 408 411 412 413 414 417 494 /kong_error_handler;
error_page 500 502 503 504 /kong_error_handler;

**access_log ${{PROXY_ACCESS_LOG}};**

.........

  1. the highlighted entry configured the internal call from nchan to kong
    .......
    location = /unsubKong {
    proxy_pass http://localhost:8000/internal/unsubscribe;
    proxy_ignore_client_abort on; #!!!important!!!!
    proxy_set_header X-Subscriber-Type $nchan_subscriber_type;
    proxy_set_header X-Channel-Id $nchan_channel_id;
    proxy_set_header X-Original-URI $request_uri;
    proxy_set_header Accept '/';
    }
    .........

  2. The kong route configuration exposes internal/unsubscribe location.
    curl localhost:8001/services/unSubService/routes
    {"next":null,"data":[{"id":"87a34fef-df06-476c-be1f-41693523b027","tags":null,"updated_at":1573767620,"destinations":null,"headers":null,"protocols":["http"
    ,"https"],"created_at":1573767620,"snis":null,"service":{"id":"b91fc1b6-b4cf-4a03-8f86-b1073eba37f8"},"name":null,"preserve_host":false,"regex_priority":0,"
    strip_path":true,"sources":null,"paths":["/internal/unsubscribe"],"https_redirect_status_code":426,"hosts":null,"methods":null}]}

  3. The kong service configuration links to the upstream service
    curl localhost:8001/services/unSubService
    {"host":"137.236.145.54","created_at":1573767602,"connect_timeout":60000,"id":"b91fc1b6-b4cf-4a03-8f86-b1073eba37f8","protocol":"http","name":"unSubService"
    ,"read_timeout":60000,"port":8002,"path":"/rfc/v1/events/streams/unsubscribe","updated_at":1573767602,"retries":5,"write_timeout":60000,"tags":null,"cl
    ient_certificate":null}

Steps To Reproduce

  1. Execute N curl commands at the same time (where N was about 4-5 in our tests)
    curl http://{kongserver}:{port}//rfc/v1/events/streams/1
    curl http://{kongserver}:{port}//rfc/v1/events/streams/2
    ...
    curl http://{kongserver}:{port}//rfc/v1/events/streams/N

  2. Ctrl-C each command in one at a time until nginx worker core-dump

  3. Repeat 1 and 2 if needed

Additional Details & Logs

  • Kong version ($ kong version) - 1.4.0
  • Kong debug-level startup logs ($ kong start --vv) - see attached
  • Kong error logs (<KONG_PREFIX>/logs/error.log) - see attached
  • Kong configuration (the output of a GET request to Kong's Admin port - see
    https://docs.konghq.com/latest/admin-api/#retrieve-node-information) - please refer to attached file: kong-conf-admin.txt

kong.conf.txt
kong-conf-admin.txt
debug-core.25213.txt
debug-core.27209.txt

nchan_nginx_with_kong.conf.txt
nchan_nginx_without_kong.conf.txt

  • Operating system - RH 7.7
@thibaultcha
Copy link
Member

Hi,

Could you upload the core dump somewhere for us to look at it? Or at least give us some more information about it, maybe getting the backtrace from it? Thanks.

@chienhsingwu
Copy link
Author

Please see the call stacks below.

Here are the core dumps:

@hishamhm
Copy link
Contributor

@thibaultcha At a first glance of the stacktraces, looks like the crash was not in OpenResty code... could this be caused by the other module the user has installed?

@chienhsingwu
Copy link
Author

Please note that the issue went away when Kong was removed from the call path.

@thibaultcha
Copy link
Member

thibaultcha commented Apr 2, 2020 •
edited
Loading

When you say "Kong was removed", do you mean that you disabled the location = /unsubKong which has the proxy_pass directive? It seems to me like the issue lies within nchan or even maybe NGINX itself (most likely nchan though). See similar stacktraces reported to nchan as well as this topic: https://forum.nginx.org/read.php?2,237362,237362#msg-237362.

This doesn't seem related to Kong so far.

@chienhsingwu
Copy link
Author

I meant we change the configuration so nchan makes calls to upstream service directly
client->nchan->upstream service->nginx access logging of upstream call with RemoteUser/UserAgent fields successfully

vs the below
client->nchan->kong->upstream service->nginx access logging of upstream call with RemoteUser/UserAgent fields in the request ->core dump

The above showed that HTTP request constructed from nginx for that client call can be logged successfully.

For the core dump flow, nchan made nginx subrequest call to kong, passing it the original HTTP Request nginx constructed. Somehow the HTTP Request object kong used to call upstream service did not have the proper data structure for those two headers (RemoteUser/UserAgent) and caused error when the low level nginx access log retrieve values; and therefore caused core dump.

Maybe somehow kong manipulated the received HTTP Request directly or indirectly and caused those headers to be corrupted? For example, maybe it (or a plugin) changed those headers based on something that did not work in the nginx subrequest calls?

@thibaultcha
Copy link
Member

Can you share your nchan configuration in both setups?

@thibaultcha thibaultcha added the task/needs-investigation Requires investigation and reproduction before classifying it as a bug or not. label Apr 2, 2020
@chienhsingwu
Copy link
Author

It is that Kong.conf.txt in the attachments.

@thibaultcha
Copy link
Member

No, I am talking about the nginx.conf file which contains your nchan configuration.

@chienhsingwu
Copy link
Author

I have added two more files in the ticket above.

nchan_nginx_with_kong.conf.txt
nchan_nginx_without_kong.conf.txt

@StarlightIbuki
Copy link
Contributor

Dear contributor,
We're closing this issue as there hasn't been any update to it for a long time. If the issue is still relevant in the latest version, please feel free to reopen it. We're more than happy to revisit it again. Your contribution is greatly appreciated!
Please have a look at our pledge to the community for more information.
Sincerely,
Kong Gateway Team

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
core/proxy task/needs-investigation Requires investigation and reproduction before classifying it as a bug or not.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@kikito @hishamhm @bungle @thibaultcha @chienhsingwu @StarlightIbuki