400 bad request nginx как исправить

Yes changing the error_to debug level as Emmanuel Joubaud suggested worked out (edit /etc/nginx/sites-enabled/default ):

        error_log /var/log/nginx/error.log debug;

Then after restarting nginx I got in the error log with my Python application using uwsgi:

        2017/02/08 22:32:24 [debug] 1322#1322: *1 connect to unix:///run/uwsgi/app/socket, fd:20 #2
        2017/02/08 22:32:24 [debug] 1322#1322: *1 connected
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http upstream connect: 0
        2017/02/08 22:32:24 [debug] 1322#1322: *1 posix_memalign: 0000560E1F25A2A0:128 @16
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http upstream send request
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http upstream send request body
        2017/02/08 22:32:24 [debug] 1322#1322: *1 chain writer buf fl:0 s:454
        2017/02/08 22:32:24 [debug] 1322#1322: *1 chain writer in: 0000560E1F2A0928
        2017/02/08 22:32:24 [debug] 1322#1322: *1 writev: 454 of 454
        2017/02/08 22:32:24 [debug] 1322#1322: *1 chain writer out: 0000000000000000
        2017/02/08 22:32:24 [debug] 1322#1322: *1 event timer add: 20: 60000:1486593204249
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http finalize request: -4, "/?" a:1, c:2
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http request count:2 blk:0
        2017/02/08 22:32:24 [debug] 1322#1322: *1 post event 0000560E1F2E5DE0
        2017/02/08 22:32:24 [debug] 1322#1322: *1 post event 0000560E1F2E5E40
        2017/02/08 22:32:24 [debug] 1322#1322: *1 delete posted event 0000560E1F2E5DE0
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http run request: "/?"
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http upstream check client, write event:1, "/"
        2017/02/08 22:32:24 [debug] 1322#1322: *1 http upstream recv(): -1 (11: Resource temporarily unavailable)

Then I took a look to my uwsgi log and found out that:

        Invalid HTTP_HOST header: 'www.mysite.local'. You may need to add u'www.mysite.local' to ALLOWED_HOSTS.
        [pid: 10903|app: 0|req: 2/4] 192.168.221.2 () {38 vars in 450 bytes} [Wed Feb  8 22:32:24 2017] GET / => generated 54098 bytes in 55 msecs (HTTP/1.1 400) 4 headers in 135 bytes (1 switches on core 0)

And adding www.mysite.local to the settings.py ALLOWED_HOSTS fixed the
issue 🙂

        ALLOWED_HOSTS = ['www.mysite.local']

Раздражает, когда какой-то сайт не загружается и отзывается непонятными ошибками. Обычно они сопровождаются одним из десятков HTTP-кодов, которые как раз намекают на характер сбоя, а также его вероятные причины. 

В этом материале поговорим об ошибке 400 Bad Request. Почему она появляется и как ее исправить. 

Чуть подробнее об ошибке 400

Как и другие коды, начинающиеся на четверку, 400 Bad Request говорит о том, что возникла проблема на стороне пользователя. Зачастую сервер отправляет ее, когда появившаяся неисправность не подходит больше ни под одну категорию ошибок. 

Стоит запомнить — код 400 напрямую связан с клиентом (браузером, к примеру) и намекает на то, что отправленный запрос со стороны пользователя приводит к сбою еще до того, как его обработает сервер (вернее, так считает сам сервер). 

Из-за чего всплывает Bad Request?

Есть 4 повода для возникновения ошибки сервера 400 Bad Request при попытке зайти на сайт:

1. Некорректно настроенные HTTP-заголовки в запросе со стороны клиента. Некоторые приложения и сайты мониторят заголовки на предмет наличия в них чего-нибудь подозрительного. Если ваш запрос не соответствует ожиданиям сервера, то высока вероятность появления ошибки 400 (но это не всегда вина пользователя).
2. Такой же сбой появляется, если клиент пытается загрузить на сервер файл слишком большого размера. Это происходит, потому что на большинстве сайтов есть ограничения по размеру загружаемых данных. Причем ограничение может быть как в 2 гигабайта, так и в 600 килобайт.
3. Еще ошибка 400 появляется, когда пользователь пытается получить доступ к несуществующей странице. То есть в браузер банально ввели ссылку с опечаткой, некорректным доменом или поддоменом.
4. Устаревшие или измененные куки-файлы. Сервер может воспринять подмену куки-файлов как попытку атаковать или воспользоваться дырой в безопасности. Поэтому такие запросы сходу блокируются.

