lua-nginx-module icon indicating copy to clipboard operation
lua-nginx-module copied to clipboard

Lua stacktrace error logs creates invalid syslog output

Open wfjsw opened this issue 1 year ago • 0 comments

Debian 12
nginx version: openresty/1.27.1.1
built with OpenSSL 3.0.15 3 Sep 2024
TLS SNI support enabled
configure arguments: --prefix=/usr/local/openresty/nginx --with-cc-opt='-O2 -DNGX_LUA_ABORT_AT_PANIC -I/usr/local/openresty/zlib/include -I/usr/local/openresty/pcre2/include -I/usr/local/openresty/openssl3/include' --add-module=../ngx_devel_kit-0.3.3 --add-module=../echo-nginx-module-0.63 --add-module=../xss-nginx-module-0.06 --add-module=../ngx_coolkit-0.2 --add-module=../set-misc-nginx-module-0.33 --add-module=../form-input-nginx-module-0.12 --add-module=../encrypted-session-nginx-module-0.09 --add-module=../srcache-nginx-module-0.33 --add-module=../ngx_lua-0.10.27 --add-module=../ngx_lua_upstream-0.07 --add-module=../headers-more-nginx-module-0.37 --add-module=../array-var-nginx-module-0.06 --add-module=../memc-nginx-module-0.20 --add-module=../redis2-nginx-module-0.15 --add-module=../redis-nginx-module-0.3.9 --add-module=../ngx_stream_lua-0.0.15 --with-ld-opt='-Wl,-rpath,/usr/local/openresty/luajit/lib -L/usr/local/openresty/zlib/lib -L/usr/local/openresty/pcre2/lib -L/usr/local/openresty/openssl3/lib -Wl,-rpath,/usr/local/openresty/zlib/lib:/usr/local/openresty/pcre2/lib:/usr/local/openresty/openssl3/lib' --with-pcre-jit --with-stream --with-stream_ssl_module --with-stream_ssl_preread_module --with-http_v2_module --with-http_v3_module --without-mail_pop3_module --without-mail_imap_module --without-mail_smtp_module --with-http_stub_status_module --with-http_realip_module --with-http_addition_module --with-http_auth_request_module --with-http_secure_link_module --with-http_random_index_module --with-http_gzip_static_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_mp4_module --with-http_slice_module --with-http_gunzip_module --with-threads --with-compat --with-stream --with-http_ssl_module

The Nginx error logger seems to not expect linebreaks in error log and there is no mechanism in place to properly handle them. On the Lua side of the OpenResty, the main thing that creates a log with linebreaks is the Lua stacktrace. This creates a particular issue when the error log output is directed to a syslog server, the Nginx will write the lines with only 1 syslog header, making the subsequent lines unparseable.

Take this log line for example:

2024/11/16 00:08:28 [error] 143589#143589: *1885879 lua entry thread aborted: runtime error: error loading module '***' from file '/etc/openresty/lualib/test.lua':
        /etc/openresty/lualib/test.lua:28: unexpected symbol near '{'
stack traceback:
coroutine 0:
        [C]: in function 'require'
        /etc/openresty/test.lua:1: in main chunk, client: ***, server: ***, request: "OPTIONS *** HTTP/1.1", host: "***", referrer: "***"

According to the syslog spec, it should write the following thing to socket:

<34>Oct 11 22:14:15 mymachine nginx: 2024/11/16 00:08:28 [error] 143589#143589: *1885879 lua entry thread aborted: runtime error: error loading module '***' from file '/etc/openresty/lualib/test.lua':
<34>Oct 11 22:14:15 mymachine nginx:         /etc/openresty/lualib/test.lua:28: unexpected symbol near '{'
<34>Oct 11 22:14:15 mymachine nginx: stack traceback:
<34>Oct 11 22:14:15 mymachine nginx: coroutine 0:
<34>Oct 11 22:14:15 mymachine nginx:         [C]: in function 'require'
<34>Oct 11 22:14:15 mymachine nginx:         /etc/openresty/test.lua:1: in main chunk, client: ***, server: ***, request: "OPTIONS *** HTTP/1.1", host: "***", referrer: "***"

In reality, this is written:

<34>Oct 11 22:14:15 mymachine nginx: 2024/11/16 00:08:28 [error] 143589#143589: *1885879 lua entry thread aborted: runtime error: error loading module '***' from file '/etc/openresty/lualib/test.lua':
        /etc/openresty/lualib/test.lua:28: unexpected symbol near '{'
stack traceback:
coroutine 0:
        [C]: in function 'require'
        /etc/openresty/test.lua:1: in main chunk, client: ***, server: ***, request: "OPTIONS *** HTTP/1.1", host: "***", referrer: "***"

This could as well be an Nginx issue, but I'm not aware of any multiline error logs produced by vanilla Nginx, so they might not be responsible for this.

See: https://nginx.org/en/docs/syslog.html

wfjsw avatar Nov 18 '24 06:11 wfjsw