Since todays update of logcheck I get every message twice,
and the
first entry is:
2025-05-14T19:02:04.733378+02:00 twentytwo exim[42129]: 2025-05-14 19:02:04 1uFFUa-00000000AxR-2z0z failed to write to main log: length=98 result=-1 errno=9 (Bad file descriptor)
2025-05-14T19:02:04.735285+02:00 twentytwo exim[42129]: write failed on panic log: length=123 result=-1 errno=9 (Bad file descriptor)
Since exim (also in conjunction with previous logcheck) works fine
However, I have no idea where to look for this problem, but I can most certainly provide more information, please tell me what you need.
Indeed, that looks unusual. I did find one old report on the debian-
user list that's similar, but was ultimately unsolved[0].
If you're getting two duplicate emails, that indicates logcheck is
running from both the crontab and new systemd timer. In that case, can
you share the contents of /etc/cron.d/logcheck? If you had locally
modified that file, it might not have been properly updated to not run
in a systemd environment.
Richard provided several good things to check that will help track
down the root cause of this issue.
Hello Richard,
Am Wed, May 14, 2025 at 10:55:48PM +0100 schrieb Richard Lewis:
On Wed, 14 May 2025 at 20:36, Helge Kreutzmann <debian@helgefjell.de> wrote:
Since todays update of logcheck I get every message twice,
does message mean every email, email from logcheck, or line in the
logceck report?
Every e-mail comes twice. But at different times, i.e. it take a while
until the 2nd e-mail comes. In my sample the first one comes 2 minutes
past the hour, the 2nd one arrives 7 - 17 minutes later.
Otherwise the e-mails look the same (except the deilvery date).
is this perhaps because logcheck is reporting messages that are in the journal and rsyslog? (it should!)
Maybe.
2025-05-14T19:02:04.733378+02:00 twentytwo exim[42129]: 2025-05-14 19:02:04 1uFFUa-00000000AxR-2z0z failed to write to main log: length=98 result=-1 errno=9 (Bad file descriptor)
2025-05-14T19:02:04.735285+02:00 twentytwo exim[42129]: write failed on panic log: length=123 result=-1 errno=9 (Bad file descriptor)
Since exim (also in conjunction with previous logcheck) works fine
this is exim saying that it was unable to write to
/var/log/exim4/paniclog and failing - this very much suggests exim is
not working fine
if you are getting an emial from logcheck then that suggests logcheck
is doing it's job and showing an issue.
I can downgrade logcheck to see if this goes away as well. But in the
exim logs themselves I could not see any issue, also there is more
than sufficient space on all relevant partitions.
what are the permissions on /var/log/exim4/ and
drwxr-s--- 2 Debian-exim adm 4096 15. Mai 19:40 /var/log/exim4/
is anything in paniclog?There is no such file on my system.
what lines are in the journal when logcheck runs?
Well, I see the following:
Mai 15 20:02:01 twentytwo CRON[18514]: pam_unix(cron:session): session opened for user logcheck(uid=113) by logcheck(uid=0)
Mai 15 20:02:01 twentytwo systemd[1]: Starting logcheck.service - logcheck... Mai 15 20:02:01 twentytwo CRON[18517]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
Mai 15 20:02:01 twentytwo CRON[18514]: pam_unix(cron:session): session closed for user logcheck
Mai 15 20:02:08 twentytwo systemd[1]: logcheck.service: Deactivated successfully.
Mai 15 20:02:08 twentytwo systemd[1]: Finished logcheck.service - logcheck. Mai 15 20:02:08 twentytwo systemd[1]: logcheck.service: Consumed 7.038s CPU time, 249.2M memory peak.
But I'm no journal expert, I primarily look at the classic logs.
what happens if you run logcheck manually? with the -d option?
I'll check that later.
what is in logcheck.conf?
The non empty/non comment lines are:
REPORTLEVEL="server"
SENDMAILTO="logcheck"
On Thu, 15 May 2025 at 19:58, Helge Kreutzmann <debian@helgefjell.de> wrote:
Am Wed, May 14, 2025 at 10:55:48PM +0100 schrieb Richard Lewis:
On Wed, 14 May 2025 at 20:36, Helge Kreutzmann <debian@helgefjell.de> wrote:
Since todays update of logcheck I get every message twice,
does message mean every email, email from logcheck, or line in the logceck report?
Every e-mail comes twice. But at different times, i.e. it take a while until the 2nd e-mail comes. In my sample the first one comes 2 minutes
past the hour, the 2nd one arrives 7 - 17 minutes later.
this does sound like both the cron and journal are running, which
shouldnt happen
what is the output of
systemctl list-timers --all logcheck
what are the permissions on /var/log/exim4/ and
drwxr-s--- 2 Debian-exim adm 4096 15. Mai 19:40 /var/log/exim4/
is anything in paniclog?There is no such file on my system.
permissions look fine - is the logcheck user in the adm group? (grep
logcheck /etc/group )
what is in exim log (/var/log/exim4/mainlog and
/var/log/exim4/rejectlog) for the mail?
what lines are in the journal when logcheck runs?
Well, I see the following:
Mai 15 20:02:01 twentytwo CRON[18514]: pam_unix(cron:session): session opened for user logcheck(uid=113) by logcheck(uid=0)
Mai 15 20:02:01 twentytwo systemd[1]: Starting logcheck.service - logcheck...
Mai 15 20:02:01 twentytwo CRON[18517]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
Mai 15 20:02:01 twentytwo CRON[18514]: pam_unix(cron:session): session closed for user logcheck
Mai 15 20:02:08 twentytwo systemd[1]: logcheck.service: Deactivated successfully.
Mai 15 20:02:08 twentytwo systemd[1]: Finished logcheck.service - logcheck. Mai 15 20:02:08 twentytwo systemd[1]: logcheck.service: Consumed 7.038s CPU time, 249.2M memory peak.
But I'm no journal expert, I primarily look at the classic logs.
this looks ok to me, i think: looks like the cron did nothing but the
timer ran (just check: this should say systemd:
if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then
echo "cron" else echo "systemd"; fi
what about at the time of the second mail?
what happens if you run logcheck manually? with the -d option?
it's especially the part where it sends the email that might help
what is in logcheck.conf?
The non empty/non comment lines are:
REPORTLEVEL="server"
SENDMAILTO="logcheck"
looks fine - does sending a mail to the logcheck user work? what is
grep logcheck /etc/aliases
Hello Richard,
first of all, to test other configuration, I downgraded logcheck to
the previous version - now everything is back to normal. So this is not
an exim issue or so, but is clearly caused by the updated package.
(Logcheck
is running on this machines for many years).
On Fri, 16 May 2025, 17:29 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Hello Richard,
first of all, to test other configuration, I downgraded logcheck to
the previous version - now everything is back to normal. So this is not
an exim issue or so, but is clearly caused by the updated package. (Logcheck
is running on this machines for many years).
thanks - all the other lines looked ok, although am confused by the exim output --- my guess is that this is an issue with systemd units exim. i didnt think this would affect the non-hardened unit, but:
can you edit the logcheck script, and add a "sleep 30s" to the "end' ,
after the point the email is sent -- make sure to pick a point that will actually be run, i cant look right now, but search for where mime-construct is used. i think this may work --
i think that what is happening is: logcheck itself is ok, it makes the report and hands it to exim corrextly. but the systemd unit is shut down "too soon", while exim has taken in the mail - exim thinks something
failed, tries to write to paniclog but cannot (i dont know why, but i
suppose system closes all file descriptors.or.something). somehow exim retries later and you get a duplicate delivery --.actually you could
check: is the mail id the same?. and if you run mailq between running logcheck and getting the 2nd mail, do you see a frozen/deferred message
Hello Richard,
Am Fri, May 16, 2025 at 06:02:55PM +0100 schrieb Richard Lewis:
On Fri, 16 May 2025, 17:29 Helge Kreutzmann, <debian@helgefjell.de>wrote:
Hello Richard,
first of all, to test other configuration, I downgraded logcheck to
the previous version - now everything is back to normal. So this is not an exim issue or so, but is clearly caused by the updated package. (Logcheck
is running on this machines for many years).
thanks - all the other lines looked ok, although am confused by the exim output --- my guess is that this is an issue with systemd units exim. i didnt think this would affect the non-hardened unit, but:
can you edit the logcheck script, and add a "sleep 30s" to the "end' , after the point the email is sent -- make sure to pick a point that will actually be run, i cant look right now, but search for wheremime-construct
is used. i think this may work --
I'm not sure I understand what I should do, sorry.
What exact change *in logcheck* could have triggered this?
anythin *in logcheck* I can (temporarily) disable, like bisecting the difference between the previous version and the current one?
the hard freeze now[1] …
On Fri, 16 May 2025, 18:40 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Am Fri, May 16, 2025 at 06:02:55PM +0100 schrieb Richard Lewis:
On Fri, 16 May 2025, 17:29 Helge Kreutzmann, <debian@helgefjell.de>wrote:
Hello Richard,
first of all, to test other configuration, I downgraded logcheck to
the previous version - now everything is back to normal. So this is not an exim issue or so, but is clearly caused by the updated package. (Logcheck
is running on this machines for many years).
thanks - all the other lines looked ok, although am confused by the exim output --- my guess is that this is an issue with systemd units exim. i didnt think this would affect the non-hardened unit, but:
can you edit the logcheck script, and add a "sleep 30s" to the "end' , after the point the email is sent -- make sure to pick a point that will actually be run, i cant look right now, but search for wheremime-construct
is used. i think this may work --
I'm not sure I understand what I should do, sorry.
https://salsa.debian.org/debian/logcheck/-/blob/debian/sid/src/logcheck?ref_type=heads#L328
add a new line with a " sleep 30 " before the return (and after the call to mime-construct (30 seconds is way too long - probably 10s is enough!)
What exact change *in logcheck* could have triggered this?
the use of a systemd timer
Is there
anythin *in logcheck* I can (temporarily) disable, like bisecting the difference between the previous version and the current one?
you could also try and confirm it works if systemd is not used
systemctl disable logcheck.timer
edit the cron.d and remove the code that disables it - logcheck will then
run from cron
If not, maybe it is better to return to the previous one, as we are in
the hard freeze now[1] …
or, if the fix can be found it can be added to trixie - but we need to confirm the issue and fix first.
Am Fri, May 16, 2025 at 06:58:44PM +0100 schrieb Richard Lewis:
https://salsa.debian.org/debian/logcheck/-/blob/debian/sid/src/logcheck?ref_type=heads#L328
add a new line with a " sleep 30 " before the return (and after the call to mime-construct (30 seconds is way too long - probably 10s is enough!)
Ok, I added it. So I can report tomorrow what (if) changed.
Hello Richard,
Am Fri, May 16, 2025 at 06:35:14PM +0000 schrieb Helge Kreutzmann:
Am Fri, May 16, 2025 at 06:58:44PM +0100 schrieb Richard Lewis:
https://salsa.debian.org/debian/logcheck/-/blob/debian/sid/src/logcheck?ref_type=heads#L328
call toadd a new line with a " sleep 30 " before the return (and after the
mime-construct (30 seconds is way too long - probably 10s is enough!)
Ok, I added it. So I can report tomorrow what (if) changed.
I can see only a slight change. The exim error is the same, and two mails arrive, one shortly after the hour, but the 2nd one always 24 minutes later (before this, the 2nd mail arrived at a non deterministic time).
Does this help you?
Should I now undo this change and go for the 2nd change?
On Sat, 17 May 2025, 09:30 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Am Fri, May 16, 2025 at 06:35:14PM +0000 schrieb Helge Kreutzmann:
Am Fri, May 16, 2025 at 06:58:44PM +0100 schrieb Richard Lewis:
https://salsa.debian.org/debian/logcheck/-/blob/debian/sid/src/logcheck?ref_type=heads#L328
call toadd a new line with a " sleep 30 " before the return (and after the
mime-construct (30 seconds is way too long - probably 10s is enough!)
Ok, I added it. So I can report tomorrow what (if) changed.
I can see only a slight change. The exim error is the same, and two mails arrive, one shortly after the hour, but the 2nd one always 24 minutes later (before this, the 2nd mail arrived at a non deterministic time).
Does this help you?
hmm... not what i was expecting!
what happens if you run mailq between the 2 emails arriving - is there perhaps something frozen?
what is in the exim mainlog for the 2nd email?
Should I now undo this change and go for the 2nd change?
i think that would at least confirm if this is systemd+exim-related in the way i suspect
Hello Richard,
Am Sat, May 17, 2025 at 11:12:05AM +0100 schrieb Richard Lewis:
On Sat, 17 May 2025, 09:30 Helge Kreutzmann, <debian@helgefjell.de>wrote:
Am Fri, May 16, 2025 at 06:35:14PM +0000 schrieb Helge Kreutzmann:
Am Fri, May 16, 2025 at 06:58:44PM +0100 schrieb Richard Lewis:
https://salsa.debian.org/debian/logcheck/-/blob/debian/sid/src/logcheck?ref_type=heads#L328
enough!)call toadd a new line with a " sleep 30 " before the return (and after the
mime-construct (30 seconds is way too long - probably 10s is
Ok, I added it. So I can report tomorrow what (if) changed.
mailsI can see only a slight change. The exim error is the same, and two
laterarrive, one shortly after the hour, but the 2nd one always 24 minutes
(before this, the 2nd mail arrived at a non deterministic time).
Does this help you?
hmm... not what i was expecting!
what happens if you run mailq between the 2 emails arriving - is there perhaps something frozen?
For the next one:
root@twentytwo:~# mailq
13m 3.0K 1uGEMm-00000000KGp-1rQA <logcheck@twentytwo.helgefjell.de>
logcheck@twentytwo.helgefjell.de
what is in the exim mainlog for the 2nd email?
For the previous run:
2025-05-17 11:10:01 1uGDYP-00000000It2-0waZ <=
kreutzmannhelge@helgefjell.de H=(twentytwo.helgefjell.de) [::1] P=esmtp S=6850 id=courier.00000000682850E3.000D35BC@mail.helgefjell.de
2025-05-17 11:10:02 1uGDYP-00000000It2-0waZ => helge <helge@localhost> R=procmail T=procmail_pipe
H=(twentytwo.helgefjell.de) [::1] P=esmtp S=7008 id= courier.00000000682850E3.000D35C4@mail.helgefjell.de
2025-05-17 11:10:03 1uGDYP-00000000It2-1FK6 => helge <helge@localhost>
2025-05-17 11:10:03 1uGDYP-00000000It2-1FK6 Completed
2025-05-17 11:26:45 1uGDQi-00000000Ign-2
In /etc/exim4 three files mention procmail:
exim4-config: /etc/exim4/conf.d/transport/30_exim4-config_procmail_pipe >exim4-config: /etc/exim4/conf.d/router/700_exim4-config_procmail >exim4-config: /etc/exim4/exim4.conf.template
But I never edited them directly, only via Debconf (probably when I
installed the machine.
On Sat, May 17, 2025 at 01:44:57PM +0000, Helge Kreutzmann wrote:
In /etc/exim4 three files mention procmail:
exim4-config: /etc/exim4/conf.d/transport/30_exim4-config_procmail_pipe exim4-config: /etc/exim4/conf.d/router/700_exim4-config_procmail exim4-config: /etc/exim4/exim4.conf.template
But I never edited them directly, only via Debconf (probably when I installed the machine.
If you don't use procmail, you should deinstall it. Exim can deliver by itself.
I have had much fun with sending e-mail from a systemd unit as well, but
that systemd unit is rather verbose and limited. I ended up using a helper program to deliver mail and not calling /usr/lib/sendmail any more. See:
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/aide-common.dailyaidecheck.service
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/aide-common.dailyaidecheck.timer
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/bin/dailyaidecheck
That was a pretty stiff amount of work.
My first guess is that the suid bit does not work when /usr/lib/sendmail is invoked from the systemd unit, and running as logcheck exim can indeed not
do anything.
My second guess is that for some reason Helge's system indeed runs
logcheck's classical cron job AND the new systemd timer, and the systemd timer version shows the issue in question. I'd go ahead and debug why logcheck's classical cron job doesn't get disabled on Helge's system.
Am Sat, May 17, 2025 at 05:44:03PM +0200 schrieb Marc Haber:
On Sat, May 17, 2025 at 01:44:57PM +0000, Helge Kreutzmann wrote:
In /etc/exim4 three files mention procmail:
exim4-config: /etc/exim4/conf.d/transport/30_exim4-config_procmail_pipe exim4-config: /etc/exim4/conf.d/router/700_exim4-config_procmail exim4-config: /etc/exim4/exim4.conf.template
But I never edited them directly, only via Debconf (probably when I installed the machine.
If you don't use procmail, you should deinstall it. Exim can deliver by itself.
I use procmail on several machines, but right, on this one it is not
(much) used. I just wonder - is procmail incompatible with the updated logcheck?
I have had much fun with sending e-mail from a systemd unit as well, but that systemd unit is rather verbose and limited. I ended up using a helper program to deliver mail and not calling /usr/lib/sendmail any more. See:
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/aide-common.dailyaidecheck.service
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/bin/dailyaidecheck
That was a pretty stiff amount of work.
My first guess is that the suid bit does not work when /usr/lib/sendmail is invoked from the systemd unit, and running as logcheck exim can indeed not do anything.
My second guess is that for some reason Helge's system indeed runs logcheck's classical cron job AND the new systemd timer, and the systemd timer version shows the issue in question. I'd go ahead and debug why logcheck's classical cron job doesn't get disabled on Helge's system.
Before the update I get mails with the subject:
Reboot: twentytwo.helgefjell.de 2025-05-16 15:54 +0200 System Events
After the reboot, now mails with this subject are sent; however, the
content is there (i.e. the filtered logs from the reboot are sent).
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
So the cron commands changed during the update.
Should I revert this and look how it behaves?
On Sat, 17 May 2025 at 17:14, Helge Kreutzmann <debian@helgefjell.de> wrote:
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
So the cron commands changed during the update.
yes - the cron job is still running, but only if you are not booted
under systemd
Should I revert this and look how it behaves?
you could try - i predict you will get then get 3 emails: one from
cron, and the same 2 from the timer
On Sun, 18 May 2025, 12:37 Helge Kreutzmann, <debian@helgefjell.de> wrote:
root@twentytwo:~# cat /etc/cron.d/logcheck
# /etc/cron.d/logcheck: crontab entries for the logcheck package
# These do nothing under systemd because the systemd timer will take precedence
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin MAILTO=root
@reboot logcheck if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck -R; fi
#2 * * * * logcheck if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi
2 * * * * logcheck if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi
And now I get *one* e-mail again. The first had the exim error still,
but the second did not.
makes sense -- there is a lag as then failed weite to paniclog on run N is reported by logcheck in run N+1
is this with the systemd unit enabled or disabled?
On Sun, 18 May 2025, 14:14 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Am Sun, May 18, 2025 at 01:18:57PM +0100 schrieb Richard Lewis:
On Sun, 18 May 2025, 12:37 Helge Kreutzmann, <debian@helgefjell.de>wrote:
root@twentytwo:~# cat /etc/cron.d/logcheck
# /etc/cron.d/logcheck: crontab entries for the logcheck package
# These do nothing under systemd because the systemd timer will take precedence
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin MAILTO=root
-n10@reboot logcheck if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck -R; fi
#2 * * * * logcheck if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi
2 * * * * logcheck if [ -x /usr/sbin/logcheck ]; then nice
/usr/sbin/logcheck; fi
And now I get *one* e-mail again. The first had the exim error still, but the second did not.
makes sense -- there is a lag as then failed weite to paniclog on run Nis
reported by logcheck in run N+1
Also the 3rd e-mail no longer had the exim entry.
Looks to me as if this was the culprit.
is this with the systemd unit enabled or disabled?
I did not change anything beyond this.
root@twentytwo:~# systemctl status logcheck
◈ logcheck.service - logcheck
Loaded: loaded (/usr/lib/systemd/system/logcheck.service; static)
Active: inactive (dead) since Sun 2025-05-18 15:02:09 CEST; 11min ago
Invocation: deaadb792c564047a561772068245285
TriggeredBy: • logcheck.timer
Docs: man:logcheck(8)
Process: 2038900 ExecStart=/usr/sbin/logcheck (code=exited, status=0/SUCCESS)
Main PID: 2038900 (code=exited, status=0/SUCCESS)
Mem peak: 222.8M
CPU: 3.534s
Mai 18 15:02:01 twentytwo systemd[1]: Starting logcheck.service - logcheck...
Mai 18 15:02:09 twentytwo systemd[1]: logcheck.service: Deactivated successfully.
Mai 18 15:02:09 twentytwo systemd[1]: Finished logcheck.service - logcheck. Mai 18 15:02:09 twentytwo systemd[1]: logcheck.service: Consumed 3.534s
CPU time, 222.8M memory peak.
so you've now got
- cron is running logcheck
- systemd is also running logcheck
only one of them sends an email
no other errors
no other messages in the mailq?
i can only guess that the email comes from cron, and system's email is now being silently lost.
can you check this -- if you add a -R to the cron.d line so it is
... nice -n10 /usr/sbin/logcheck -R; ....
then any emails from cron will have "Reboot" in the subject, and any email from systemd will not, that would be helpful.
(youll presumably now only get a logcheck email if there is something in
the log to report, i usually do "logger test" to make sure that happens)
On Sun, 18 May 2025, 14:28 Richard Lewis, < richard.lewis.debian@googlemail.com> wrote:
On Sun, 18 May 2025, 14:14 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Am Sun, May 18, 2025 at 01:18:57PM +0100 schrieb Richard Lewis:so you've now got
On Sun, 18 May 2025, 12:37 Helge Kreutzmann, <debian@helgefjell.de>wrote:
- cron is running logcheck
- systemd is also running logcheck
only one of them sends an email
no other errors
no other messages in the mailq?
i can only guess that the email comes from cron, and system's email is now being silently lost.
can you check this -- if you add a -R to the cron.d line so it is
... nice -n10 /usr/sbin/logcheck -R; ....
then any emails from cron will have "Reboot" in the subject, and any email from systemd will not, that would be helpful.
(youll presumably now only get a logcheck email if there is something in the log to report, i usually do "logger test" to make sure that happens)
stuud me -- you wont get 2 emails because whoever runs second may not find any new messages to report. and in fact if both cron and systemd are
running at the same time onenof them should fail as it cant take the lock.
so you cant ever get duplicate reports from having cron and systemd
running, so that was never the cause.
I use procmail on several machines, but right, on this one it is not
(much) used. I just wonder - is procmail incompatible with the updated >logcheck?
Before the update I get mails with the subject:
Reboot: twentytwo.helgefjell.de 2025-05-16 15:54 +0200 System Events
After the reboot, now mails with this subject are sent; however, the
content is there (i.e. the filtered logs from the reboot are sent).
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
On Sat, May 17, 2025 at 04:14:34PM +0000, Helge Kreutzmann wrote:
Before the update I get mails with the subject:
Reboot: twentytwo.helgefjell.de 2025-05-16 15:54 +0200 System Events
After the reboot, now mails with this subject are sent; however, the content is there (i.e. the filtered logs from the reboot are sent).
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
I guess one of the messages come from the old cron job which might not be disabled properly, and the other one from the new systemd timer.
On Sun, 18 May 2025, 18:02 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Hello Richard,
Am Sun, May 18, 2025 at 05:41:49PM +0100 schrieb Richard Lewis:
On Sun, 18 May 2025, 17:22 Helge Kreutzmann, <debian@helgefjell.de>wrote:
Yes, now the subject is Reboot:
I dont't get any e-mails without the Reboot form this logcheck
anymore.
So this would mean (only) cron is running, correct?
yes, i think so. it would help to check that if you comment out the cron line nothing different happens, ie you would then get no mails at all?
I just switched to:
@reboot logcheck if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck -R; fi
#2 * * * * logcheck if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi
#2 * * * * logcheck if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck -R; fi
i think what i need to know is - how do i configure exim to match your set up. .probably thay is just what procmail package to install, and any
settings for that? (i know nothing about procmail)
im starting in a systemd-nspawn container and am not seeing the issue yet)
Hello Richard,
Am Sun, May 18, 2025 at 07:12:15PM +0100 schrieb Richard Lewis:
i think what i need to know is - how do i configure exim to match your set up. .probably thay is just what procmail package to install, and any settings for that? (i know nothing about procmail)
im starting in a systemd-nspawn container and am not seeing the issue yet)
I cannot tell you how I installed it initially. I started with Debian
around 2000, and the systems evolved, i.e. when installing a new
machine I usually copied over important configuration files.
I noticed that exim contains some rules regarding procmail, but I'm
sure that I did not touch them. I have no idea how to configure exim
except by Debconf.
The procmail recipie which is in place is neglible, so I just
deinstalled procmail.
Let's see the next run …
Per advice of Richard, I just disabled cron, so let's see if the
systemd timer is sending anything.
Am Sat, May 17, 2025 at 05:44:03PM +0200 schrieb Marc Haber:
On Sat, May 17, 2025 at 01:44:57PM +0000, Helge Kreutzmann wrote:
In /etc/exim4 three files mention procmail:
exim4-config: /etc/exim4/conf.d/transport/30_exim4-config_procmail_pipe
exim4-config: /etc/exim4/conf.d/router/700_exim4-config_procmail
exim4-config: /etc/exim4/exim4.conf.template
But I never edited them directly, only via Debconf (probably when I
installed the machine.
If you don't use procmail, you should deinstall it. Exim can deliver by
itself.
I use procmail on several machines, but right, on this one it is not
(much) used. I just wonder - is procmail incompatible with the updated >logcheck?
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
So the cron commands changed during the update.
file /run/systemd/system:
/run/systemd/system: directory
There is a known 'incompatibility' between systemd and exim that both >upstreams have explicitly declined to address - but it's
not clear (to me anyway) why you are hitting this -- ive been using
systemd and logcheck (and several other local email-sending units) for
over
a year with hardening and (after much pain) it now works for me - i
get an email every single day from a shell script in a systemd unit.
but i dont use procmail so it may well be the difference.
I have had much fun with sending e-mail from a systemd unit as well, but >> > that systemd unit is rather verbose and limited. I ended up using a helper >> > program to deliver mail and not calling /usr/lib/sendmail any more. See: >> >
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/aide-common.dailyaidecheck.service
this is interesting - i found i needed to have slightly different
settings. but in debian's logcheck unit there is no settings for any >capabilities.
https://salsa.debian.org/debian/aide/-/blob/debian/latest/debian/bin/dailyaidecheck
i think this uses s-nail whereas logcheck uses mime-construct -- does
s-nail perhaps block until the mail is 'delivered'? or use smtp?
My first guess is that the suid bit does not work when /usr/lib/sendmail is
invoked from the systemd unit, and running as logcheck exim can indeed not >> > do anything.
my understanding is that systemd assumes that all processes started by
a unit are part of that unit. so it wants
the mail sender (logcheck.server) to start a program to send data to
exim (which is in its own cgroup), and block until that is done.
whereas exim has slightly odd model where it starts a new process in
the background (using suid i guess) to immediately deliver the email
- systemd thinks this new process is part of the sending unit rather
than exim's unit
and so has a tendency to kill it, when the "main"
process exits or stop it working in various ways.
Each upstream considers the other one to be wrong.
that was my first thought, but i am no longer sure - i think that it is also >possible that exim delivers the email but, before it can remove it
from the queue, systemd
tears down the logcheck unit, and so exim retries, and this makes a duplicate.
(i see regularly see this when adding hardening to the a systemd unit
that sends mail- but ive nver seen 2 emails, i
have only seen an email left in the queue, or frozen. and debian's
unit has no hardening.)
Before the update I get mails with the subject:
Reboot: twentytwo.helgefjell.de 2025-05-16 15:54 +0200 System Events
After the reboot, now mails with this subject are sent; however, the
content is there (i.e. the filtered logs from the reboot are sent).
you mean "no mails with this subject are sent"? this is expected -
logcheck's cron does a (pointless) extra run after a reboot -- the
_only_ difference is that it adds the word
"reboot" in the subject. this isnt done under systemd
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
So the cron commands changed during the update.
yes - the cron job is still running, but only if you are not booted
under systemd
On Sat, May 17, 2025 at 06:58:56PM +0100, Richard Lewis wrote:
There is a known 'incompatibility' between systemd and exim that both >upstreams have explicitly declined to address - but it's
not clear (to me anyway) why you are hitting this -- ive been using
systemd and logcheck (and several other local email-sending units) for
over
a year with hardening and (after much pain) it now works for me - i
get an email every single day from a shell script in a systemd unit.
And all those scripts alos deliver via /usr/lib/sendmail?
Are you refering to the suid issue that I mentioned or is that incompatibility something else?
that was my first thought, but i am no longer sure - i think that it is also >possible that exim delivers the email but, before it can remove it
from the queue, systemd
tears down the logcheck unit, and so exim retries, and this makes a duplicate.
I have yet to see log evidence that exim actually delivers the message
twice.
On Sun, 18 May 2025 at 21:35, Helge Kreutzmann <debian@helgefjell.de> wrote:
I would suggest to install a machine with local exim (per debconf) and
some simple procmail rules, maybe just installing procmail is
sufficient, I don't know.
this is exactly what i am trying to do!
On Sat, May 17, 2025 at 04:14:34PM +0000, Helge Kreutzmann wrote:
Am Sat, May 17, 2025 at 05:44:03PM +0200 schrieb Marc Haber:
On Sat, May 17, 2025 at 01:44:57PM +0000, Helge Kreutzmann wrote:
In /etc/exim4 three files mention procmail:
exim4-config: /etc/exim4/conf.d/transport/30_exim4-config_procmail_pipe exim4-config: /etc/exim4/conf.d/router/700_exim4-config_procmail exim4-config: /etc/exim4/exim4.conf.template
But I never edited them directly, only via Debconf (probably when I installed the machine.
If you don't use procmail, you should deinstall it. Exim can deliver by itself.
I use procmail on several machines, but right, on this one it is not
(much) used. I just wonder - is procmail incompatible with the updated logcheck?
I don't think so. I just suggest disabling it to make things a bit easier to reproduce for Richard. It's like building a minimal reproducer, and taking software that should not interfere her out of the equation makes things easier if it is not necessary.
The cron.log says (before the update):
2025-04-14T00:02:01.739639+02:00 twentytwo CRON[11492]: (logcheck) CMD ( if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
and after the update:
2025-05-17T18:02:01.470178+02:00 twentytwo CRON[110761]: (logcheck) CMD ( if [ ! -d /run/systemd/system ] && [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
So the cron commands changed during the update.
That is boilerplate code to make the cron job do nothing on a system that
has systemd as pid 1.
file /run/systemd/system:
/run/systemd/system: directory
That is the common way to identify whether your system has systemd as pid 1. It is a very common idiom, see codesearch.debian.net.
Am Mon, May 19, 2025 at 01:33:42PM +0200 schrieb Marc Haber:
On Sun, May 18, 2025 at 05:04:00PM +0000, Helge Kreutzmann wrote:
Per advice of Richard, I just disabled cron, so let's see if the
systemd timer is sending anything.
Since there are many different possibilities to "disable" "cron", I would
like to suggest that you in the future give more exact description of what >> you have done, for example like "I have commented out the entire entry in
/etc/cron.d/logcheck" or "I have run systemctl disable --now cron" or
something else.
I exactly pasted what I did, i.e. commenting out the entry in the cron >script.
On Mon, 19 May 2025 at 12:29, Marc Haber
<mh+debian-packages@zugschlus.de> wrote:
On Sat, May 17, 2025 at 06:58:56PM +0100, Richard Lewis wrote:
There is a known 'incompatibility' between systemd and exim that both
upstreams have explicitly declined to address - but it's
not clear (to me anyway) why you are hitting this -- ive been using
systemd and logcheck (and several other local email-sending units) for
over
a year with hardening and (after much pain) it now works for me - i
get an email every single day from a shell script in a systemd unit.
And all those scripts alos deliver via /usr/lib/sendmail?
not sure --- i just use mail (from mailutils) -- and logcheck uses >mime-construct -- these may call sendmail ?
Are you refering to the suid issue that I mentioned or is that
incompatibility something else?
not sure -- >https://systemd-devel.freedesktop.narkive.com/nV1QMO8j/exim4-only-queues-mails-sent-by-systemd-service
Me neither -- this
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1106030 is the only >reproducible "issue" i have seen in the logcheck unit (and it doesnt
match this bug)
@Marc Haber would love your more expert view on that bug - and to
correct the likely flawed terminology in there!)
ps, my other email-sending units work with the following hardening
(not complete) - as long as i add a "sleep" after sending the email.
(but logcheck us using has none of these)
control: tags -1 + moreinfo unreproducible
Having reviewed the messages so far in this bug report, it's clear
that something different is happening when logcheck runs under the
systemd timer/service, but not cron. However, we don't have a
reproducer yet.
On Mon, 19 May 2025 at 20:04, Mathias Gibbens <gibmat@debian.org> wrote:
control: tags -1 + moreinfo unreproducible
Having reviewed the messages so far in this bug report, it's clear
that something different is happening when logcheck runs under the
systemd timer/service, but not cron. However, we don't have a
reproducer yet.
Agree with the above - helge sent me some exim config files and a .procmailrc, but, i still cannot reproduce the original issue.
My test wont be an exact replica, and i may well not be doing
something right, but as far as i can tell, "exim + procmail +
smarthost + logcheck" works (i got some SMTP rejections from the
smarthost, so i think it tried to send OK and got - as expected -
rejected).
All i see is the issue in https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1106030 so
hopefully the workaround for that fixes this
Hello Richard,
Am Tue, May 20, 2025 at 12:41:15AM +0100 schrieb Richard Lewis:
On Mon, 19 May 2025 at 20:04, Mathias Gibbens <gibmat@debian.org> wrote:
control: tags -1 + moreinfo unreproducible
Having reviewed the messages so far in this bug report, it's clear
that something different is happening when logcheck runs under the systemd timer/service, but not cron. However, we don't have a
reproducer yet.
i still cannot reproduce the original issue.
If you need anything else, if I should turn something verbose etc.,
please let me know.
All i see is the issue in
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1106030 so
hopefully the workaround for that fixes this
Should I locally implement this, i.e. return to stock logcheck 1.4.4?
On Tue, 20 May 2025, 17:29 Helge Kreutzmann, <debian@helgefjell.de> wrote:
Am Tue, May 20, 2025 at 12:41:15AM +0100 schrieb Richard Lewis:
On Mon, 19 May 2025 at 20:04, Mathias Gibbens <gibmat@debian.org> wrote:
control: tags -1 + moreinfo unreproducible
Having reviewed the messages so far in this bug report, it's clear that something different is happening when logcheck runs under the systemd timer/service, but not cron. However, we don't have a reproducer yet.
i still cannot reproduce the original issue.
If you need anything else, if I should turn something verbose etc.,
please let me know.
im not sure quite what else to suggest. what we need is to know what exim
was trying to write. Mybe there is an exim option for that?
All i see is the issue in
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1106030 so
hopefully the workaround for that fixes this
Should I locally implement this, i.e. return to stock logcheck 1.4.4?
cant hurt - you can also do this locally:
systemctl edit logcheck
# in the editor add:
[Service]
ExecStart=sleep 180
# im suggestibg a very long sleep, to give more chance to let exim do something - or to write its paniclog
cant hurt - you can also do this locally:
systemctl edit logcheck
# in the editor add:
[Service]
ExecStart=sleep 180
# im suggestibg a very long sleep, to give more chance to let exim do something - or to write its paniclog
| Sysop: | Keyop |
|---|---|
| Location: | Huddersfield, West Yorkshire, UK |
| Users: | 481 |
| Nodes: | 16 (2 / 14) |
| Uptime: | 09:25:47 |
| Calls: | 9,538 |
| Calls today: | 6 |
| Files: | 13,653 |
| Messages: | 6,139,122 |
| Posted today: | 1 |