Исправляем ошибку 400 Bad Request на стороне клиента

Так как ошибка 400 в 99 случаев из 100 возникает на стороне клиента, начнем с соответствующих методов. Проверим все элементы, участвующие в передаче запроса со стороны клиента (браузера).

Проверяем адрес сайта

Банальщина, но необходимая банальщина. Перед тем как бежать куда-то жаловаться и предпринимать более серьезные шаги, повнимательнее взгляните на ссылку в адресной строке. Может, где-то затесалась опечатка или вы случайно написали большую букву вместо маленькой. Некоторые части адреса чувствительны к регистру. 

А еще стоит поискать запрашиваемую страницу через поисковик, встроенный в сайт. Есть вероятность, что конкретная страница куда-то переехала, но сервер не может показать подходящий HTTP-код в духе 404 Not Found. Если, конечно, сам сайт работает. 

Сбрасываем параметры браузера

Этот метод срабатывает, если сервер отказывается принимать запросы из-за «битых» куки или других данных. Дело в том, что сайт использует куки-файлы, чтобы хранить информацию о пользователе у него же в браузере. При входе конкретного человека на ресурс, он пытается распознать куки и сравнить информацию с той, что уже есть на сервере.

Иногда случается, что куки-файлы одного или нескольких пользователей вступают в конфликт. В таком случае надо открыть настройки браузера, а потом удалить весь кэш, куки и прочие связанные элементы. 

В зависимости от браузера процесс удаления куки-файлов может немного отличаться. В Chrome это работает так:

• Открываем настройки браузера. 
• Переходим в раздел «Конфиденциальность и безопасность».
• Выбираем «Файлы cookie и другие данные».
• Нажимаем на кнопку «Удалить все».

Для чистки cookies можно использовать стороннюю программу в духе CCleaner или CleanMyPC.

Загружаем файл подходящего размера

Если ошибка 400 Bad Request появляется при попытке загрузить на сайт какой-нибудь файл, то стоит попробовать загрузить файл поменьше. Иногда вебмастера ленятся грамотно настроить ресурс, и вместо понятного объяснения вроде «Загружаемые файлы не должны быть размером больше 2 мегабайт» люди получают Bad Request. Остается только гадать, какой там у них лимит. 

Устраняем проблемы, связанные с Windows и сторонним софтом

Помимо браузера, на работу сети могут влиять другие программные продукты (экраны, защищающие от «непонятных подключений»). И вирусы. Да и сама Windows может стать проблемой. Почти любой ее компонент. Поэтому надо бы проделать следующее:

• Повторно установить NET.Framework. Желательно перед этим удалить предыдущую версию.
• Установить какой-нибудь приличный антивирус (а лучше два) и запустить глубокую проверку систему. Возможно, подключению и входу на ресурс мешает вредоносная программа.
• Если у вас уже установлен антивирус, то, наоборот, попробуйте его отключить. Иногда встроенные в них экраны проверки подключений блокируют работу браузера целиком или отдельных страниц. Лучше выдать браузеру больше прав на выполнение своих задач или установить антивирус, который более лояльно относится к установленному на компьютере софту.
• Еще надо поменять параметры брандмауэра. Его можно разыскать в панели управления Windows. Там надо добавить в список исключений ваш браузер. Тогда брандмауэр не будет мешать подключению к запрашиваемому сайту.
• Почистить Windows от программного мусора. Можно пройтись приложением CCleaner. 
• Обновить драйверы для сетевых устройств. 
• Обновить Windows или просканировать систему на наличие погрешностей в системных компонентах.

Ищем проблему на стороне сервера

Если что-то происходит на стороне ресурса, то это редко заканчивается ошибкой 400. Но все-таки есть несколько сценариев, при которых клиента обвиняют в сбое зря, а настоящая вина лежит на сервере. 

Проверяем требования к HTTP-заголовкам

Пока настраиваешь сайт, несложно допустить ошибку или даже парочку. Возможно, требования к HTTP-заголовком указаны некорректно, и сервер ожидает запросы с ошибками, которые по объективным причинам не может распознать адекватно. Тогда администратору стоит перепроверить ожидаемые заголовки на своем сайте или в приложении. 

Удаляем свежие обновления и плагины

