search

Kong / kong

🦍 The Cloud-Native API Gateway and AI Gateway.
https://konghq.com/install/#kong-community
Apache License 2.0
38.78k stars 4.77k forks source link

request-transformer plugin fails if multipart/form-data contains file #3024

Closed arvileino closed 6 years ago

arvileino commented 6 years ago

Summary

When request-transformer plugin enabled, multipart/form-data coded file sending through Kong fails. Everything seems to be fine until Request Transformer plugin is added. When sending file and Request Transformer plugin is activated, result is [{"code":400,"description":"An internal error occurred"}]

Steps To Reproduce

  1. Send multipart/form-data coded file through Kong. That is ok.
  2. Enable request-transformer plugin.
  3. Send multipart/form-data coded file through Kong. Sending fails with message [{"code":400,"description":"An internal error occurred"}]

Additional Details & Logs

bungle commented 6 years ago

Thank you for reporting. To understand what is going on, we need more information.

On our test suite, we do test multipart/form-data: https://github.com/Kong/kong/tree/master/spec/03-plugins/15-request-transformer

Can you show us `/logs/error.log (there could be more information)´. I quickly tried to to reproduce on my side, but it didn't fail on my test. Is there any specific plugin configuration that you are trying?

arvileino commented 6 years ago

Thanks for testing. The problem seems to be little different from what I described earlier.

If feedback data is sent through Kong and api_key is added with request-transformer plugin option config.add.body, upstream service returns [{"code":400,"description":"An internal error occurred"}] If upstream service is changed to my own echo service, it works fine. If upstream service, which failed earlier, is called with api_key parameter directly or without request-transformer plugin, it works fine. Coding is multipart/form-data.

So if api_key is added with Kong request-transformer plugin, upstream server fails. There is no information in Kong logs other than URL access. If upstream service, which failed earlier, is called directly, it works fine.

bungle commented 6 years ago

@arvileino, thank you for further information. I will try it out and report back.

arvileino commented 6 years ago

Found it. Plugin request-transformer seems to add extra line break characters. If image contains \r it is converted to \r\n Sample data below.

Original data:

--------------------------d3cfb9fe757b8050\r\nContent-Disposition: form-data; name="media"; filename="box.png"\r\nContent-Type: application/octet-stream\r\n\r\n\x89PNG\r\n\x1a\n\x00\x00\x00\rIHDR\x00\x00\x01,\x00\x00\x01,\x01\x03\x00\x00\x00C\xb3\x1c6\x00\x00\x00\x03sBIT\x08\x08\x08\xdb\xe1O\xe0\x00\x00\x00\tpHYs\x00\x00\x03v\x00\x00\x03v\x01}\xd5\x82\xcc\x00\x00\x00\x19tEXtSoftware\x00www.inkscape.org\x9b\xee<\x1a\x00\x00\x00\x06PLTE\x00\x00\x00\xff\xff\xff\xa5\xd9\x9f\xdd\x00\x00\x00FIDATh\xde\xed\xd81\x01\x000\x0c\xc3\xb0\xf0G[\x06\xd9\xbb\xaf\x05 \xdfB\xe0\xf4\xd2\x04\xc30\x0c\xc30\x0c\xc30\x0c\xc3\xb0\xb6\x93/\x0c\xc30\x0c\xc30\x0c\xc30\x0c\xc3\xcc\x04\x0c\xc30\x0c\xc30\x0c\xc30\x0c\xdb\xd9\x031R\x9b\x02\xe5,6\\\x00\x00\x00\x00IEND\xaeB\x82\r\n--------------------------d3cfb9fe757b8050--\r\n`

After transformer:

--------------------------4dab79a6267bc680\r\nContent-Disposition: form-data; name="media"; filename="box.png"\r\nContent-Type: application/octet-stream\r\n\r\n\x89PNG\r\n\x1a\r\n\x00\x00\x00\r\nIHDR\x00\x00\x01,\x00\x00\x01,\x01\x03\x00\x00\x00C\xb3\x1c6\x00\x00\x00\x03sBIT\x08\x08\x08\xdb\xe1O\xe0\x00\x00\x00\tpHYs\x00\x00\x03v\x00\x00\x03v\x01}\xd5\x82\xcc\x00\x00\x00\x19tEXtSoftware\x00www.inkscape.org\x9b\xee<\x1a\x00\x00\x00\x06PLTE\x00\x00\x00\xff\xff\xff\xa5\xd9\x9f\xdd\x00\x00\x00FIDATh\xde\xed\xd81\x01\x000\x0c\xc3\xb0\xf0G[\x06\xd9\xbb\xaf\x05 \xdfB\xe0\xf4\xd2\x04\xc30\x0c\xc30\x0c\xc30\x0c\xc3\xb0\xb6\x93/\x0c\xc30\x0c\xc30\x0c\xc30\x0c\xc3\xcc\x04\x0c\xc30\x0c\xc30\x0c\xc30\x0c\xdb\xd9\x031R\x9b\x02\xe5,6\\\x00\x00\x00\x00IEND\xaeB\x82\r\n--------------------------4dab79a6267bc680\r\n`

bungle commented 6 years ago

@arvileino, that's really valuable, I think the bug starts from here: https://github.com/Kong/lua-multipart/blob/master/src/multipart.lua#L41

and goes wrong later on... we need to fix this (we should possible start using something like lua-resty-upload or modified https://github.com/bungle/lua-resty-reqargs/blob/master/lib/resty/reqargs.lua (which uses lua-resty-upload). Parsing multipart in the way it is done now is a bit problematic as everything is read in memory etc.

I think this should be implemented in with streaming parsing.

nanaromance commented 6 years ago

Waiting fix this issue.

bungle commented 6 years ago

@arvileino / @nanaromance can you try this one (it is a quick fix to original library): https://github.com/Kong/lua-multipart/pull/14

bungle commented 6 years ago

or just do:

luarocks install multipart 0.5.2 --force (and reload Kong)

arvileino commented 6 years ago

Made quick test:

  1. Updated multipart to 0.5.2-2 and defined API
  2. Tried API -> works
  3. Added request-transformer
  4. Tried API -> did not work. Returned [{"code":400,"description":"An internal error occurred"}] from upstream server.
arvileino commented 6 years ago

Made other test:

curl -X "POST" "http://localhost/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"

Request-transformer 0.5.2-2 seems to multiply some fields and lose some:

b'--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="address_string"\r\n\r\nTEST ADDRESS\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="service_code"\r\n\r\n73da8c74-49e8-e611-8bc2-005056820025\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="address_string"\r\n\r\nTEST ADDRESS\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="service_code"\r\n\r\n73da8c74-49e8-e611-8bc2-005056820025\r\nContent-Disposition: form-data; name="description"\r\n\r\nTEST FEEDBACK\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="address_string"\r\n\r\nTEST ADDRESS\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="service_code"\r\n\r\n73da8c74-49e8-e611-8bc2-005056820025\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="address_string"\r\n\r\nTEST ADDRESS\r\n--------------------------d6fcd41540af83d8\r\nContent-Disposition: form-data; name="service_code"\r\n\r\n73da8c74-49e8-e611-8bc2-005056820025\r\nContent-Disposition: form-data; name="description"\r\n\r\nTEST FEEDBACK\r\nContent-Disposition: form-data; name="first_name"\r\n\r\nFIRST\r\n--------------------------d6fcd41540af83d8--'

bungle commented 6 years ago

@arvileino when you get An internal error occurred do you see any errors in

<kong-prefix>/logs/error.log

Do you also see things like:

a client request body is buffered to a temporary file

In your error.log? If yes, then try adjusting: client_body_buffer_size: https://getkong.org/docs/0.11.x/configuration/#client_body_buffer_size

(it is only 8k by default, so won't really work with file uploads).

I quickly checked out, and request transformer doesn't currently try to read file buffered requests, as can be seen here (file io is a blocking operation in OpenResty, and it blocks the worker process so that it cannot serve anything else meanwhile): https://github.com/Kong/kong/blob/master/kong/plugins/request-transformer/access.lua#L345-L346

It only tries to read memory buffered data.

bungle commented 6 years ago

I couldn't reproduce your multiplying/removing problem:

Starting Kong:

$ ./bin/kong start
2017/11/30 00:40:10 [verbose] Kong: 0.11.1
...
2017/11/30 00:40:10 [info] Kong started

Creating API:

$ http post :8001/apis name=demo uris=/ upstream_url=http://httpbin.org/post

Try API:

$ touch empty.txt
$ http post :8000 file@empty.txt
HTTP/1.1 200 OK
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: *
Connection: keep-alive
Content-Length: 395
Content-Type: application/json
Date: Wed, 29 Nov 2017 22:42:48 GMT
Server: meinheld/0.6.1
Via: kong/0.11.1
X-Kong-Proxy-Latency: 177
X-Kong-Upstream-Latency: 287
X-Powered-By: Flask
X-Processed-Time: 0.000699996948242
{
    "args": {},
    "data": "",
    "files": {},
    "form": {},
    "headers": {
        "Accept": "*/*",
        "Accept-Encoding": "gzip, deflate",
        "Connection": "close",
        "Content-Length": "0",
        "Host": "httpbin.org",
        "User-Agent": "HTTPie/0.9.9",
        "X-Forwarded-Host": "localhost"
    },
    "json": null,
    "origin": "127.0.0.1",
    "url": "http://localhost/post"
}

Add request-transformer plugin:

$ http post :8001/apis/demo/plugins name=request-transformer config.add.body=api_key:key,jurisdiction_id:test

Make test again:

$ touch empty.txt
$ http post :8000 file@empty.txt -f -v
POST / HTTP/1.1
Accept: */*
Accept-Encoding: gzip, deflate
Connection: keep-alive
Content-Length: 171
Content-Type: multipart/form-data; boundary=5ba425bb63304f4b80675e50224d4fd5
Host: localhost:8000
User-Agent: HTTPie/0.9.9

--5ba425bb63304f4b80675e50224d4fd5
Content-Disposition: form-data; name="file"; filename="empty.txt"
Content-Type: text/plain

--5ba425bb63304f4b80675e50224d4fd5--
HTTP/1.1 200 OK
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: *
Connection: keep-alive
Content-Length: 558
Content-Type: application/json
Date: Wed, 29 Nov 2017 22:47:53 GMT
Server: meinheld/0.6.1
Via: kong/0.11.1
X-Kong-Proxy-Latency: 0
X-Kong-Upstream-Latency: 310
X-Powered-By: Flask
X-Processed-Time: 0.000979900360107
{
    "args": {},
    "data": "",
    "files": {
        "file": ""
    },
    "form": {
        "api_key": "key",
        "jurisdiction_id": "test"
    },
    "headers": {
        "Accept": "*/*",
        "Accept-Encoding": "gzip, deflate",
        "Connection": "close",
        "Content-Length": "360",
        "Content-Type": "multipart/form-data; boundary=5ba425bb63304f4b80675e50224d4fd5",
        "Host": "httpbin.org",
        "User-Agent": "HTTPie/0.9.9",
        "X-Forwarded-Host": "localhost"
    },
    "json": null,
    "origin": "127.0.0.1",
    "url": "http://localhost/post"
}

Change plugin config (as described in #2981):

$ http patch :8001/apis/demo/plugins/<UUID> config.add.body=jurisdiction_id:test,api_key:key

Make request again:

$ http post :8000 file@empty.txt -f -v
POST / HTTP/1.1
Accept: */*
Accept-Encoding: gzip, deflate
Connection: keep-alive
Content-Length: 171
Content-Type: multipart/form-data; boundary=ad696279ef644a259988a8584c9b0e8e
Host: localhost:8000
User-Agent: HTTPie/0.9.9

--ad696279ef644a259988a8584c9b0e8e
Content-Disposition: form-data; name="file"; filename="empty.txt"
Content-Type: text/plain

--ad696279ef644a259988a8584c9b0e8e--
HTTP/1.1 200 OK
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: *
Connection: keep-alive
Content-Length: 558
Content-Type: application/json
Date: Wed, 29 Nov 2017 22:53:20 GMT
Server: meinheld/0.6.1
Via: kong/0.11.1
X-Kong-Proxy-Latency: 1249
X-Kong-Upstream-Latency: 284
X-Powered-By: Flask
X-Processed-Time: 0.00156903266907
{
    "args": {},
    "data": "",
    "files": {
        "file": ""
    },
    "form": {
        "api_key": "key",
        "jurisdiction_id": "test"
    },
    "headers": {
        "Accept": "*/*",
        "Accept-Encoding": "gzip, deflate",
        "Connection": "close",
        "Content-Length": "360",
        "Content-Type": "multipart/form-data; boundary=ad696279ef644a259988a8584c9b0e8e",
        "Host": "httpbin.org",
        "User-Agent": "HTTPie/0.9.9",
        "X-Forwarded-Host": "localhost"
    },
    "json": null,
    "origin": "127.0.0.1",
    "url": "http://localhost/post"
}

Now let's try your curlcommand:

$ curl -X "POST" "http://localhost:8000" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"
{
  "args": {}, 
  "data": "", 
  "files": {}, 
  "form": {
    "address_string": "TEST ADDRESS", 
    "api_key": "key", 
    "description": "TEST FEEDBACK", 
    "first_name": "FIRST", 
    "jurisdiction_id": "test", 
    "last_name": "LAST", 
    "service_code": "73da8c74-49e8-e611-8bc2-005056820025"
  }, 
  "headers": {
    "Accept": "*/*", 
    "Connection": "close", 
    "Content-Length": "822", 
    "Content-Type": "multipart/form-data; boundary=------------------------5bc700bb7e9cb516", 
    "Host": "httpbin.org", 
    "User-Agent": "curl/7.54.0", 
    "X-Forwarded-Host": "localhost"
  }, 
  "json": null, 
  "origin": "127.0.0.1", 
  "url": "http://localhost/post"
}
arvileino commented 6 years ago

"An internal error occurred" is from upstream server and I can not see it's logs. client_body_buffer_size is set to 1024m and there is no new messages in error.log

access.log has row [30/Nov/2017:03:50:26 +0000] "POST /feedback/v1/requests.json HTTP/1.1" 400 82 "-" "curl/7.47.0"

I will check your test not later than next week.

arvileino commented 6 years ago

Create API:

curl -i -X POST --url http://localhost:8001/apis/ --data 'name=echo' --data 'uris=/echo/' --data 'upstream_url=http://localhost:8020/'

Echo service:

from flask import *
import requests
import json

app = Flask(__name__)

@app.errorhandler(404)
def page_not_found(e):
        return str(request.headers) + request.get_data(as_text=True)

if __name__ == "__main__":
    app.run(host='0.0.0.0',port=8020)

Run echo:

python echo.py &

Send data:

curl -X "POST" "http://localhost:8010/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"

Result OK:

127.0.0.1 - - [04/Dec/2017 17:18:40] "POST / HTTP/1.1" 200 -
X-Forwarded-Port: 8010
User-Agent: curl/7.47.0
Content-Type: multipart/form-data; boundary=------------------------64655954c1016901
Connection: keep-alive
Host: localhost:8020
Accept: */*
Content-Length: 617
X-Real-Ip: 127.0.0.1
X-Forwarded-For: 127.0.0.1
X-Forwarded-Host: localhost
X-Forwarded-Proto: http

--------------------------64655954c1016901
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------64655954c1016901
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
--------------------------64655954c1016901
Content-Disposition: form-data; name="description"

TEST FEEDBACK
--------------------------64655954c1016901
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------64655954c1016901
Content-Disposition: form-data; name="last_name"

LAST
--------------------------64655954c1016901--

Add Request transformer:

curl -X POST http://localhost:8001/apis/echo/plugins --data 'name=request-transformer' --data 'config.add.body=api_key:APIKEY'

Send data:

curl -X "POST" "http://localhost:8010/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"

Result problem:

127.0.0.1 - - [04/Dec/2017 17:20:13] "POST / HTTP/1.1" 200 -
X-Forwarded-Port: 8010
User-Agent: curl/7.47.0
Content-Type: multipart/form-data; boundary=------------------------f766fd3a411e3493
Connection: keep-alive
Host: localhost:8020
Accept: */*
Content-Length: 1454
X-Real-Ip: 127.0.0.1
X-Forwarded-For: 127.0.0.1
X-Forwarded-Host: localhost
X-Forwarded-Proto: http

--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
Content-Disposition: form-data; name="description"

TEST FEEDBACK
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
Content-Disposition: form-data; name="description"

TEST FEEDBACK
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="last_name"

LAST
--------------------------f766fd3a411e3493
Content-Disposition: form-data; name="api_key"

APIKEY
bungle commented 6 years ago

@arvileino thanks a lot for this. I will continue on this. Really good example, thank you!

bungle commented 6 years ago

@arvileino

I tried with your exact commands:

Kong Version (almost same as yours):

$ ./bin/kong version
0.11.2

Multipart Version:

$ luarocks show multipart
multipart 0.5.2-2 - A simple HTTP multipart encoder/decoder for Lua

A simple HTTP multipart encoder/decoder for Lua, that can be used to work with
multipart/form-data payloads.

License:    MIT
Homepage:   https://github.com/Kong/lua-multipart
Installed in:   /Users/bungle/.luaver/luarocks/2.4.2_5.1

Modules:
    multipart (/Users/bungle/.luaver/luarocks/2.4.2_5.1/share/lua/5.1/multipart.lua)

Depends on:
    lua >= 5.1 (using 5.1-1)
    penlight >= 1.4.1 (using 1.5.4-1)

Indirectly pulling:
    luafilesystem (using 1.7.0-2)

Resetting Database:

$ yes | ./bin/kong migrations reset
> Are you sure? This operation is irreversible. [Y/n]
Schema successfully reset

Running Migrations:

$ ./bin/kong migrations up
migrating core for database kong
core migrated up to: 2015-01-12-175310_skeleton
core migrated up to: 2015-01-12-175310_init_schema
core migrated up to: 2015-11-23-817313_nodes
core migrated up to: 2016-02-29-142793_ttls
core migrated up to: 2016-09-05-212515_retries
core migrated up to: 2016-09-16-141423_upstreams
core migrated up to: 2016-12-14-172100_move_ssl_certs_to_core
core migrated up to: 2016-11-11-151900_new_apis_router_1
core migrated up to: 2016-11-11-151900_new_apis_router_2
core migrated up to: 2016-11-11-151900_new_apis_router_3
core migrated up to: 2016-01-25-103600_unique_custom_id
core migrated up to: 2017-01-24-132600_upstream_timeouts
core migrated up to: 2017-01-24-132600_upstream_timeouts_2
core migrated up to: 2017-03-27-132300_anonymous
core migrated up to: 2017-04-18-153000_unique_plugins_id
core migrated up to: 2017-04-18-153000_unique_plugins_id_2
core migrated up to: 2017-05-19-180200_cluster_events
core migrated up to: 2017-05-19-173100_remove_nodes_table
core migrated up to: 2017-06-16-283123_ttl_indexes
migrating response-transformer for database kong
response-transformer migrated up to: 2016-05-04-160000_resp_trans_schema_changes
migrating ip-restriction for database kong
ip-restriction migrated up to: 2016-05-24-remove-cache
migrating statsd for database kong
statsd migrated up to: 2017-06-09-160000_statsd_schema_changes
migrating jwt for database kong
jwt migrated up to: 2015-06-09-jwt-auth
jwt migrated up to: 2016-03-07-jwt-alg
jwt migrated up to: 2017-05-22-jwt_secret_not_unique
migrating cors for database kong
cors migrated up to: 2017-03-14_multiple_orgins
migrating basic-auth for database kong
basic-auth migrated up to: 2015-08-03-132400_init_basicauth
basic-auth migrated up to: 2017-01-25-180400_unique_username
migrating key-auth for database kong
key-auth migrated up to: 2015-07-31-172400_init_keyauth
migrating ldap-auth for database kong
ldap-auth migrated up to: 2017-10-23-150900_header_type_default
migrating hmac-auth for database kong
hmac-auth migrated up to: 2015-09-16-132400_init_hmacauth
hmac-auth migrated up to: 2017-06-21-132400_init_hmacauth
migrating datadog for database kong
datadog migrated up to: 2017-06-09-160000_datadog_schema_changes
migrating acl for database kong
acl migrated up to: 2015-08-25-841841_init_acl
migrating galileo for database kong
galileo migrated up to: 2016-04-15_galileo-import-mashape-analytics
migrating response-ratelimiting for database kong
response-ratelimiting migrated up to: 2015-08-03-132400_init_response_ratelimiting
response-ratelimiting migrated up to: 2016-08-04-321512_response-rate-limiting_policies
migrating request-transformer for database kong
request-transformer migrated up to: 2016-05-04-160000_req_trans_schema_changes
migrating rate-limiting for database kong
rate-limiting migrated up to: 2015-08-03-132400_init_ratelimiting
rate-limiting migrated up to: 2016-07-25-471385_ratelimiting_policies
migrating oauth2 for database kong
oauth2 migrated up to: 2015-08-03-132400_init_oauth2
oauth2 migrated up to: 2016-07-15-oauth2_code_credential_id
oauth2 migrated up to: 2016-12-22-283949_serialize_redirect_uri
oauth2 migrated up to: 2016-09-19-oauth2_api_id
oauth2 migrated up to: 2016-12-15-set_global_credentials
oauth2 migrated up to: 2017-04-24-oauth2_client_secret_not_unique
46 migrations ran

Starting Kong:

$ ./bin/kong start --vv
2017/12/08 17:24:33 [verbose] Kong: 0.11.2
2017/12/08 17:24:33 [debug] ngx_lua: 10008
2017/12/08 17:24:33 [debug] nginx: 1011002
2017/12/08 17:24:33 [debug] Lua: LuaJIT 2.1.0-beta2
2017/12/08 17:24:33 [verbose] reading config file at /etc/kong/kong.conf
2017/12/08 17:24:33 [debug] KONG_ANONYMOUS_REPORTS ENV found with "off"
2017/12/08 17:24:33 [debug] KONG_LOG_LEVEL ENV found with "debug"
2017/12/08 17:24:33 [debug] admin_access_log = "logs/admin_access.log"
2017/12/08 17:24:33 [debug] admin_error_log = "logs/error.log"
2017/12/08 17:24:33 [debug] admin_http2 = false
2017/12/08 17:24:33 [debug] admin_listen = "0.0.0.0:8001"
2017/12/08 17:24:33 [debug] admin_listen_ssl = "0.0.0.0:8444"
2017/12/08 17:24:33 [debug] admin_ssl = true
2017/12/08 17:24:33 [debug] anonymous_reports = false
2017/12/08 17:24:33 [debug] cassandra_consistency = "ONE"
2017/12/08 17:24:33 [debug] cassandra_contact_points = {"127.0.0.1"}
2017/12/08 17:24:33 [debug] cassandra_data_centers = {"dc1:2","dc2:3"}
2017/12/08 17:24:33 [debug] cassandra_keyspace = "kong"
2017/12/08 17:24:33 [debug] cassandra_lb_policy = "RoundRobin"
2017/12/08 17:24:33 [debug] cassandra_port = 9042
2017/12/08 17:24:33 [debug] cassandra_repl_factor = 1
2017/12/08 17:24:33 [debug] cassandra_repl_strategy = "SimpleStrategy"
2017/12/08 17:24:33 [debug] cassandra_schema_consensus_timeout = 10000
2017/12/08 17:24:33 [debug] cassandra_ssl = false
2017/12/08 17:24:33 [debug] cassandra_ssl_verify = false
2017/12/08 17:24:33 [debug] cassandra_timeout = 5000
2017/12/08 17:24:33 [debug] cassandra_username = "kong"
2017/12/08 17:24:33 [debug] client_body_buffer_size = "8k"
2017/12/08 17:24:33 [debug] client_max_body_size = "0"
2017/12/08 17:24:33 [debug] client_ssl = false
2017/12/08 17:24:33 [debug] custom_plugins = {}
2017/12/08 17:24:33 [debug] database = "postgres"
2017/12/08 17:24:33 [debug] db_cache_ttl = 3600
2017/12/08 17:24:33 [debug] db_update_frequency = 5
2017/12/08 17:24:33 [debug] db_update_propagation = 0
2017/12/08 17:24:33 [debug] dns_error_ttl = 1
2017/12/08 17:24:33 [debug] dns_hostsfile = "/etc/hosts"
2017/12/08 17:24:33 [debug] dns_no_sync = false
2017/12/08 17:24:33 [debug] dns_not_found_ttl = 30
2017/12/08 17:24:33 [debug] dns_order = {"LAST","SRV","A","CNAME"}
2017/12/08 17:24:33 [debug] dns_resolver = {}
2017/12/08 17:24:33 [debug] dns_stale_ttl = 4
2017/12/08 17:24:33 [debug] error_default_type = "text/plain"
2017/12/08 17:24:33 [debug] http2 = false
2017/12/08 17:24:33 [debug] latency_tokens = true
2017/12/08 17:24:33 [debug] log_level = "debug"
2017/12/08 17:24:33 [debug] lua_package_cpath = ""
2017/12/08 17:24:33 [debug] lua_package_path = "./?.lua;./?/init.lua;"
2017/12/08 17:24:33 [debug] lua_socket_pool_size = 30
2017/12/08 17:24:33 [debug] lua_ssl_verify_depth = 1
2017/12/08 17:24:33 [debug] mem_cache_size = "128m"
2017/12/08 17:24:33 [debug] nginx_daemon = "on"
2017/12/08 17:24:33 [debug] nginx_optimizations = true
2017/12/08 17:24:33 [debug] nginx_user = "nobody nobody"
2017/12/08 17:24:33 [debug] nginx_worker_processes = "auto"
2017/12/08 17:24:33 [debug] pg_database = "kong"
2017/12/08 17:24:33 [debug] pg_host = "127.0.0.1"
2017/12/08 17:24:33 [debug] pg_port = 5432
2017/12/08 17:24:33 [debug] pg_ssl = false
2017/12/08 17:24:33 [debug] pg_ssl_verify = false
2017/12/08 17:24:33 [debug] pg_user = "kong"
2017/12/08 17:24:33 [debug] prefix = "/usr/local/kong/"
2017/12/08 17:24:33 [debug] proxy_access_log = "logs/access.log"
2017/12/08 17:24:33 [debug] proxy_error_log = "logs/error.log"
2017/12/08 17:24:33 [debug] proxy_listen = "0.0.0.0:8000"
2017/12/08 17:24:33 [debug] proxy_listen_ssl = "0.0.0.0:8443"
2017/12/08 17:24:33 [debug] real_ip_header = "X-Real-IP"
2017/12/08 17:24:33 [debug] real_ip_recursive = "off"
2017/12/08 17:24:33 [debug] server_tokens = true
2017/12/08 17:24:33 [debug] ssl = true
2017/12/08 17:24:33 [debug] ssl_cipher_suite = "modern"
2017/12/08 17:24:33 [debug] 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"
2017/12/08 17:24:33 [debug] trusted_ips = {}
2017/12/08 17:24:33 [debug] upstream_keepalive = 60
2017/12/08 17:24:33 [verbose] prefix in use: /usr/local/kong
2017/12/08 17:24:33 [verbose] preparing nginx prefix directory at /usr/local/kong
2017/12/08 17:24:33 [verbose] SSL enabled, no custom certificate set: using default certificate
2017/12/08 17:24:33 [verbose] default SSL certificate found at /usr/local/kong/ssl/kong-default.crt
2017/12/08 17:24:33 [verbose] Admin SSL enabled, no custom certificate set: using default certificate
2017/12/08 17:24:33 [verbose] admin SSL certificate found at /usr/local/kong/ssl/admin-kong-default.crt
2017/12/08 17:24:33 [debug] searching for OpenResty 'nginx' executable
2017/12/08 17:24:33 [debug] /usr/local/openresty/nginx/sbin/nginx -v: 'nginx version: openresty/1.11.2.4'
2017/12/08 17:24:33 [debug] found OpenResty 'nginx' executable at /usr/local/openresty/nginx/sbin/nginx
2017/12/08 17:24:33 [debug] starting nginx: /usr/local/openresty/nginx/sbin/nginx -p /usr/local/kong -c nginx.conf
2017/12/08 17:24:33 [debug] nginx started
2017/12/08 17:24:33 [info] Kong started

Starting Flask Server:

$ python hello.py
 * Running on http://0.0.0.0:8020/ (Press CTRL+C to quit)

CURL Flask Server:

$ curl -X "POST" "http://localhost:8020/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"
127.0.0.1 - - [08/Dec/2017 17:19:44] "POST /echo HTTP/1.1" 200 -
Host: localhost:8020
User-Agent: curl/7.54.0
Accept: */*
Content-Length: 617
Expect: 100-continue
Content-Type: multipart/form-data; boundary=------------------------a45cc9f31d1dd00d

--------------------------a45cc9f31d1dd00d
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------a45cc9f31d1dd00d
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
--------------------------a45cc9f31d1dd00d
Content-Disposition: form-data; name="description"

TEST FEEDBACK
--------------------------a45cc9f31d1dd00d
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------a45cc9f31d1dd00d
Content-Disposition: form-data; name="last_name"

LAST
--------------------------a45cc9f31d1dd00d--

Create Kong API:

$ curl -i -X POST --url http://localhost:8001/apis/ --data 'name=echo' --data 'uris=/echo/' --data 'upstream_url=http://localhost:8020/'
HTTP/1.1 201 Created
Date: Fri, 08 Dec 2017 15:27:00 GMT
Content-Type: application/json; charset=utf-8
Transfer-Encoding: chunked
Connection: keep-alive
Access-Control-Allow-Origin: *
Server: kong/0.11.2

{"created_at":1512746820911,"strip_uri":true,"id":"cfb7fb12-59ef-41e9-a90f-22ee5c5affc6","name":"echo","http_if_terminated":false,"preserve_host":false,"upstream_url":"http:\/\/localhost:8020\/","uris":["\/echo"],"upstream_connect_timeout":60000,"upstream_send_timeout":60000,"upstream_read_timeout":60000,"retries":5,"https_only":false}

Calling Flask Through Kong:

$ curl -X "POST" "http://localhost:8000/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"
127.0.0.1 - - [08/Dec/2017 17:28:24] "POST / HTTP/1.1" 200 -
Host: localhost:8020
Connection: keep-alive
X-Forwarded-For: 127.0.0.1
X-Forwarded-Proto: http
X-Forwarded-Host: localhost
X-Forwarded-Port: 8000
X-Real-Ip: 127.0.0.1
Content-Length: 617
User-Agent: curl/7.54.0
Accept: */*
Content-Type: multipart/form-data; boundary=------------------------a7959ca4311e9cfa

--------------------------a7959ca4311e9cfa
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------a7959ca4311e9cfa
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
--------------------------a7959ca4311e9cfa
Content-Disposition: form-data; name="description"

TEST FEEDBACK
--------------------------a7959ca4311e9cfa
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------a7959ca4311e9cfa
Content-Disposition: form-data; name="last_name"

LAST
--------------------------a7959ca4311e9cfa--

Enabling Request Transformer:

$ curl -X POST http://localhost:8001/apis/echo/plugins --data 'name=request-transformer' --data 'config.add.body=api_key:APIKEY'
{"created_at":1512747023000,"config":{"remove":{"querystring":{},"headers":{},"body":{}},"add":{"querystring":{},"headers":{},"body":["api_key:APIKEY"]},"append":{"querystring":{},"headers":{},"body":{}},"replace":{"querystring":{},"headers":{},"body":{}},"rename":{"querystring":{},"headers":{},"body":{}}},"id":"d6a7e37a-47cf-4986-b352-ba4d043337ba","name":"request-transformer","api_id":"cfb7fb12-59ef-41e9-a90f-22ee5c5affc6","enabled":true}

Calling Flask Through Kong with Request Tranformer Added:

$ curl -X "POST" "http://localhost:8000/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"
127.0.0.1 - - [08/Dec/2017 17:31:33] "POST / HTTP/1.1" 200 -
Host: localhost:8020
Connection: keep-alive
X-Forwarded-For: 127.0.0.1
X-Forwarded-Proto: http
X-Forwarded-Host: localhost
X-Forwarded-Port: 8000
X-Real-Ip: 127.0.0.1
Content-Length: 717
User-Agent: curl/7.54.0
Accept: */*
Content-Type: multipart/form-data; boundary=------------------------5e39281cf61b3b8d

--------------------------5e39281cf61b3b8d
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------5e39281cf61b3b8d
Content-Disposition: form-data; name="service_code"

73da8c74-49e8-e611-8bc2-005056820025
--------------------------5e39281cf61b3b8d
Content-Disposition: form-data; name="description"

TEST FEEDBACK
--------------------------5e39281cf61b3b8d
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------5e39281cf61b3b8d
Content-Disposition: form-data; name="last_name"

LAST
--------------------------5e39281cf61b3b8d
Content-Disposition: form-data; name="api_key"

APIKEY
--------------------------5e39281cf61b3b8d--

No duplicates. What could be different? Your example used different ports than Kong defaults (e.g. I cannot get it work with using yours 1:1 but I tried to reproduce this as close as possible).

arvileino commented 6 years ago

@bungle Upgraded to Kong 0.11.2. Getting expected result after commands:

yes | kong migrations reset
kong migrations up
sudo kong start
curl -i -X POST --url http://localhost:8001/apis/ --data 'name=echo' --data 'uris=/echo/' --data 'upstream_url=http://localhost:8020/'
curl -X POST http://localhost:8001/apis/echo/plugins  --data 'name=request-transformer'  --data 'config.add.body=api_key:APIKEY'
curl -X "POST" "http://localhost:8010/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8cion=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"
127.0.0.1 - - [08/Dec/2017 16:31:44] "POST / HTTP/1.1" 200 -
User-Agent: curl/7.47.0
Accept: */*
Host: localhost:8020
X-Forwarded-Host: localhost
X-Forwarded-Port: 8010
Content-Length: 591
X-Forwarded-For: 127.0.0.1
Connection: keep-alive
Content-Type: multipart/form-data; boundary=------------------------64278e5a39a6ae61
X-Real-Ip: 127.0.0.1
X-Forwarded-Proto: http

--------------------------64278e5a39a6ae61
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------64278e5a39a6ae61
Content-Disposition: form-data; name="service_code"

73da8cion=TEST FEEDBACK
--------------------------64278e5a39a6ae61
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------64278e5a39a6ae61
Content-Disposition: form-data; name="last_name"

LAST
--------------------------64278e5a39a6ae61
Content-Disposition: form-data; name="api_key"

APIKEY
--------------------------64278e5a39a6ae61--

After sending JPG multiple times, following API-request gets wrong result. That will be fixed on next Kong restart. There might be some other problems too, because our feedback system returns error starting from first request, if request-transformer is used.

curl -X "POST" "http://localhost:8010/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"  -F "media=@palautekuva.jpg"
curl -X "POST" "http://localhost:8010/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"  -F "media=@palautekuva.jpg"
curl -X "POST" "http://localhost:8010/echo" -F "address_string=TEST ADDRESS" -F "service_code=73da8c74-49e8-e611-8bc2-005056820025" -F "description=TEST FEEDBACK" -F "first_name=FIRST" -F "last_name=LAST"
127.0.0.1 - - [08/Dec/2017 16:33:09] "POST / HTTP/1.1" 200 -
User-Agent: curl/7.47.0
Accept: */*
Host: localhost:8020
X-Forwarded-Host: localhost
X-Forwarded-Port: 8010
Content-Length: 786
X-Forwarded-For: 127.0.0.1
Connection: keep-alive
Content-Type: multipart/form-data; boundary=------------------------a3b2e950765326b2
X-Real-Ip: 127.0.0.1
X-Forwarded-Proto: http

--------------------------a3b2e950765326b2
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------a3b2e950765326b2
Content-Disposition: form-data; name="service_code"

73da8cion=TEST FEEDBACK
--------------------------a3b2e950765326b2
Content-Disposition: form-data; name="address_string"

TEST ADDRESS
--------------------------a3b2e950765326b2
Content-Disposition: form-data; name="service_code"

73da8cion=TEST FEEDBACK
Content-Disposition: form-data; name="first_name"

FIRST
--------------------------a3b2e950765326b2
Content-Disposition: form-data; name="last_name"

LAST
--------------------------a3b2e950765326b2
Content-Disposition: form-data; name="api_key"

APIKEY
--------------------------a3b2e950765326b2--
arvileino commented 6 years ago

@bungle New information about this problem? Currently we have to partly bypass Kong.

bungle commented 6 years ago

@arvileino sorry for the delays on this, we are afraid of the situation, I will try to invest more time on fixing this. Thanks againg for great reports and testing!

bungle commented 6 years ago

@arvileino I am working on it.

bungle commented 6 years ago

@arvileino there is now a PR from me to lua-multipart: https://github.com/Kong/lua-multipart/pull/15

I am waiting for a review, and then I can publish multipart 0.5.3 that should fix the issue that you were having. In the mean time, can you try it? Just copy multipart.lua from here: https://github.com/Kong/lua-multipart/blob/fix/several-issues/src/multipart.lua

to your luarocks, just forcibly overwrite that, and then restart Kong and try again. I tested and it now works on your example and the Flask script that you did sent to me.

bungle commented 6 years ago

or just do:

luarocks install multipart 0.5.3 --force # (and reload Kong)
arvileino commented 6 years ago

@bungle Installed multipart 0.5.3 There seems to be problem with image data and \r\n Second \r\n will be removed from Content-Type: image/jpeg\r\n\r\n

bungle commented 6 years ago

@arvileino you mean if image body has \r\n\r\n?

bungle commented 6 years ago

@arvileino can you send me the image that you are using? I mean there is even test for this now: https://github.com/Kong/lua-multipart/blob/master/spec/multipart_spec.lua#L157-L179

bungle commented 6 years ago

@arvileino ok, I got it, and found the issue. Let's hope this is the last one, or I will rewrite the whole library :-).

bungle commented 6 years ago

@arvileino can you please try this one: https://raw.githubusercontent.com/Kong/lua-multipart/fix/new-line-handling-at-start-of-part-content/src/multipart.lua

If it is still not working I will rewrite the parser from scratch:

  1. split to parts by boundary
  2. split part in two by \r\n 2.1. for first part: parse headers 2.2. second part is the content
bungle commented 6 years ago

or just do:

luarocks install multipart 0.5.4 --force # (and reload Kong)
arvileino commented 6 years ago

Thanks @bungle! multipart 0.5.4-1 installed. I will check.

bungle commented 6 years ago

@arvileino great! I keep my fingers crossed.

arvileino commented 6 years ago

@bungle Checked with feedback system and two different photos. API gateway with plugin seems to work in these cases. However could not send two photos within one request. Will check later this week.

bungle commented 6 years ago

@arvileino thanks! Finally we are getting forward with this, :-).

bungle commented 6 years ago

@arvileino anything new from your side? still having problems? if you give a green light, I can work to get the PR merged. that two photos thing worries me, though.

arvileino commented 6 years ago

Sorry about delay. No problems I am aware of. Please do the merge. Thank you very much!