﻿id	summary	reporter	owner	description	type	status	priority	milestone	component	version	resolution	keywords	cc	uname	nginx_version
1815	Debug log of response is garbled in journald	kosmas.valianos@…		"It is quite easy to reproduce. In your nginx.conf set the ''error_log'' to ''stdout''. Create a body handler so that you can send your own response to an HTTP request. Do a curl or something to trigger your response. In the logs to stdout you will nicely see:
{{{
2019/07/17 08:54:38 [debug] 18863#18863: *1 http request body content length filter
2019/07/17 08:54:38 [debug] 18863#18863: *1 lua capture header filter, uri ""/url_access/remove_all""
2019/07/17 08:54:38 [debug] 18863#18863: *1 HTTP/1.1 200 OK
Server: nginx
Date: Wed, 17 Jul 2019 08:54:38 GMT
Content-Length: 128
Connection: keep-alive
X-Nginx-Module: url_access

2019/07/17 08:54:38 [debug] 18863#18863: *1 write new buf t:1 f:0 000055FCB4E0D2B0, pos 000055FCB4E0D2B0, size: 144 file: 0, size: 0
2019/07/17 08:54:38 [debug] 18863#18863: *1 http write filter: l:0 f:0 s:144
2019/07/17 08:54:38 [debug] 18863#18863: *1 http output filter ""/url_access/remove_all?""
2019/07/17 08:54:38 [debug] 18863#18863: *1 http copy filter: ""/url_access/remove_all?""
2019/07/17 08:54:38 [debug] 18863#18863: *1 lua capture body filter, uri ""/url_access/remove_all""
2019/07/17 08:54:38 [debug] 18863#18863: *1 http postpone filter ""/url_access/remove_all?"" 00007FFE03A91AD0
2019/07/17 08:54:38 [debug] 18863#18863: *1 write old buf t:1 f:0 000055FCB4E0D2B0, pos 000055FCB4E0D2B0, size: 144 file: 0, size: 0
2019/07/17 08:54:38 [debug] 18863#18863: *1 write new buf t:0 f:0 00007FFE03A91B50, pos 00007FFE03A91B50, size: 128 file: 0, size: 0
2019/07/17 08:54:38 [debug] 18863#18863: *1 http write filter: l:1 f:0 s:272
2019/07/17 08:54:38 [debug] 18863#18863: *1 http write filter limit 0
2019/07/17 08:54:38 [debug] 18863#18863: *1 writev: 272 of 272
2019/07/17 08:54:38 [debug] 18863#18863: *1 http write filter 0000000000000000
2019/07/17 08:54:38 [debug] 18863#18863: *1 http copy filter: 0 ""/url_access/remove_all?""
2019/07/17 08:54:38 [debug] 18863#18863: *1 http finalize request: 0, ""/url_access/remove_all?"" a:1, c:2
2019/07/17 08:54:38 [debug] 18863#18863: *1 http request count:2 blk:0
2019/07/17 08:54:38 [debug] 18863#18863: *1 http finalize request: -4, ""/url_access/remove_all?"" a:1, c:1
2019/07/17 08:54:38 [debug] 18863#18863: *1 set http keepalive handler
2019/07/17 08:54:38 [debug] 18863#18863: *1 http close request
2019/07/17 08:54:38 [debug] 18863#18863: *1 http log handler
}}}

Change now your nginx.conf to use journald. I use ''error_log syslog:server=unix:/dev/log,nohostname debug;''. Do the same thing to trigger your response. Check journald logs and you will see garbled output instead:

{{{
Jul 17 08:52:44 envy-172-17-146-2.devops nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http request body content length filter
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 lua capture header filter, uri ""/url_access/remove_all""
nginx[12890]: [184B blob data]
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 write new buf t:1 f:0 00005571CAEA22B0, pos 00005571CAEA22B0, size: 144 file: 0, size: 0
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http write filter: l:0 f:0 s:144
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http output filter ""/url_access/remove_all?""
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http copy filter: ""/url_access/remove_all?""
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 lua capture body filter, uri ""/url_access/remove_all""
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http postpone filter ""/url_access/remove_all?"" 00007FFE0A649170
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 write old buf t:1 f:0 00005571CAEA22B0, pos 00005571CAEA22B0, size: 144 file: 0, size: 0
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 write new buf t:0 f:0 00007FFE0A6491F0, pos 00007FFE0A6491F0, size: 128 file: 0, size: 0
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http write filter: l:1 f:0 s:272
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http write filter limit 0
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 writev: 272 of 272
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http write filter 0000000000000000
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http copy filter: 0 ""/url_access/remove_all?""
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http finalize request: 0, ""/url_access/remove_all?"" a:1, c:2
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http request count:2 blk:0
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http finalize request: -4, ""/url_access/remove_all?"" a:1, c:1
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 set http keepalive handler
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http close request
nginx[12890]: 2019/07/17 08:52:44 [debug] 12890#12890: *2 http log handler
}}}

Notice it now shows '''nginx[12890]: [184B blob data]''' instead of the headers etc like above in the stdout case

"	defect	closed	minor		nginx-core	1.16.x	invalid	journald, stdout		Linux envy-172-17-146-2.devops 4.15.0-54-generic #58-Ubuntu SMP Mon Jun 24 10:55:24 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux	"nginx version: nginx/1.16.0
built by gcc 8.3.0 (Ubuntu 8.3.0-6ubuntu1~18.04.1) 
built with OpenSSL 1.1.1  11 Sep 2018
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -Wall -Wextra -fshort-enums -fPIE -fstack-protector-all -fstack-clash-protection -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security -std=gnu11 --param=ssp-buffer-size=4 -mtune=intel -O3 -fno-omit-frame-pointer -flto -DNDEBUG' --with-ld-opt='-Wl,-z,now -Wl,-z,relro -Wl,-Bsymbolic-functions -pie' --add-module=ngx-devel-kit --add-module=lua-nginx-module --with-threads --add-module=../url_access --without-http_gzip_module --with-http_ssl_module --with-http_auth_request_module --with-ipv6 --with-debug --prefix=/usr --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/run/nginx.pid --with-http_v2_module"
