[THREESCALE-9542] Part 1: buffering policy

[tkan145]

What

As part of https://issues.redhat.com/browse/THREESCALE-9542, this PR adds a new buffering policy which enable users to disable request buffering for use cases which call for it (namely, large payloads using HTTP 1.1 chunked encoding).
(Note: currently only support use case with no proxy between APIcast and upstream).

By default that the request buffer is true (which is the same as before). Users can now turn the request buffering off per service.

When request buffering is disabled, nginx will forward request body to upstream ASAP.

Verification steps

• Expose port 8080 from dev image docker-compose-devel.yml

version: '2.2'                                                               
services:                                                                    
   ....   
    expose:                                                                  
      - "8080" 
    ports:                                                                   
      - "8080:8080" 
  redis:                                                                     
    image: redis                                                             

• Generate a APICast configuration file

▲ ~ cat <<EOF >apicast-config-buffering.json
{
  "services": [
    {
      "id": "1",
      "backend_version": "1",
      "proxy": {
        "hosts": ["one"],
        "api_backend": "https://postman-echo.com/post",
        "backend": {
          "endpoint": "http://127.0.0.1:8081",
          "host": "backend"
        },
        "policy_chain": [
          {
            "name": "apicast.policy.request_unbuffered",
          },
          {
            "name": "apicast.policy.apicast"
          }
        ],
        "proxy_rules": [
          {
            "http_method": "POST",
            "pattern": "/",
            "metric_system_name": "hits",
            "delta": 1,
            "parameters": [],
            "querystring_parameters": {}
          }
        ]
      }
    }
  ]
}
EOF

• Start APICast

▲ ~ make development

bash-4.4$ APICAST_LOG_LEVEL=info \
     APICAST_WORKERS=1 \
     APICAST_CONFIGURATION_LOADER=lazy \
     APICAST_CONFIGURATION_CACHE=0 \
     APICAST_CACHE_MAX_TIME=60m \
     THREESCALE_DEPLOYMENT_ENV=staging \
     THREESCALE_CONFIG_FILE=apicast-config-buffering.json \
     ./bin/apicast

• On another terminal window, get APIcast IP

▲ ~ docker ps
CONTAINER ID   IMAGE                                               COMMAND                  CREATED        STATUS          PORTS      NAMES
b296d42cd090   quay.io/3scale/apicast-ci:openresty-1.19.3-pr1379   "cat"                    40 hours ago   Up 42 minutes   8080/tcp   apicast_build_0-development-1
66b01064a328   redis                                               "docker-entrypoint.s…"   40 hours ago   Up 42 minutes   6379/tcp   apicast_build_0-redis-1

▲ ~ APICAST_IP=$(docker inspect -f '{{range.NetworkSettings.Networks}}{{.IPAddress}}{{end}}' apicast_build_0-development-1)

• Send a chunked request to APICast

▲ ~ curl -v -X POST -H "Host: one" -H "Transfer-Encoding: chunked" -d "hello world" "http://${APICAST_IP}:8080/?user_key="

Note: Unnecessary use of -X or --request, POST is already inferred.
* Rebuilt URL to: http://172.18.0.3:8080/?user_key=
*   Trying 172.18.0.3...
* TCP_NODELAY set
* Connected to 172.18.0.3 (172.18.0.3) port 8080 (#0)
> POST /?user_key= HTTP/1.1
> Host: one
> User-Agent: curl/7.61.1
> Accept: */*
> Transfer-Encoding: chunked
> Content-Type: application/x-www-form-urlencoded
>
> b
* upload completely sent off: 18 out of 11 bytes
< HTTP/1.1 200 OK
< Server: openresty
< Date: Fri, 29 Sep 2023 04:56:52 GMT
< Content-Type: application/json; charset=utf-8
< Content-Length: 519
< Connection: keep-alive
< ETag: W/"207-E3Zw8GywynTtA+pWygta+QpX/iE"
< set-cookie: sails.sid=s%3AHNaAy70f4ZxTdqL0JbduWyqKyDpKLvkd.amZZvuEujjMHLdAH88d1WQC%2BIHLlgIC4UFvtt4X6EwE; Path=/; HttpOnly
<
{
  "args": {
    "user_key": ""
  },
  "data": "",
  "files": {},
  "form": {
    "hello world": ""
  },
  "headers": {
    "x-forwarded-proto": "https",
    "x-forwarded-port": "443",
    "host": "postman-echo.com",
    "x-amzn-trace-id": "Root=1-65165913-499dff523f8d21ae49c82810",
    "content-length": "11",
    "user-agent": "curl/7.61.1",
    "accept": "*/*",
    "content-type": "application/x-www-form-urlencoded"
  },
  "json": {
    "hello world": ""
  },
  "url": "https://postman-echo.com/post?user_key="
* Connection #0 to host 172.18.0.3 left intact
}%

The upstream return 200 with Content-Length header

• Generate a big enough file

▲ ~ fallocate -l 1k bigfile

• Send another request with the file just created.

▲ ~ curl -v -X POST -H "Host: one" -H "Transfer-Encoding: chunked" -F file=@bigfile "http://${APICAST_IP}:8080/?user_key="

Note: Unnecessary use of -X or --request, POST is already inferred.
* Rebuilt URL to: http://172.18.0.3:8080/?user_key=
*   Trying 172.18.0.3...
* TCP_NODELAY set
* Connected to 172.18.0.3 (172.18.0.3) port 8080 (#0)
> POST /?user_key= HTTP/1.1
> Host: one
> User-Agent: curl/7.61.1
> Accept: */*
> Transfer-Encoding: chunked
> Content-Type: multipart/form-data; boundary=------------------------75222875ca38fe83
> Expect: 100-continue
>
< HTTP/1.1 100 Continue
* Signaling end of chunked upload via terminating chunk.
< HTTP/1.1 200 OK
< Server: openresty
< Date: Fri, 29 Sep 2023 05:36:30 GMT
< Content-Type: application/json; charset=utf-8
< Content-Length: 1398679
< Connection: keep-alive
< ETag: W/"155797-TOcX0o2gapOIAVRTgw4rQelFlTk"
< set-cookie: sails.sid=s%3A2aN1_2w7ZtrrN0vfAxb3vnS_YZbijWNm.Dn29qUNy274GfKY1L%2BV1VfuAMxfzDaq7Ua2xbMs600M; Path=/; HttpOnly
<
{
  "args": {
    "user_key": ""
  },
  "data": {},
  "files": {
    "filename": "data:application/octet-stream;base64,AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
...
=="
  },
  "form": {},
  "headers": {
    "x-forwarded-proto": "https",
    "x-forwarded-port": "443",
    "host": "postman-echo.com",
    "x-amzn-trace-id": "Root=1-6516625b-4f7d069c20a9c6584473507c",
    "transfer-encoding": "chunked",
    "user-agent": "curl/7.61.1",
    "accept": "*/*",
    "content-type": "multipart/form-data; boundary=------------------------75222875ca38fe83"
  },
  "json": null,
  "url": "https://postman-echo.com/post?user_key="
* Connection #0 to host 172.18.0.3 left intact
}%

This time we can see that upstream return 200 with "transfer-encoding": "chunked" header

[eguzki]

Looking very good.

Left some comments

[eguzki]

All looks great.

Two updates missing:

• Entry in the changelog
• README.md of the policy with brief description and maybe configuration example like

          {
            "name": "request_unbuffered",
            "version": "builtin",
            "configuration": {}
          },

[eguzki]

nice!

[tkan145]

Added README and updated CHANGELOG

[eguzki]

Verification steps 👍 🆗

• build local image

make runtime-image IMAGE_NAME=apicast-test

• Run environment with APIcast configured as gateway of an echo API (from httpbin.org) in plain HTTP 1.1.

First add request_unbuffered policy to the chain

diff --git a/dev-environments/plain-http-upstream/apicast-config.json b/dev-environments/plain-http-upstream/apicast-config.json
index 30c2db39..4dbea5f8 100644
--- a/dev-environments/plain-http-upstream/apicast-config.json
+++ b/dev-environments/plain-http-upstream/apicast-config.json
@@ -38,6 +38,11 @@
           "host": "backend"
         },
         "policy_chain": [
+          {
+              "name": "request_unbuffered",
+              "version": "builtin",
+              "configuration": {}
+          },
           {
             "name": "apicast.policy.apicast"
           }

The run the gateway with the built image

cd dev-environments/plain-http-upstream/
make gateway IMAGE_NAME=apicast-test

• Send chunked request with one chunk body

cat <<EOF >my-data.json
{
   "a": 1
}
EOF

curl --resolve post.example.com:8080:127.0.0.1 -v -H "Transfer-Encoding: chunked"   -H "Content-Type: application/json"  -d @my-data.json "http://post.example.com:8080/?user_key=123"

That request should return 200 OK.

* Added post.example.com:8080:127.0.0.1 to DNS cache
* Hostname post.example.com was found in DNS cache
*   Trying 127.0.0.1:8080...
* Connected to post.example.com (127.0.0.1) port 8080 (#0)
> POST /?user_key=123 HTTP/1.1
> Host: post.example.com:8080
> User-Agent: curl/7.81.0
> Accept: */*
> Transfer-Encoding: chunked
> Content-Type: application/json
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Server: openresty
< Date: Fri, 17 Nov 2023 22:30:56 GMT
< Content-Type: application/json
< Content-Length: 380
< Connection: keep-alive
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Credentials: true
< 
{
  "args": {
    "user_key": "123"
  }, 
  "data": "{   \"a\": 1}", 
  "files": {}, 
  "form": {}, 
  "headers": {
    "Accept": "*/*", 
    "Content-Length": "11", 
    "Content-Type": "application/json", 
    "Host": "example.com", 
    "User-Agent": "curl/7.81.0"
  }, 
  "json": {
    "a": 1
  }, 
  "origin": "172.19.0.3", 
  "url": "http://example.com/post?user_key=123"
}
* Connection #0 to host post.example.com left intact

Note that upstream echo API is reporting that the request included Content-Length header and the expected body.

• Send chunked request with few chunks in the body delayed in time. Python3 is required.