Иногда ошибка 400 Bad Request появляется после обновления CMS или установки новых плагинов. Если у вас она появилась из-за этого, то наиболее логичное решение — откатиться до более ранней версии CMS и удалить все новые плагины. 

Главное, перед этим сделать резервную копию данных. И перед установкой обновлений тоже стоило бы.

Проверяем состояние базы данных

Некоторые сторонние расширения для того же WordPress получают полный доступ к ресурсу и имеют право вносить изменения даже в подключенную базу данных. Если после удаления свежих плагинов ошибка 400 никуда не исчезла и появляется у всех, кто пытается зайти на сайт, стоит проверить, в каком состоянии находится база данных. Нужно вручную проверить все записи на наличие подозрительных изменений, которые могли быть сделаны установленными расширениями.

Исправляем ошибки в коде и скриптах

Ничего из вышеперечисленного не помогло? Тогда осталось проверить свой код и работающие скрипты. Лучше провести дебаггинг вручную и не надеяться на помощь компьютера. Сделать копию приложения или сайта, потом пошагово проверить каждый отрезок кода в поисках ошибок. 

В крайнем случае придется кричать «полундра» и звать на помощь техподдержку хостинга. Возможно, возникли сложности на их стороне. Тогда вообще ничего не надо будет делать. Просто ждать, пока все исправят за вас. 

На этом все. Основные причины появления 400 Bad Request разобрали. Как ее лечить — тоже. Теперь дело за вами. Пользуйтесь полученной информацией, чтобы больше не пришлось мучиться в попытках зайти на нужный ресурс.

Ошибка 400 bad request nginx означает, что сделан неверный запрос.

Ошибка может возникать по разным причинам, всё зависит от используемой конфигурации и приложения.

Если речь идет о запросах к базе данных или API — причина может быть в работе бэкенда. Например, недостаточное количество знаков в  поле БД.

В случае если ошибка возникает при обращении к странице сайта — причина обычно в Nginx и размерах буферов, которые задаются в конфигурационных файлах.

Рассмотрим подробнее этот случай, он самый типичный.

Ошибка 400 bad request nginx

Объем заголовков в запросе может быть различным. Если он велик и лимит, установленный в конфигурации, не позволяет их обработать — возникнет ошибка.

Ошибка исправляется добавлением в секцию http конфигурационного файла nginx.conf следующей директивы:

large_client_header_buffers 2 12k;

Тестируем конфигурацию, убеждаемся в том, что ошибок в выводе нет

nginx -t

Затем перечитываем конфигурация веб-сервера чтобы он увидел новые директивы и значения паратетров.

nginx -s reload

Если параметры уже добавлены можно попробовать увеличить их значения, в 2, в 4 раза.

С каждой итерацией нужно тестировать конфигурацию с помощью nginx -t, перезапускать процесс nginx -s reload и проверять выполняя тот же запрос при котором была ошибка 400 bad request nginx.

Дополнительно можно проверить логи Nginx

less /var/log/nginx/error.log

Если ошибка возникает периодически — в логе доступа можно найти при помощи grep все случаи получения ответа 400 по уникальным характеристикам запроса: комбинации даты, времени, ip адреса клиента. Затем сопоставить данные с записями в error.log — логе ошибок.

В access.log будут запросы, которые выполнялись при обращении к сайту.

Пример запроса с кодом ответа 400 приведен на скриншоте:

Также есть другие буферы Nginx, на которые стоит обратить внимание (ссылка на статью про буферы была выше). Особенно если сервер обслуживает нагруженный проект.

Читайте про конфигурацию веб-сервера Nginx: структуру файлов с настройками и контексты.

---

Today I came across an interesting issue: A client got a http error 400 (bad request) when accessing certain pages of a website.

This website’s architecture is built redundantly around a couple of load balancers. Here’s an example drawing of such an architecture:

This means the traffic needs to run through multiple hosts including Nginx and HAProxy servers until finally reaching the application itself on the application server or container.

Debugging in Nginx

Once the client’s IP address was identified I enabled the “debug mode” for this particular IP. Nginx allows to set a certain IP address or range into debug mode by using the “debug_connection” parameter in the events context. This context is usually found in /etc/nginx/nginx.conf:

events {
    # Debugging a certain IP
    debug_connection 192.168.55.12; # client getting http 400 errors
}

