Maxim Dounin
May 08, 2021 01:30PM
Hello!

On Sat, May 08, 2021 at 07:33:07PM +0300, Reinis Rozitis wrote:

> Hello.
> I have a strange issue where for a POST request having any form data Nginx
> after version 1.9.4 doesn't log $ssl_protocol (or any other $ssl_*)
> variable.
>
>
> I have a configured custom accesslog:
>
> log_format main '... $ssl_protocol $ssl_cipher $server_port';
>
> A simple script ( for example from
> https://nodejs.dev/learn/make-an-http-post-request-using-nodejs ) will
> generate following accesslog entry with all the variables being empty:
>
> [08/May/2021:19:11:50 +0300] ... "axios/0.21.1" - - 443
>
>
> The moment you remove the form data everything is being logged:
>
> [08/May/2021:19:10:58 +0300] ... HTTP/1.1" 200 772 "-" "axios/0.21.1"
> TLSv1.2 ECDHE-RSA-AES128-GCM-SHA256 443
>
>
> I tried to debug the requests and see the difference (besides
> Content-Length) but I wasn't able to pinpoint the issue.
> I tried various nodejs libraries ('request' etc) and also native approach -
> all produce same results - empty POST requests are fine, the moment you post
> any form data the $ssl_* become empty.
> I can't reproduce it with curl - tried varios requests with and without
> data, with chunked encoding etc - everything is being logged as expected.
>
>
> One could say that the problem is on the Node side - but what has changed
> between 1.9.4 and 1.9.5 that breaks the logging?
>
> Maybe someone has any suggestions or ideas how to investigate this further?

Thanks for the report, it looks like this change broke things:

changeset: 7738:554c6ae25ffc
user: Ruslan Ermilov <ru@nginx.com>
date: Fri Nov 06 23:44:54 2020 +0300
summary: SSL: fixed non-working SSL shutdown on lingering close.

If the connection is being closed with lingering close, nginx now
shuts down the SSL connection before lingering close, and this
happens before the request is logged. As a result $ssl_*
variables are not available during request logging.

An easy way to reproduce this with arbitrary requests is to use
"lingering_close always;".

The only fix I can think of is to rewrite the lingering close so
it will happen after the request is logged.

--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx mailing list
nginx@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx
Subject Author Posted

$ssl_protocol in nodejs POST requests after 1.9.4

Reinis Rozitis May 08, 2021 12:34PM

Re: $ssl_protocol in nodejs POST requests after 1.9.4

Maxim Dounin May 08, 2021 01:30PM

RE: $ssl_protocol in nodejs POST requests after 1.9.4

Reinis Rozitis May 08, 2021 02:18PM

Re: $ssl_protocol in nodejs POST requests after 1.9.4

Maxim Dounin May 08, 2021 03:46PM

Re: $ssl_protocol in nodejs POST requests after 1.9.4

Maxim Dounin June 01, 2021 10:50AM



Sorry, only registered users may post in this forum.

Click here to login

Online Users

Guests: 269
Record Number of Users: 8 on April 13, 2023
Record Number of Guests: 421 on December 02, 2018
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready