Mailing List Archive

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #1 from Andreas Metzler <eximusers@bebt.de> ---
Afaict open_logs() is just too naive compared to what log_write() does.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #2 from Jeremy Harris <jgh146exb@wizmail.org> ---
Created attachment 1382
--> https://bugs.exim.org/attachment.cgi?id=1382&action=edit
possible fix

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #3 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Jeremy Harris from comment #2)
> Created attachment 1382 [details]
> possible fix

Thank you, better but not done. It still fails with
log_file_path = :syslog

( both "syslog : /var/log/exim4/%slog" and "/var/log/exim4/%slog : syslog" seem
to work, though.)

cu Andreas

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

Jeremy Harris <jgh146exb@wizmail.org> changed:

What |Removed |Added
----------------------------------------------------------------------------
Attachment #1382|0 |1
is obsolete| |

--- Comment #4 from Jeremy Harris <jgh146exb@wizmail.org> ---
Created attachment 1383
--> https://bugs.exim.org/attachment.cgi?id=1383&action=edit
expand fix to cover empty elements

Use instead of previous

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #5 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Jeremy Harris from comment #4)
> Created attachment 1383 [details]
> expand fix to cover empty elements
>
> Use instead of previous

Crash is gone, but I only get logging to /var/log/... instead of to both syslog
and /var/log/ with "log_file_path = :syslog".

cu Andreas

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #6 from Jeremy Harris <jgh146exb@wizmail.org> ---
Running one of the testcases, modified to use ":syslog" and with debug, I get:

08:15:01 25984 Writing spool header file:
/home/jgh/git/exim/test/spool//input//hdr.1lfdeX-0006l6-AO
08:15:01 25984 DSN: **** SPOOL_OUT - address: <eximtest@lap.dom.ain> errorsto:
<NULL> orcpt: <NULL> dsn_flags: 0x0
08:15:01 25984 Renaming spool header file:
/home/jgh/git/exim/test/spool//input//1lfdeX-0006l6-AO-H
08:15:01 25984 Size of headers = 328
08:15:01 25984 LOG: MAIN
08:15:01 25984 <= someone@some.domain U=eximtest P=local-smtp S=396
SYSLOG: '2021-05-09 08:15:01 1lfdeX-0006l6-AO <= someone@some.domain U=eximtest
P=local-smtp S=396'


That last is to stderr from the same function that calls syslog(). What do
you get from debug output?

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #7 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Jeremy Harris from comment #6)
> Running one of the testcases, modified to use ":syslog" and with debug, I
> get:
[...]
> SYSLOG: '2021-05-09 08:15:01 1lfdeX-0006l6-AO <= someone@some.domain
> U=eximtest P=local-smtp S=396'

> That last is to stderr from the same function that calls syslog(). What do
> you get from debug output?

I do not get the SYSLOG: ... in the debug log (either with 4.94.2 or
with 4.94.2+taintwarn). Looking at the source I see that it is only emitted
if(f.running_in_test_harness).

The lack of duplicate logging shows up early, the startup message
2021-05-09 11:13:53 exim 4.94.2 daemon started: pid=2321, -q30m, listening for
SMTP on [127.0.0.1]:25 [::1]:25
already only shows up in the mainlog.

I will send you complete debug logs off-bugzilla, in case I miss something I
should have sanitized.

cu Andreas

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #8 from Jeremy Harris <jgh146exb@wizmail.org> ---
There's nothing obviously wrong in the debug output. Unfortunately, it
doesn't show the logging files configuration.

With a minimally hacked source, taking the testsuite-specific diverts out
of the write_syslog() routine in src/log.c I get reasonable-looking lines
appearing in /var/log/maillog which don't appear without that hacking, for
the same testcase, I can only assume that your config is not what you think
or you're not running the same patch I am.

The output from "exim -bP log_file_path" should show what the binary thinks
the config is telling it.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #9 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Jeremy Harris from comment #8)
> There's nothing obviously wrong in the debug output. Unfortunately, it
> doesn't show the logging files configuration.
>
> With a minimally hacked source, taking the testsuite-specific diverts out
> of the write_syslog() routine in src/log.c I get reasonable-looking lines
> appearing in /var/log/maillog which don't appear without that hacking, for
> the same testcase, I can only assume that your config is not what you think
> or you're not running the same patch I am.
>
> The output from "exim -bP log_file_path" should show what the binary thinks
> the config is telling it.

Good evening

/usr/sbin/exim4 -bP log_file_path
log_file_path = :syslog

I am running the current debian package 4.94.2-2 , that is. 4.94.2 with these
patches:

https://salsa.debian.org/exim-team/exim4/-/tree/master/debian/patches

i.e. 4.94.2 + fixes + taintwarn + this patch (donot get mislead by the
filename, it is v2) + localscan-dlopen + minor changes

cu Andreas

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #10 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Andreas Metzler from comment #9)
[...]
> I am running the current debian package 4.94.2-2 , that is. 4.94.2 with
> these patches:
>
> https://salsa.debian.org/exim-team/exim4/-/tree/master/debian/patches
>
> i.e. 4.94.2 + fixes + taintwarn + this patch (donot get mislead by the
> filename, it is v2) + localscan-dlopen + minor changes


... so my log.c is identical what you get by
a) checking out 4.94.2+fixes
b) git merge exim-4.94.2+taintwarn
c) patch -p1 < /tmp/patch2.patch

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

Heiko Schlittermann <hs@schlittermann.de> changed:

What |Removed |Added
----------------------------------------------------------------------------
Assignee|unallocated@exim.org |hs@schlittermann.de
CC| |hs@schlittermann.de

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #11 from Heiko Schlittermann <hs@schlittermann.de> ---
Hi Andreas,