When this client accesses the website, there will be a lot of debug information written into the defined error log of the requested virtual host. So if you have a virtual host (server) config with a dedicated error log, this debugged connection will be logged there:

server {
  listen 80;
  server_name www.example.com;
  access_log  /var/log/nginx/www.example.com.access.log;
  error_log  /var/log/nginx/www.example.com.error.log;
[…]

The log entries appearing in /var/log/nginx/www.example.com.error.log will contain A LOT of information, don’t be shocked.

When I asked the client to access the website again and reproduce the http 400 error, this request was logged in detail and I was able to analyze it. Here’s the (almost) full data of that request:

2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http args: “”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http exten: “1482353”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http process request header line
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Host: www.example.com”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Connection: keep-alive”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Upgrade-Insecure-Requests: 1”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.169 Safari/537.36”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Referer: https://www.example.com/”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Accept-Encoding: gzip, deflate, br”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 posix_memalign: 00000000031BBA00:4096 @16
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Accept-Language: en-US,en;q=0.9,de;q=0.8”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http alloc large header buffer
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 malloc: 00000000031EDD50:8192
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http large header alloc: 00000000031EDD50 8192
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http large header copy: 464
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 SSL_read: 7140
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 SSL_read: -1
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 SSL_get_error: 2
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e3d2d2-4567-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7b5f6f548274; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW9829-qn6kGrFjkEQ314I82HLgMX6Siy74BCVpPrOD-XLVNIwC_HX-6fknWkiXxR-Yg; ens_cntpvabo=383; ens_subscrst=subscriber%3BWed%20Jun%2026%202019%2009%3A48%3A49%20GMT%2B0200%20(Mitteleurop%C3%A4ische%20Sommerzeit); _gid=GA1.2.131606941.1558944578; ens_kavz=0986-0050-01-010; _fbc=fb.1.1558951120515.IwAR1vSVauTbRT1sO397XEXVmRHTSbC3dL08dZ9WSMVLGSoS4T9m8QRgHv6Js; p4m_snot=1318; s_vdnum=1559080800290%26vn%3D1; s_dinvisit=true; s_vwnum=1559426400501%26vn%3D7; s_winvisit=true; s_vmnum=1559340000345%26vn%3D56; s_minvisit=true; s_dslv_s=Less%20than%201%20day; ens_ueid_3425441984_513=1559034247693; ens_cntpwmt=5; ens_ueid_624612360_513=1559034320820; POPUPCHE
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header done
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 generic phase: 0
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 rewrite phase: 1
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 test location: “/”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 test location: “sitemap”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 using configuration “/”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http cl:-1 max:104857600
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 rewrite phase: 3
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 post rewrite phase: 4
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 generic phase: 5
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 generic phase: 6
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 generic phase: 7
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 generic phase: 8
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 access phase: 9
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 access phase: 10
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 post access phase: 11
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http init upstream, client timer: 0
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 malloc: 0000000003207030:8282
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “Host: “
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script var: “www.example.com”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “
“
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “X-Real-IP: “
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script var: “192.168.55.12”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “
“
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “X-Forwarded-For: “
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script var: “192.168.55.12”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “
“
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “X-Forwarded-Proto: https
“
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “Connection: close
“
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http script copy: “”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Upgrade-Insecure-Requests: 1”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.169 Safari/537.36”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Referer: https://www.example.com/”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Accept-Encoding: gzip, deflate, br”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Accept-Language: en-US,en;q=0.9,de;q=0.8”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e3d2d2-4567-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7b5f6f548274; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW9829-qn6kGrFjkEQ314I82HLgMX6Siy74BCVpPrOD-XLVNIwC_HX-6fknWkiXxR-Yg; ens_cntpvabo=383; ens_subscrst=subscriber%3BWed%20Jun%2026%202019%2009%3A48%3A49%20GMT%2B0200%20(Mitteleurop%C3%A4ische%20Sommerzeit); _gid=GA1.2.131606941.1558944578; ens_kavz=0986-0050-01-010; _fbc=fb.1.1558951120515.IwAR1vSVauTbRT1sO397XEXVmRHTSbC3dL08dZ9WSMVLGSoS4T9m8QRgHv6Js; p4m_snot=1318; s_vdnum=1559080800290%26vn%3D1; s_dinvisit=true; s_vwnum=1559426400501%26vn%3D7; s_winvisit=true; s_vmnum=1559340000345%26vn%3D56; s_minvisit=true; s_dslv_s=Less%20than%201%20day; ens_ueid_3425441984_513=1559034247693; ens_cntpwmt=5; ens_ueid_624612360_513=1559034320820; PO
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header:
“GET /news/article-1234.1482353 HTTP/1.0
Host: www.example.com
X-Real-IP: 192.168.55.12
X-Forwarded-For: 192.168.55.12
X-Forwarded-Proto: https
Connection: close
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.169 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
Referer: https://www.example.com/
Accept-Encoding: gzip, deflate, br
Accept-Language: en-US,en;q=0.9,de;q=0.8
Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e3d2d2-4567-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7b5f6f548274; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http cleanup add: 00000000031BC128
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 get rr peer, try: 1
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 stream socket 1514
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 epoll add connection: fd:1514 ev:80002005
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 connect to 127.0.0.1:8080, fd:1514 #1706804565
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream connect: -2
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 posix_memalign: 00000000021EF490:128 @16
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 event timer add: 1514: 6000000:1559039102955
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http finalize request: -4, “/news/article-1234.1482353?” a:1, c:2
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http request count:2 blk:0
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 delete posted event 00007F5DB055BA50
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http run request: “/news/article-1234.1482353?”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream check client, write event:1, “/news/article-1234.1482353”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream recv(): -1 (11: Resource temporarily unavailable)
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 post event 00007F5DB055BA50
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 post event 00007F5DB055B210
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 delete posted event 00007F5DB055BA50
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http run request: “/news/article-1234.1482353?”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream check client, write event:1, “/news/article-1234.1482353”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream recv(): -1 (11: Resource temporarily unavailable)
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 delete posted event 00007F5DB055B210
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream request: “/news/article-1234.1482353?”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream send request handler
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream send request
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream send request body
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 chain writer buf fl:1 s:8243
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 chain writer in: 00000000031BC160
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 writev: 8243 of 8243
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 chain writer out: 0000000000000000
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 event timer del: 1514: 1559039102955
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 event timer add: 1514: 6000000:1559039102959
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 post event 00007F5DB064C210
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 post event 00007F5DB055B210
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 delete posted event 00007F5DB064C210
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream request: “/news/article-1234.1482353?”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream process header
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 malloc: 000000000318A3F0:4096
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 recv: fd:1514 187 of 4096
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy status 400 “400 Bad request”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Cache-Control: no-cache”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Connection: close”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Content-Type: text/html”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header done
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 HTTP/1.1 400 Bad request
Server: nginx/1.10.2
Date: Tue, 28 May 2019 08:45:02 GMT
Content-Type: text/html
Transfer-Encoding: chunked
Connection: keep-alive
Cache-Control: no-cache

There’s obviously a lot of data and it’s not easy to find the relevant part. I try to cherry-pick the relevant lines:

2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Accept-Language: en-US,en;q=0.9,de;q=0.8”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http alloc large header buffer
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 malloc: 00000000031EDD50:8192
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http large header alloc: 00000000031EDD50 8192
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http large header copy: 464
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 SSL_read: 7140
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 SSL_read: -1
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 SSL_get_error: 2
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header: “Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e3d2d2-4567-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7b5f6f548274; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW9829-qn6kGrFjkEQ314I82HLgMX6Siy74BCVpPrOD-XLVNIwC_HX-6fknWkiXxR-Yg; ens_cntpvabo=383; ens_subscrst=subscriber%3BWed%20Jun%2026%202019%2009%3A48%3A49%20GMT%2B0200%20(Mitteleurop%C3%A4ische%20Sommerzeit); _gid=GA1.2.131606941.1558944578; ens_kavz=0986-0050-01-010; _fbc=fb.1.1558951120515.IwAR1vSVauTbRT1sO397XEXVmRHTSbC3dL08dZ9WSMVLGSoS4T9m8QRgHv6Js; p4m_snot=1318; s_vdnum=1559080800290%26vn%3D1; s_dinvisit=true; s_vwnum=1559426400501%26vn%3D7; s_winvisit=true; s_vmnum=1559340000345%26vn%3D56; s_minvisit=true; s_dslv_s=Less%20than%201%20day; ens_ueid_3425441984_513=1559034247693; ens_cntpwmt=5; ens_ueid_624612360_513=1559034320820; POPUPCHE
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http header done

Nginx detected a large HTTP header and allocated a buffer for it.  Especially the “Cookie” header is huge and contains a lot of cookies and their session data.

A bit further down, the same headers are sent to the upstream server (the next hop in the data flow) using the “proxy” module:

2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Accept-Language: en-US,en;q=0.9,de;q=0.8”
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header: “Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e3d2d2-4567-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7b5f6f548274; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW9829-qn6kGrFjkEQ314I82HLgMX6Siy74BCVpPrOD-XLVNIwC_HX-6fknWkiXxR-Yg; ens_cntpvabo=383; ens_subscrst=subscriber%3BWed%20Jun%2026%202019%2009%3A48%3A49%20GMT%2B0200%20(Mitteleurop%C3%A4ische%20Sommerzeit); _gid=GA1.2.131606941.1558944578; ens_kavz=0986-0050-01-010; _fbc=fb.1.1558951120515.IwAR1vSVauTbRT1sO397XEXVmRHTSbC3dL08dZ9WSMVLGSoS4T9m8QRgHv6Js; p4m_snot=1318; s_vdnum=1559080800290%26vn%3D1; s_dinvisit=true; s_vwnum=1559426400501%26vn%3D7; s_winvisit=true; s_vmnum=1559340000345%26vn%3D56; s_minvisit=true; s_dslv_s=Less%20than%201%20day; ens_ueid_3425441984_513=1559034247693; ens_cntpwmt=5; ens_ueid_624612360_513=1559034320820; PO
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy header:
“GET /news/article-1234.1482353 HTTP/1.0

Finally the upstream server returned a HTTP 400 error when the proxied http headers were parsed:

2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http upstream process header
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 malloc: 000000000318A3F0:4096
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 recv: fd:1514 187 of 4096
2019/05/28 10:45:02 [debug] 14311#0: *1706803906 http proxy status 400 “400 Bad request”

By taking a closer look at the “Cookie” header from the http request, the data seems to be cut. It ends with “POPUPCHE” and does not contain a value.

Furthermore the Cookie header was even more cut when the request was forwarded to the upstream server; it ends with just “PO”.

Obviously these request headers are too big to handle for Nginx and they are cut to a default size. The default header size limit in Nginx is 8K.

Adjust Nginx to allow larger http headers

The HTTP protocol itself does not define a size limit of the headers, but for security and performance reasons these limits are (usually) set in the web servers. These default limits can be changed, of course.

In Nginx this default size can be changed using the option “large_client_header_buffers”. You can set this either globally in the “http” context or in a “server” context for a specific vhost. In this example I set a new limit of 64K in the “http” context:

Followed by a Nginx reload, the new http header size limit should be activated.

Testing and failing again

Now that Nginx was told to accept the larger headers, I asked the client to reproduce the error. And the http 400 error occurred again. Once more, I checked the debug logs:

2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http large header alloc: 00000000036E84F0 65536
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http large header copy: 499
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 SSL_read: 7257
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 SSL_read: -1
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 SSL_get_error: 2
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 posix_memalign: 00000000036A2010:4096 @16
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http header: “Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e094fdb-0241-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7bf803883d4c; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW9829-qn6kGrFjkEQ314I82HLgMX6Siy74BCVpPrOD-XLVNIwC_HX-6fknWkiXxR-Yg; ens_cntpvabo=383; ens_subscrst=subscriber%3BWed%20Jun%2026%202019%2009%3A48%3A49%20GMT%2B0200%20(Mitteleurop%C3%A4ische%20Sommerzeit); _gid=GA1.2.131606941.1558944578; ens_kavz=0986-0050-01-010; _fbc=fb.1.1558951120515.IwAR1vSVauTbRT1sO397XEXVmRHTSbC3dL08dZ9WSMVLGSoS4T9m8QRgHv6Js; p4m_snot=1318; s_vdnum=1559080800290%26vn%3D1; s_dinvisit=true; s_vwnum=1559426400501%26vn%3D7; s_winvisit=true; s_vmnum=1559340000345%26vn%3D56; s_minvisit=true; s_dslv_s=Less%20than%201%20day; ens_ueid_3425441984_513=1559034247693; ens_ueid_624612360_513=1559034320820; POPUPCHECK=155911712556
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http header done

This time the received “Cookie” header was complete!

Also the full “Cookie” header was sent to the upstream server:

2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http proxy header: “Cookie: bcjsck=defeb988-4e62-4971-b692-a0cab3e1aa15; bcjsmh=d41d8cd98f00b204e9800998ecf8427e; _ga=GA1.2.121262398.1500964581; conveyVisitorId=783533216391128700; _cb=DVtTO0D1nxaxqltf-; creid=1587323204948210394; ens_subscrptst=registered%3BTue%20Feb%2020%202018%2011%3A42%3A01%20GMT%2B0100%20(CET); _v__chartbeat3=CEFK3zDBkUfmBwsJ9l; _cb_ls=1; ivbsdid={“id”:”qsg6vkb6sb78″}; mbox=PC#9dc594f60e3f4c358006c402a9d0d73e.26_21#1604146991|session#61a773b682474005a1ba24467c023012#1542273057; _fbp=fb.1.1549266199618.647410032; __gads=ID=6456a71ef275ba00:T=1551781894:S=ALNI_MaKQ4DMVT2F6IMzm4G1dOcUA9koOg; ens_c1pid=8e094fdb-0241-4074-abaf-2e6e5dc7c188; cresid_platform1234=cb81a3b283a9d208b04f7bf803883d4c; bclk=3704698032204732; cresid=6a7497a5ab3d809e8fb19644ad92e710; service=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IjlmYzY2Zjg5LTdiM2ItNDBiYy04NDJhLTQzODNjMzZmMDJmYSJ9.eyJzZXJ2aWNlX2lkIjoibnp6IiwibG9naW4iOiJrYXRyaW4uaHV0aEBnbWFpbC5jb20iLCJsYXN0X25hbWUiOiJIdXRoIiwiZmlyc3RfbmFtZSI6IkthdHJpbiIsInNlc3Npb25faWQiOiJhYjU2YTYxMzg3MzYzYzZjNDM0NzIwODgxYzJjOGVkOCJ9.ZpC4f4fDN7yJT-QrsOj7CRFMxmmmZx-J08Vw8qHCpxCMlE5DJ97gn1vPmMomJhdU0JPrkHdJiAP5y-GRPRToz-1RUDhdeTmrZKHI6u9XrNDrDKUzWPxF553w2_O_TfD8ioTwLihn3sHhRpvAS7kLqbJCgMt5n3wB2Jbzz2mCVpfvFpyyMJoVDUTdeQ4Lefti-37wbwFHzZ-idt9rc3vYbK2iw0YTe-s7M3hsNRQ-2wFYSWjC4mAy8qtySa7Jb801eLSEqO2-W3603UkbcvjW9829-qn6kGrFjkEQ314I82HLgMX6Siy74BCVpPrOD-XLVNIwC_HX-6fknWkiXxR-Yg; ens_cntpvabo=383; ens_subscrst=subscriber%3BWed%20Jun%2026%202019%2009%3A48%3A49%20GMT%2B0200%20(Mitteleurop%C3%A4ische%20Sommerzeit); _gid=GA1.2.131606941.1558944578; ens_kavz=0986-0050-01-010; _fbc=fb.1.1558951120515.IwAR1vSVauTbRT1sO397XEXVmRHTSbC3dL08dZ9WSMVLGSoS4T9m8QRgHv6Js; p4m_snot=1318; s_vdnum=1559080800290%26vn%3D1; s_dinvisit=true; s_vwnum=1559426400501%26vn%3D7; s_winvisit=true; s_vmnum=1559340000345%26vn%3D56; s_minvisit=true; s_dslv_s=Less%20than%201%20day; ens_ueid_3425441984_513=1559034247693; ens_ueid_624612360_513=1559034320820; POPUPCHECK=155911

But the upstream server still sent back a 400 error:

2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http upstream process header
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 malloc: 00000000034EB2E0:4096
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 recv: fd:379 187 of 4096
2019/05/28 11:00:57 [debug] 20067#0: *1707128584 http proxy status 400 “400 Bad request”

Why would that be?

When you look at the architecture drawing at the begin, you see that after the Nginx web server, the next hop of the dataflow is HAProxy. And because HAProxy is also (kind of) a HTTP server, there are also some defaults and limits to be considered.

Adjust HAProxy to allow larger http headers

HAProxy has a lot of fine tuning settings. And to allow larger http headers, we need to exactly tune these.

The relevant settings are tune.bufsize and tune.maxrewrite. It’s important to set both of these, as the documentation says:

tune.bufsize sets the buffer size to this size (in bytes). The default value is 16384 and can be changed at build time. […] If HTTP request is larger than (tune.bufsize – tune.maxrewrite), haproxy will return HTTP 400 (Bad Request) error. Similarly if an HTTP response is larger than this size, haproxy will return HTTP 502 (Bad Gateway).

Both of these options need to be set in the “global” section of your HAProxy config:

In this case a buffer size of 64K and a max rewrite size of 16K is defined. Which leaves us with a limit size of 48K.

Let’s see if this is enough for our client.

After reloading HAProxy, the new limits are in place.

Party time

The next request came in shortly and this time the response was a successful HTTP 200:

2019/05/28 11:42:35 [debug] 20067#0: *1708050081 http upstream process header
2019/05/28 11:42:35 [debug] 20067#0: *1708050081 malloc: 00000000031B8E50:4096
2019/05/28 11:42:35 [debug] 20067#0: *1708050081 recv: fd:884 4096 of 4096
2019/05/28 11:42:35 [debug] 20067#0: *1708050081 http proxy status 200 “200 OK”

Finally the 400 errors are gone and it was all due to a larger than usual http request, because of the large http headers (damn cookies!).

If you need to increase the request/header limits, it’s important to do this in the whole chain of dataflow. Every http/application server this request goes through must be checked and if necessary adjusted.

A handy comparison of defaults

To finalize this posts, here are the default values for request/header size limits of some http servers, as of February 2021 (last updated):

HTTP Server	Setting / Option name	Default value
Apache 2.2	LimitRequestFieldSize	8190
Apache 2.4	LimitRequestFieldSize	8190
HAProxy	tune.bufsize / tune.maxrewrite	16384 / half of bufsize
IIS 4.x	MaxClientRequestBuffer	2M
IIS 5.x	MaxClientRequestBuffer	128K
IIS 5.x w Win 2000 SP4	MaxClientRequestBuffer	16K
IIS 6.x and later	MaxRequestBytes	16K
Lighttpd	server.max-request-field-size	none
LiteSpeed	maxReqHeaderSize	16380
Nginx	large_client_header_buffers	4 8k
Node.js < v13.13.0	–max-http-header-size	8KB
Node.js >= v13.13.0	–max-http-header-size	16KB
Tomcat 5.5	maxHttpHeaderSize	4096
Tomcat 6 and later	maxHttpHeaderSize	8192
Wildfly 10 and later	max-header-size	1048576

Meanwhile Geeker’s Digest also published an up to date list of HTTP request header limits.

Add a comment

Show form to leave a comment

Comments (newest first)

Ali from India wrote on May 29th, 2022:

Thanks for detailed explanation. I like who share real outputs and explain each step-by-step. Solved my issue with this!!

Thank you!

---

Ошибка 400 Bad Request возникает, когда сервер не может понять запрос, отправленный клиентом. В вашем случае это может быть связано с тем, что настройки сервера не соответствуют запросу.

Судя по коду из вашего nginx.conf, вы пытаетесь перенаправить HTTP-запросы на HTTPS-порт с помощью rewrite. Однако вместо этого запросы на порт 8080 проксируются на другой сервер.

Для исправления проблемы с ошибкой 400 вам нужно изменить ваш nginx.conf, чтобы он правильно перенаправлял HTTP-запросы на HTTPS-порт.

Примерно так должно выглядеть ваш nginx.conf:

server {
    listen 80;
    server_name example.com;
    return 301 https://$server_name$request_uri;
}

server {
    listen 443 ssl;
    server_name example.com;

    ssl_certificate /etc/letsencrypt/live/example.com/cert.pem;
    ssl_certificate_key /etc/letsencrypt/live/example.com/privkey.pem;

    location / {
        root /var/www/example.com/;
        index index.html;
    }

    location /server/ {
        resolver 00.000.000.00;
        proxy_pass https://00.000.000.00;
    }
}

Этот конфигурационный файл перенаправляет все запросы на порт 80 (HTTP) на порт 443 (HTTPS) с помощью return 301. Затем он обрабатывает запросы на порт 443 (HTTPS), предоставляя файлы из каталога /var/www/example.com/ для пути / и проксируя запросы на путь /server/ на другой сервер.

Убедитесь, что после внесения изменений вы перезапустили сервер NGINX с помощью команды
sudo systemctl restart nginx.