❯ cat <<EOF >chunked-request.py
import http.client
import time

def gen():
    yield bytes('hi', "utf-8")
    time.sleep(2)
    yield bytes('there', "utf-8")
    time.sleep(2)
    yield bytes('bye', "utf-8")

conn = http.client.HTTPConnection('127.0.0.1', 8080)

headers = {'Content-type': 'application/octet-stream', 'Host': 'post.example.com'}

conn.request('POST', '/?user_key=foo', gen(), headers)

response = conn.getresponse()
print(response.read().decode())
EOF

> python3 chunked-request.py
{
  "args": {
    "user_key": "foo"
  }, 
  "data": "hitherebye", 
  "files": {}, 
  "form": {}, 
  "headers": {
    "Accept-Encoding": "identity", 
    "Content-Type": "application/octet-stream", 
    "Host": "example.com", 
    "Transfer-Encoding": "chunked"
  }, 
  "json": null, 
  "origin": "172.19.0.3", 
  "url": "http://example.com/post?user_key=foo"
}

Note that the upstream service got transfer encoding chunked request.

Traffic between the apicast gateway and upstream can be inspected looking at logs from example.com service

> docker compose -p plain-http-upstream logs example.com
example.com  | POST /post?user_key=foo HTTP/1.1\r
example.com  | X-Real-IP: 172.19.0.1\r
example.com  | Host: example.com\r
example.com  | Transfer-Encoding: chunked\r
example.com  | Accept-Encoding: identity\r
example.com  | Content-type: application/octet-stream\r
example.com  | \r
example.com  | 2\r
example.com  | hi\r
example.com  | > 2023/11/17 22:34:18.000755285  length=10 from=180 to=189
example.com  | 5\r
example.com  | there\r
example.com  | > 2023/11/17 22:34:20.000757378  length=13 from=190 to=202
example.com  | 3\r
example.com  | bye\r
example.com  | 0\r
example.com  | \r
example.com  | < 2023/11/17 22:34:20.000758970  length=230 from=0 to=229
example.com  | HTTP/1.1 200 OK\r
example.com  | Server: gunicorn/19.9.0\r
example.com  | Date: Fri, 17 Nov 2023 22:34:20 GMT\r
example.com  | Connection: keep-alive\r
example.com  | Content-Type: application/json\r
example.com  | Content-Length: 361\r
example.com  | Access-Control-Allow-Origin: *\r
example.com  | Access-Control-Allow-Credentials: true\r
example.com  | \r
example.com  | < 2023/11/17 22:34:20.000759320  length=361 from=230 to=590
example.com  | {
example.com  |   "args": {
example.com  |     "user_key": "foo"
example.com  |   }, 
example.com  |   "data": "hitherebye", 
example.com  |   "files": {}, 
example.com  |   "form": {}, 
example.com  |   "headers": {
example.com  |     "Accept-Encoding": "identity", 
example.com  |     "Content-Type": "application/octet-stream", 
example.com  |     "Host": "example.com", 
example.com  |     "Transfer-Encoding": "chunked"
example.com  |   }, 
example.com  |   "json": null, 
example.com  |   "origin": "172.19.0.3", 
example.com  |   "url": "http://example.com/post?user_key=foo"
example.com  | }
example.com  | 2023/11/17 22:34:22 socat[23] N socket 2 (fd 5) is at EOF
example.com  | 2023/11/17 22:34:22 socat[23] N socket 1 (fd 6) is at EOF
example.com  | 2023/11/17 22:34:22 socat[23] N exiting with status 0
example.com  | 2023/11/17 22:34:22 socat[1] N childdied(): handling signal 17

Note the chunked encoding of the request with the length bytes preceding each chunk.

[eguzki]

Great job!

It will be ready to be merged, once all test pass

[eguzki]

Some (prove) tests are failing, even locally. Let me know if you need some help to fix them.

[tkan145]

It should be good now. I don't have permission to rerun the test, can you please help re-trigger the prove test for me?

[tkan145]

@eguzki I looked at those failed tests apicast-mapping-rules.t and backend-cache-handler.t

Both failed because I used liquid to include the shared file, but they used the old test method so the configuration file could not be expanded.

2 ways to fix this:

1. Add all of the proxy_xxx back to the apicast.conf file
2. Convert both tests to Blackbox apicast-mapping-rules.t conversion to APIcast::Blackbox #1430 backend-cache-handler.t conversion to APIcast::Blackbox #1431

we need to move those two to Blackbox anyway, but let me know what you think.

[eguzki]

o move those two to Blackb

Another good reason to move those to backbox.

Ok, let's merge those two first, and then rebase this PR on top of them.

[tkan145]

codecov failed 🙄

still good to merge?

[eguzki]

it is already approved. you requested a new review?

[tkan145]

Ah sorry, I just wanted to ask if I can merge the PR even if the codecov fails, or all the tests MUST pass before I can merge.

[eguzki]

No hard rule here. It is true that the coverage dropped more than 3%. That was the threshold we specified https://github.com/3scale/APIcast/blob/master/.codecov.yml#L10-L19

You implemented tests. So, we can agree on "bypassing" exceptionally this time. LGTM