please can you check if the issue goes away once you remove the call to
open_logs() from src/transports/appendfile.c

I did so here (based on the latest commit on exim-4.94.2+taintwarn) and now
logging appendfile problems to main/panic log as well as to syslog works.

It seems that other changes I introduced alongside with inventing that
simple-minded open_logs() already solved the original issue. I'm running the
testsuite now, to check if this partial revert of
235c7030ee9ee1c1aad507786506a470b580bfe2 doesn't break anything else.

--
Heiko

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #12 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Andreas Metzler from comment #10)
[...]
> ... so my log.c is identical what you get by
> a) checking out 4.94.2+fixes
> b) git merge exim-4.94.2+taintwarn
> c) patch -p1 < /tmp/patch2.patch

I think I can see what goes wrong in the patched log.c:

724 set_file_path(BOOL *multiple) ()
[...]
728 const uschar *ss = *log_file_path ? log_file_path : US LOG_FILE_PATH;
729
730 if (*ss)
731 for (logging_mode = 0;
732 s = string_nextinlist(&ss, &sep, log_buffer, LOG_BUFFER_SIZE); )
733 {
[...]
Empty element:
748 else if (*log_file_path && LOG_FILE_PATH[0])
749 {
750 ss = US LOG_FILE_PATH;
751 continue;
752 }

So when the function looks at ":syslog" an empty element is found. The
log_file_path is ignored and the LOG_FILE_PATH compile time setting is parsed
*instead*, ignoring any further settings ("syslog") in log_file_path.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #13 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Heiko Schlittermann from comment #11)
> please can you check if the issue goes away once you remove the call to
> open_logs() from src/transports/appendfile.c
>
> I did so here (based on the latest commit on exim-4.94.2+taintwarn) and now
> logging appendfile problems to main/panic log as well as to syslog works.


If I take taintwarn, without patch2.patch (Attachment 1383 Bug 2733) and set
log_file_path = :syslog
and simply start the daemon I only get the following message in syslog, but not
in the file log.
Mai 13 12:58:00 argenau exim[19370]: 2021-05-13 12:58:00 exim 4.94.2 daemon
started: pid=19370, -q30m, listening for SMTP on [127.0.0.1]:25 [::1]:25

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #14 from Andreas Metzler <eximusers@bebt.de> ---
(In reply to Andreas Metzler from comment #13)
> (In reply to Heiko Schlittermann from comment #11)
> > please can you check if the issue goes away once you remove the call to
> > open_logs() from src/transports/appendfile.c

> > I did so here (based on the latest commit on exim-4.94.2+taintwarn) and now
> > logging appendfile problems to main/panic log as well as to syslog works.
>
>
> If I take taintwarn, without patch2.patch (Attachment 1383 [details] Bug
> 2733) and set
> log_file_path = :syslog
> and simply start the daemon I only get the following message in syslog, but
> not in the file log.
> Mai 13 12:58:00 argenau exim[19370]: 2021-05-13 12:58:00 exim 4.94.2 daemon
> started: pid=19370, -q30m, listening for SMTP on [127.0.0.1]:25 [::1]:25

Heiko, my guess seems to have been correct. My EDITME has
LOG_FILE_PATH=/var/log/exim4/%slog
if I comment this out (i.e. exim logs to spooldir/log unless told otherwise) I
will indeed get the expected duplicate logging with log_file_path = :syslog.

Which fits with my diagnosis in comment #12

748 else if (*log_file_path && LOG_FILE_PATH[0])

is not entered when LOG_FILE_PATH is unset.

cu Andreas

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #15 from Heiko Schlittermann <hs@schlittermann.de> ---
While I believe your observations, I can't reproduce it.

4.94.2-31-503e55a2c is the version I'm running (latest commit on
exim-4.94.2+taintwarn).
LOG_FILE_PATH is set to "/opt/exim/log". `exim -C /dev/null -bP log_file_path`
returns the expected output:

log_file_path = /opt/exim/log/%slog

With the real runtime config I get:

log_file_path = :syslog


Starting Exim `exim -bdf` (or `exim -bd`) writes the startup message to the
syslog *and* to the mainlog.
So, what I'm missing here?

Journal:
Mai 13 19:00:53 x1 exim[29680]: 2021-05-13 19:00:53 [29680] exim
4.94.2-31-503e55a2c daemon started: pid=29680, no queue runs, listening for
SMTP on port 25 (IPv4)

Mainlog:
2021-05-13 19:00:53 [29680] exim 4.94.2-31-503e55a2c daemon started: pid=29680,
no queue runs, listening for SMTP on port 25 (IPv4)

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

--- Comment #16 from Heiko Schlittermann <hs@schlittermann.de> ---
New *inofficial* set of patches:
https://gitea.schlittermann.de/heiko/exim/src/branch/fix-log
These patches are based on exim-4.94.2+taintwarn. You're invited to test in
your environment. (@Andreas: nothing changed since yesterday evening, this
message here is just in case someone is following us.)

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2733

Heiko Schlittermann <hs@schlittermann.de> changed:

What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
Resolution|--- |FIXED

--- Comment #17 from Heiko Schlittermann <hs@schlittermann.de> ---
See 66392b270e3a6c8202e4626d43bbc9b77545ae23 and
e19790f7707cc901435849e78d20f249056c16b5 wich deal with this issue.

These commits are part of the branch exim-4.94.2+taintwarn

I'm not 100% sure if issue happens with taintwarn only, or if it is of general
nature. IMHO, it should do much harm if applied to the the +fixes and master
too.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##