[CritFix] - Fix reported length of logging structure

[AdamMajer]

The logging code contains one place where the apparent size of the logging structure is defined and then it's actually utilized in another place. Re-writes and refactoring this code ended up with these values to not co-relate what was previously there resulting in a stack overwrite in last version or currently in log truncation.

Move assignment of logging structure to the place where it's actually used, reducing future logic de-sync dangers. Also move the g_assert() to the end as it should be a development aid only.

[AdamMajer]

I can open a bug report for this, if necessary. But in currently released version, there is a stack variable overflow because of this disjoint logic that results in crash on start.

2023-11-02 15:21:52 #1(main) <957c11>; main; main: rspamd 3.7.3 is loading configuration, build id: release
(main) lua; lua_cfg_transform.lua:173: group excessb64 has no symbols*** stack smashing detected ***: terminated
Stack trace (most recent call last):
#24   Object "[0xffffffffffffffff]", at 0xffffffffffffffff, in 
#23   Object "/usr/bin/rspamd", at 0xaaaacffad76f, in 
#22   Object "/lib64/libc.so.6", at 0xffffb06cb61f, in __libc_start_main
#21   Object "/lib64/libc.so.6", at 0xffffb06cb54b, in 
#20   Object "/usr/bin/rspamd", at 0xaaaacffacb2b, in 
#19   Object "/usr/bin/rspamd", at 0xaaaacffc103b, in 
#18   Object "/lib64/librspamd-server.so", at 0xffffb0e3c5bf, in rspamd_config_read
#17   Object "/lib64/librspamd-server.so", at 0xffffb0e35107, in rspamd_rcl_maybe_apply_lua_transform
#16   Object "/lib64/liblua5.4.so.5", at 0xffffb0c9431f, in lua_pcallk
#15   Object "/lib64/liblua5.4.so.5", at 0xffffb0cb2697, in 
#14   Object "/lib64/liblua5.4.so.5", at 0xffffb0c8e107, in 
#13   Object "/lib64/liblua5.4.so.5", at 0xffffb0c941f3, in 
#12   Object "/lib64/liblua5.4.so.5", at 0xffffb0ca0d1b, in 
#11   Object "/lib64/liblua5.4.so.5", at 0xffffb0c93713, in 
#10   Object "/lib64/librspamd-server.so", at 0xffffb0fe0863, in 
#9    Object "/lib64/librspamd-server.so", at 0xffffb0f23553, in 
#8    Object "/lib64/librspamd-server.so", at 0xffffb0e8c74b, in rspamd_common_log_function
#7    Object "/lib64/librspamd-server.so", at 0xffffb0e8c553, in rspamd_common_logv
#6    Object "/lib64/librspamd-server.so", at 0xffffb0e8f93b, in rspamd_log_console_log
#5    Object "/lib64/libc.so.6", at 0xffffb07a77b7, in __stack_chk_fail
#4    Object "/lib64/libc.so.6", at 0xffffb07a676f, in __fortify_fail
#3    Object "/lib64/libc.so.6", at 0xffffb071e84b, in 
#2    Object "/lib64/libc.so.6", at 0xffffb06cae07, in abort
#1    Object "/lib64/libc.so.6", at 0xffffb06dfbff, in raise
#0    Object "/lib64/libc.so.6", at 0xffffb072b430, in 
Aborted (Signal sent by tkill() 1 498)
watf? exit

In the master branch, the code was reworked in such a way that this overflow was accidentally fixed, but we now have log truncation instead and console looks like

(normal) <b6fdb9>; main; rspamd_worker_term_handler: terminating after receiving signal Terminated(hs_helper) <b6fdb9>; main; rspamd_worker_term_han
dler: terminating after receiving signal Terminated(normal) <b6fdb9>; main; rspamd_worker_term_handler: terminating after receiving signal Terminated(normal) <b6fdb9>; main; rspamd_worker_term_handler: terminating after receiving signal Terminated(rspamd_proxy) <b6fdb9>; main; rspamd_worker_term_handler: terminating after receiving signal Terminated(normal) <b6fdb9>; main; rspa
md_worker_term_handler: terminating after receiving signal Terminated(main) <b6fdb9>; main; rspamd_term_handler: catch termination signal, waiting for 7 children for 16.00 seconds(controller
) <b6fdb9>; main; rspamd_worker_term_handler: terminating after receiving signal Terminated(controller) rspamd_controller_on_terminate: closing rrd file: /var/lib/rspamd/rspamd.rrd(controlle
r) rspamd_map_backend_dtor: clear shared memory cache for a map in /rhm.378e86c510f040f3859b as backend "https://maps.rspamd.com/rspamd/dmarc_whitelist_new.inc.zst" is closing(controller) rs
pamd_map_backend_dtor: clear shared memory cache for a map in /rhm.1e86cc393b8ecf3c66e1 as backend "https://maps.rspamd.com/rspamd/spf_dkim_whitelist.inc.zst" is closing(controller) rspamd_m
ap_backend_dtor: clear shared memory cache for a map in /rhm.936002066f49390a3abe as backend "https://maps.rspamd.com/rspamd/surbl-whitelist.inc.zst" is closing(controller) rspamd_map_backen
d_dtor: clear shared memory cache for a map in /rhm.adac8b7b183a123e3d9d as backend "http://sa-update.surbl.org/rspamd/surbl-hashbl-map.inc" is closing(controller) rspamd_map_backend_dtor: c
lear shared memory cache for a map in /rhm.1e8b5d61b510ceb197a9 as backend "https://maps.rspamd.com/rspamd/redirectors.inc.zst" is closing(controller) rspamd_map_backend_dtor: clear shared m
emory cache for a map in /rhm.f4102ec3be335300e71c as backend "https://maps.rspamd.com/rspamd/phishing_whitelist.inc.zst" is closing(controller) rspamd_map_backend_dtor: clear shared memory 
cache for a map in /rhm.9b2f1251ead8eb5486d0 as backend "https://maps.rspamd.com/rspamd/redirectors.inc.zst" is closing(controller) rspamd_map_backend_dtor: clear shared memory cache for a m
ap in /rhm.fa2b57c4c7aee3522e20 as backend "https://maps.rspamd.com/freemail/free.txt.zst" is closing(controller) rspamd_map_backend_dtor: clear shared memory cache for a map in /rhm.922305f
d072cec2820e3 as backend "https://maps.rspamd.com/freemail/disposable.txt.zst" is closing(controller) rspamd_map_backend_dtor: clear shared memory cache for a map in /rhm.2a7c0ec3528abd7d90f
d as backend "https://maps.rspamd.com/rspamd/mime_types.inc.zst" is closing(controller) rspamd_map_backend_dtor: clear shared memory cache for a map in /rhm.4cbe84bc84f673518460 as backend "https://maps.rspamd.com/rspamd/mid.inc.zst" is closing==15078==LeakSanitizer has encountered a fatal error.

[vstakhov]

Nice, I'm really curious why no CI test has detected this issue :) However, it seems that we have one now thanks to @fatalbanana

[darix]

it seems you have different versions of fixing this issue now in master and in the 3.7.5 release. master has the patch from this PR.

while 3.7.5 uses c1feeaa and 75ea56d

which solution is to be preferred.

[fatalbanana]

which solution is to be preferred.

Supposing 3.7.5 works you might use that without patches. 3.8.0 will be patched as here.

[darix]

so basically this patch will get reverted and replaced with your 2 patches?

[fatalbanana]

so basically this patch will get reverted and replaced with your 2 patches?

no, more like the inverse (my commits are in the old branch, this is the forward-looking branch).

maybe yes depending on the context? more likely no...