Имеется приложение, которое должно принимать данные через POST-запросы от клиентов.
Перед этим приложением имеется некий прокси, не важно какой – AWS Application Load Balancer, NGINX или любой другой. Мы изначально столкнулись с проблемой на AWS ALB, потом я начал тестить на NGINX, что бы искючить влияение самого AWS-сервиса – воспроизводится везде, т.к. не зависит от проксирующей службы.
Прокси помимо проксирования трафика к приложению выполняет редирект с HTTP (80) на HTTPS (443).
Собственно, проблема возникает именно во время такого редиректа:
- клиент отправляет
POST
по HTTP - прокси возвращает клиенту редирект 301 или 302 на HTTPS
- клиент отправляет запрос на HTTPS, но:
- либо запрос превращается в
GET
- либо он остаётся
POST
, но все данные после редиректа “пропадают”
- либо запрос превращается в
Содержание
Setup – тестовая площадка
Для тестирования будем использовать следующий сетап:
- на входе API-запросы принимаются NGINX
- NGINX через
proxy_pass
по HTTP передаёт запрос бекенду- в роли бекенда используем Go-приложение в Docker-контейнере, что бы воспроизвести проблему с
POST
, который превращается вGET
- и Python-приложение, что бы воспроизвести проблему с “потерянными” данными и пустым
Сontent-length
- в роли бекенда используем Go-приложение в Docker-контейнере, что бы воспроизвести проблему с
NGINX
Тут всё совершенно стандартно – обычный NGINX, который принимает соединения на порт 80, и редиректит их на HTTPS:
server { listen 80; server_name dev.poc.example.com; location / { return 302 https://dev.poc.example.com$request_uri; } } ...
И server 443 {}
– тоже стандартный, с proxy_pass
на бекенд, тут для тестов используем 8081:
... server { listen 443 ssl; server_name dev.poc.example.com; ... location / { proxy_pass http://localhost:8081; proxy_set_header Host $host; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; proxy_set_header X-Forwarded-Proto $scheme; } }
Go-app в Docker
Там на самом деле несколько контейнеров, нас интересует их проксирующий go-queue-consumer, в котором крутися стандартный NGINX (весь этот сетап ещё в Proof of Concept, потому не удивляйтесь количеству NGINX в этой схеме).
Нам от него интересны логи, в которых будет POST
или GET
.
Python web-server
И для тестирования HTTP message body – используем нагугленный Python-скрипт:
#!/usr/bin/env python3 """ Very simple HTTP server in python for logging requests Usage:: ./server.py [<port>] """ from http.server import BaseHTTPRequestHandler, HTTPServer import logging class S(BaseHTTPRequestHandler): def _set_response(self): self.send_response(200) self.send_header('Content-type', 'text/html') self.end_headers() def do_GET(self): logging.info("GET request,\nPath: %s\nHeaders:\n%s\n", str(self.path), str(self.headers)) self._set_response() self.wfile.write("GET request for {}".format(self.path).encode('utf-8')) def do_POST(self): content_length = int(self.headers['Content-Length']) # <--- Gets the size of data post_data = self.rfile.read(content_length) # <--- Gets the data itself logging.info("POST request,\nPath: %s\nHeaders:\n%s\n\nBody:\n%s\n", str(self.path), str(self.headers), post_data.decode('utf-8')) self._set_response() self.wfile.write("POST request for {}".format(self.path).encode('utf-8')) def run(server_class=HTTPServer, handler_class=S, port=8081): logging.basicConfig(level=logging.INFO) server_address = ('', port) httpd = server_class(server_address, handler_class) logging.info('Starting httpd...\n') try: httpd.serve_forever() except KeyboardInterrupt: pass httpd.server_close() logging.info('Stopping httpd...\n') if __name__ == '__main__': from sys import argv if len(argv) == 2: run(port=int(argv[1])) else: run()
Примеры – воспроизводим проблему
POST теряет данные после редиректа
Первое, с чем столкнулись, и что вообще заставило углубиться в проблему – после выполнения редиректа с HTTP на HTTPS – POST
-запрос терял данные.
Т.е, обратился бекенд-разработчик, который сказал, что после редиректа на бекенд не приходят данные.
Что бы воспроизвести проблему – используем Python-скрипт, приведённый выше.
Запускаем его на порту 8081:
[simterm]
root@ip-10-0-15-118:/home/admin# ./test_post.py 8081 INFO:root:Starting httpd...
[/simterm]
Выполняем curl
с POST
с какими-то данными в --data
:
[simterm]
$ curl -vL -X POST http://dev.poc.example.com/ -d "param1=value1¶m2=value2" ... * Trying 52.***.***.224:80... ... > Content-Length: 27 ... < HTTP/1.1 302 Moved Temporarily ... < Content-Length: 161 < Connection: keep-alive < Location: https://dev.poc.example.com/ ... > POST / HTTP/1.1 > Host: dev.poc.example.com > User-Agent: curl/7.67.0 > Accept: */* > * Mark bundle as not supporting multiuse < HTTP/1.1 502 Bad Gateway < Server: nginx/1.10.3 ... < Content-Type: text/html < Content-Length: 173
[/simterm]
Что тут происходит:
POST
-запрос с данными на HTTP, Content-Length: 27- 302 редирект на HTTPS
POST
на HTTPS, Content-Length: 173
В логах NGINX видим нормальный HTTP POST
:
[simterm]
... ==> /var/log/nginx/dev.poc.example.com-error.log <== 2019/11/23 09:52:41 [error] 19793#19793: *51100 upstream prematurely closed connection while reading response header from upstream, client: 194.***.***.26, server: dev.poc.example.com, request: "POST / HTTP/1.1", upstream: "http://127.0.0.1:8081/", host: "dev.poc.example.com" ==> /var/log/nginx/dev.poc.example.com-access.log <== 194.***.***.26 - - [23/Nov/2019:09:52:41 +0000] "POST / HTTP/1.1" 502 173 "-" "curl/7.67.0" ...
[/simterm]
И посмотрим stderr нашего Python-сервера:
[simterm]
... Exception happened during processing of request from ('127.0.0.1', 38224) Traceback (most recent call last): File "/usr/lib/python3.5/socketserver.py", line 313, in _handle_request_noblock self.process_request(request, client_address) File "/usr/lib/python3.5/socketserver.py", line 341, in process_request self.finish_request(request, client_address) File "/usr/lib/python3.5/socketserver.py", line 354, in finish_request self.RequestHandlerClass(request, client_address, self) File "/usr/lib/python3.5/socketserver.py", line 681, in __init__ self.handle() File "/usr/lib/python3.5/http/server.py", line 422, in handle self.handle_one_request() File "/usr/lib/python3.5/http/server.py", line 410, in handle_one_request method() File "./test_post.py", line 22, in do_POST content_length = int(self.headers['Content-Length']) # <--- Gets the size of data TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType' ...
[/simterm]
Нас тут интересуют вот эти строки:
…
content_length = int(self.headers[‘Content-Length‘])
TypeError: int() argument must be a string, a bytes-like object or a number, not ‘NoneType‘
Т.е. к приложению Content-Length пришёл совершенно пустой.
При этом, если выполнить прямой запрос на HTTP (с отключенным редиректом в NGINX) или HTTPS – всё работает, как ожидается:
[simterm]
$ curl -vL -X POST https://dev.poc.example.com/ -d "param1=value1¶m2=value2" ... > POST / HTTP/1.1 > Host: dev.poc.example.com > User-Agent: curl/7.67.0 > Accept: */* > Content-Length: 27 > Content-Type: application/x-www-form-urlencoded > * upload completely sent off: 27 out of 27 bytes * Mark bundle as not supporting multiuse < HTTP/1.1 200 OK < Server: nginx/1.10.3 < Date: Sat, 23 Nov 2019 09:55:07 GMT < Content-Type: text/html < Transfer-Encoding: chunked < Connection: keep-alive < * Connection #0 to host dev.poc.example.com left intact POST request for /
[/simterm]
И stdout Python-приложения:
[simterm]
... INFO:root:POST request, Path: / Headers: Host: dev.poc.example.com X-Real-IP: 194.***.***.26 X-Forwarded-For: 194.***.***.26 X-Forwarded-Proto: https Connection: close Content-Length: 27 User-Agent: curl/7.67.0 Accept: */* Content-Type: application/x-www-form-urlencoded Body: param1=value1¶m2=value2 127.0.0.1 - - [23/Nov/2019 09:55:07] "POST / HTTP/1.0" 200 -
[/simterm]
Теперь – посмотрим на вторую проблему.
POST становится GET
В процессе дебага описанной выше проблемы, когда на бекенд не доходили данные при POST
, нашлось ещё одно интересное поведение запросов при HTTP-редиректах.
Теперь посмотрим, как POST
превращается в …. GET
🙂
“Всё сложно”. Детали поведения рассмотрим в конце этого поста, сейчас – давайте попробуем один и тот же запрос на один и тот же ендпоинт, но используя два разных клиента – curl
, и Postman (в виде standalone-приложения на рабочей машине).
curl
Выполняем запрос с типом POST
на HTTP, добавляем -L
, что бы проследовать по редиректам на HTTPS.
Тут в роли бекенда уже используем не Python-скрипт, как в примерах выше, а наш реальный бекенд в Docker-контейнере, что бы продемонстрировать его нормальную и не очень работу.
Сами данные значения и ошибки сейчас не имеют – нам интересен только тип запроса в логах NGINX:
[simterm]
$ curl -vL -X POST http://dev.poc.example.com/skin/api/v1/receipt -d "{}" ... > POST /skin/api/v1/receipt HTTP/1.1 > Host: dev.poc.example.com > User-Agent: curl/7.67.0 > Accept: */* > * Mark bundle as not supporting multiuse < HTTP/1.1 400 Bad Request < Server: nginx/1.10.3 < Date: Sat, 23 Nov 2019 10:07:37 GMT < Content-Type: application/json; charset=utf-8 < Content-Length: 58 < Connection: keep-alive < * Connection #1 to host dev.poc.example.com left intact {"message":"Validation failed: unable to parse json body"}
[/simterm]
Ещё раз – на ошибки не обращаем внимания, т.к. реальные данные к бекенду не отправили, нас сейчас интересует исключительно тип запроса в логах, давайте ещё глянем в логах NGINX:
[simterm]
==> /var/log/nginx/dev.poc.example.com-access.log <== 194.***.***.26 - - [23/Nov/2019:10:07:37 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 400 58 "-" "curl/7.67.0"
[/simterm]
Тут всё хорошо, да? POST
отправили – POST
приняли.
Если мы curl
-ом отправим явный GET
– ответ бекенда будет другим:
[simterm]
$ curl -L -X GET http://dev.poc.example.com/skin/api/v1/receipt -d "{}" 404 page not found
[/simterm]
И вот этот же GET
в логе NGINX:
[simterm]
==> /var/log/nginx/dev.poc.example.com-access.log <== 194.***.***.26 - - [23/Nov/2019:10:07:37 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 400 58 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:09:57 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "-" "curl/7.67.0"
[/simterm]
Всё правильно – всё логично, да?
Postman
А теперь – повторяем этот же запрос из Postman.
Нам важно отправить другим клиентом, QA-тима воспроизводила как раз в Postman, но должно быть и в прочих.
Выполняем такой же запрос – POST
на HTTP, и сработает редирект на HTTPS:
И? 🙂
И теперь – смотрим лог NGINX снова, последняя запись:
[simterm]
==> /var/log/nginx/dev.poc.example.com-access.log <== 194.***.***.26 - - [23/Nov/2019:10:07:37 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 400 58 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:09:57 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:11:44 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "http://dev.poc.example.com/skin/api/v1/receipt" "PostmanRuntime/7.19.0"
[/simterm]
Ээээ…
Шта?!?
Но я ведь отправил явный POST
?
Ещё раз:
- выполняем запрос
curl
, срабатывает редирект HTTP => HTTPS, видимPOST
– всё отлично - выполняем запрос из Postman, срабатывает редирект HTTP => HTTPS, видим
GET
– WTF???
POST, GET и “потерянные данные”
Зато теперь сновится понятно – куда “потерялись” наши данные из POST
– потому что он превратился к GET
.
Причина проблемы, 3xx redirects и HTTP RFC
Собственно, обе проблемы вызваны одной и той же причиной.
Начнём со чтения кода 301 в RFC 2616 – https://tools.ietf.org/html/rfc2616#section-10.3.2 – нас тут особенно интересует Note к описанию 301 редиректа:
Note: When automatically redirecting a POST request after
receiving a 301 status code, some existing HTTP/1.0 user agents
will erroneously change it into a GET request.
Т.е. некоторые существующие агенты HTTP/1.0 после выполнения POST
и получения 301 – меняют его тип (хотя не должны, см. ниже), и выполняют GET
.
Но это оказалось только вершиной айсберга.
Читаем дальше, про код 302, в том же RFC 2016 – https://tools.ietf.org/html/rfc2616#section-10.3.3 – и снова внимание на Note:
Note: RFC 1945 and RFC 2068 specify that the client is not allowed
to change the method on the redirected request. However, most
existing user agent implementations treat 302 as if it were a 303
response, performing a GET on the Location field-value regardless
of the original request method. The status codes 303 and 307 have
been added for servers that wish to make unambiguously clear which
kind of reaction is expected of the client.
RFC 1945 про 3хх редиректы – https://tools.ietf.org/html/rfc1945#section-9.3
RFC 2068 про 3хх редиректы – https://tools.ietf.org/html/rfc2068#section-10.3.2
Т.е. – RFC 1945 and RFC 2068 говорят, что клиент не должен менять метод для редиректнутого запроса, но при этом большинство считают код 302 как 303.
Идём ниже, и читаем описание кода 303 – https://tools.ietf.org/html/rfc2616#section-10.3.4:
The response to the request can be found under a different URI and
SHOULD be retrieved using a GET method on that resource.
Т.е., когда клиент считает, что он получил 303 код – он всегда выполняет GET.
Т.е, что мы видим в случае с Postman (и нашими мобильными клиентами, на которых проблема и проявилась изначально):
- клиент отправляет
POST
на HTTP - получает редирект на HTTPS с кодом 301 или 302
- воспринимает его, как редирект 303
- и меняет тип своего запроса уже к HTTPS на
GET
, с “потерей” отправленных данных
Решение
Найти решение помогла документация от Mozilla (хотя подсказка была и в Notes RFC 2016 по 302), которая в своей документации к 301 и 302 явно говорит:
It is therefore recommended to set the 302 code only as a response for GET or HEAD methods and to use 307 Temporary Redirect instead, as the method change is explicitly prohibited in that case.
Идём в NGINX, меняем код редиректа с 302 на 307:
server { listen 80; ... location / { # return 302 https://dev.poc.example.com$request_uri; return 307 https://dev.poc.example.com$request_uri; } } ...
Перечитываем конфиги NGINX и повторяем запрос с помощью curl
:
[simterm]
$ curl -L -X POST http://dev.poc.example.com/skin/api/v1/receipt -d "{}" {"message":"Validation failed: fields 'hardware_id' and 'receipt' are mandatory"}
[/simterm]
Теперь мы получили валидный ответ от бекенда, который просто хочет нормальных входных данных.
Редирект сработал, POST
-запрос от нас пришёл.
Лог NGINX:
[simterm]
==> /var/log/nginx/dev.poc.example.com-access.log <== 194.***.***.26 - - [23/Nov/2019:10:07:37 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 400 58 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:09:57 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:11:44 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "http://dev.poc.example.com/skin/api/v1/receipt" "PostmanRuntime/7.19.0" 194.***.***.26 - - [23/Nov/2019:10:35:51 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 422 81 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:36:00 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 422 81 "-" "curl/7.67.0"
[/simterm]
Повторяем запрос из Postman:
Лог NGINX:
[simterm]
==> /var/log/nginx/dev.poc.example.com-access.log <== 194.***.***.26 - - [23/Nov/2019:10:07:37 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 400 58 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:09:57 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:11:44 +0000] "GET /skin/api/v1/receipt HTTP/1.1" 404 18 "http://dev.poc.example.com/skin/api/v1/receipt" "PostmanRuntime/7.19.0" 194.***.***.26 - - [23/Nov/2019:10:35:51 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 422 81 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:36:00 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 422 81 "-" "curl/7.67.0" 194.***.***.26 - - [23/Nov/2019:10:37:57 +0000] "POST /skin/api/v1/receipt HTTP/1.1" 422 81 "http://dev.poc.example.com/skin/api/v1/receipt" "PostmanRuntime/7.19.0"
[/simterm]
Всё работает, как ожидалось.
AWS Application Load Balancer redirects
Увы, при использовании редиректов на AWS ALB – он не позволяет задать другой код:
В целом – на этом всё.
Было интересно.
Ссылки по теме
Эта же проблема на других ресурсах
- POST Request redirects to GET in Nginx proxy and NodeJS
- Trouble while passing POST request through proxy_pass
- How to proxy_pass POST with headers
- Nginx removes Content-Length header for chunked content
- POST Request with response 302 and content-length 0 crashes nginx
- Reverse Proxy POST problem
- HTTP POST redirect – no Content-Length