7.16 logging email not sent immediately after boot

DaveN · Mon Oct 07, 2024 6:06 am

Hello,

With 7.16, I am no longer getting log emails being sent immediately after boot.

I have logging setup to send any critical topic to echo, email and remote. With 7.15.3 and earlier, every reboot I would get an email (and syslog, and echo to console) for the ntp time change. With 7.16 the email is no longer sent at boot for the critical topic, however email does work if I send a test. Syslog shows no indication that an email was attempted at boot, but does log when doing the test.

From syslog, this is with 7.15.3

2024-09-19T07:47:44.224614-04:00 system,critical,info ntp change time Sep/18/2024 23:16:01 => Sep/19/2024 07:47:44
2024-09-19T07:47:48.260212-04:00 e-mail,info sent <system,critical,info ntp change time Sep/18/2024 23:16:01 => Sep/19/2024 07:47:44> to: xxxx@gmail.com

And this is after the 7.16 update

2024-09-25T02:39:04.234520-04:00 system,info installed system-7.16
2024-09-25T02:39:04.234582-04:00 system,info installed wireless-7.16
2024-09-25T02:39:04.238899-04:00 system,info router rebooted
2024-09-25T02:39:04.238899-04:00 system,info,critical Firmware upgraded successfully, please reboot for changes to take effect!
2024-09-25T02:39:04.238899-04:00 system,info router firmware has been automatically upgraded
2024-09-25T02:39:04.239311-04:00 system,info please reboot router to run new firmware
<snip>
2024-09-25T02:39:14.202792-04:00 system,clock,critical,info ntp change time Sep/25/2024 02:37:44 => Sep/25/2024 02:39:14

Ever reboot since 7.16 was installed (whether a proper reboot, or power cycle) fails to send an email.

I added topic clock to send an email as a test. The email does send OK when I change clock settings, but not for the ntp time change at boot.

2024-10-06T22:28:37.965917-04:00 system,info log rule added by winbox-3.41/tcp-msg(winbox):xxx (*C = /system logging add action=email disabled=no prefix="" topics=clock)
2024-10-06T22:29:20.403852-04:00 system,clock,info change time Oct/06/2024 22:29:20 => Oct/06/2024 22:29:19
2024-10-06T22:29:20.421879-04:00 system,info system time zone settings changed by winbox-3.41/tcp-msg(winbox):xxx (/system clock set time-zone-autodetect=yes time-zone-name=America/Montreal; /system clock manual set dst-delta=+00:00 dst-end="1970-01-01 00:00:00" dst-start="1970-01-01 00:00:00" time-zone=+00:00)
2024-10-06T22:29:23.563714-04:00 e-mail,info sent <system,clock,info change time Oct/06/2024 22:29:20 => Oct/06/2024 22:29:19> to: xxxx@gmail.com 

2024-10-06T22:31:07.487686-04:00 system,info router rebooted by winbox-3.41/tcp-msg(winbox):xxx
<snip>
2024-10-06T22:31:14.866017-04:00 system,clock,critical,info ntp change time Oct/06/2024 22:30:54 => Oct/06/2024 22:31:14
2024-10-06T22:44:04.188291-04:00 system,info,account user xxx logged in from <snip> via winbox

The issue occurs on all three types of MT hardware I have: hAPac3 (RBD53iG-5HacD2HnD), hAPac2 (RBD52G-5HacD2HnD-TC), Metal52ac (RBMetalG-52SHPacn).

Cheers,
DaveN

Tue Oct 08, 2024 8:56 pm

Maybe a simple delay before sending the email ?
Most likely not everything is ready yet for email to work right after boot.

You can also log a message right before sending the mail, so you can see what still had to be done.

gbtest85 · Fri Oct 11, 2024 12:38 am

hi I'm noticing this issue too, mails from logging are not sent!

I used to receive ntp time change upon reboot but also any wrong login as are marked as CRITICAL

Last mail received 21 September just before installation of 7.16

If I send a manual mail it works, it's the logging that is not working!

Thank you!

Giorgio

Fri Oct 11, 2024 9:38 am

If it works manually, it means everything works as it should and the system is not yet ready to send mail when you want to send it.
Wait a bit or check for DNS resolution or whatever before even TRYING to use email.

DaveN · Sat Oct 12, 2024 11:22 am

Still broken with 7.16.1.

The critical log email is when NTP gets a new time from an external source, so the network and dns ae up.

With the exact same configuration file, the email was sent for the NTP time change after boot with 7.15.3. This broke on update to 7.16.

Both manual and logging triggered emails do start working eventually, but for the first NTP change, syslog does not even log an attempt to send an email. With 7.15.3 and earlier I would see syslog entries for failed attempts to send email logs even this early in the boot cycle if the upstream network wasn't ready.

gbtest85 · Sat Oct 12, 2024 8:19 pm

Same here on my AX3!

Still broken with 7.16.1.

The critical log email is when NTP gets a new time from an external source, so the network and dns ae up.

With the exact same configuration file, the email was sent for the NTP time change after boot with 7.15.3. This broke on update to 7.16.

Both manual and logging triggered emails do start working eventually, but for the first NTP change, syslog does not even log an attempt to send an email. With 7.15.3 and earlier I would see syslog entries for failed attempts to send email logs even this early in the boot cycle if the upstream network wasn't ready.

MC88 · Sat Oct 26, 2024 11:02 am

I have the same problem since I updated to version 7.16. It seems to be a bug

Sat Oct 26, 2024 12:06 pm

When you start up a Windows laptop, you can not immediately start some apps either when you see the desktop. There is still some startup finishing to be done.

You need to check everything is ready to be used before actually using it.
Wait a bit or do the checks. Waiting is easier.

Most likely some startup processes take just a bit longer now and that's why it may have worked before.

Lokamaya · Sat Oct 26, 2024 12:28 pm

I'll use Netwatch, not Logging, for sending email for the time being until it is resolved. And add "start up delay" into it.

MC88 · Sat Oct 26, 2024 7:58 pm

When you start up a Windows laptop, you can not immediately start some apps either when you see the desktop. There is still some startup finishing to be done.

You need to check everything is ready to be used before actually using it.
Wait a bit or do the checks. Waiting is easier.

Most likely some startup processes take just a bit longer now and that's why it may have worked before.

It's not just when it starts up. For example, just failing to login generates a "critical" error and I have it configured to send email and it doesn't...

DaveN · Sun Nov 10, 2024 5:28 am

I sent the following to support@mikrotik.com - will update if I get a response.

Hello Mikrotik,

Logging to email for "critical" topics is broken since 7.16 - it worked in 7.15.3.
I have this issue on all of my devices hAPac^2, hAPac^3, Metal52ac, and RB750Gr3.
I've reset my RB750Gr3 to the default configuration, then enabled the bare minimum to reproduce the issue.
/system logging action
add email-start-tls=yes email-to=mikrotik@mailinator.com name=email target=email
/system logging
add action=email topics=critical
/system ntp client
set enabled=yes
/system ntp client servers
add address=ca.pool.ntp.org
/tool e-mail
set from=mikrotik073@gmail.com port=465 server=smtp.gmail.com tls=yes user=mikrotik073
With this configuration, on 7.15.3, at boot there would be a "system, critical, info" log about the ntp time change showing in the memory buffer. An email would also be sent, and this action was logged in the memory buffer as well.

After updating to either 7.16 or 7.16.1, the email is no longer sent and the memory buffer does not show any attempt to send the email.

In the 7.16.1 config I added a new logging action to email all "info" and "!e-mail" events.
/system logging
add action=email topics=info,!e-mail
On reboot, the memory buffer does show attempts to send email for "info" events, but it does not show any attempt to email for "critical" events.

Attached to this email are archives with supout.rif, .backup files and screenshots of the memory buffer log for both the working 7.15.3 config and the not working 7.16.1 config. FYI, The gmail account the router is sending from was generated specifically for this test - I'm not worried about security if you extract the password for it from the backups.

Cheers,
Dave N.

7.16.1 - not working.zip

7.15.3 - working.zip

DaveN · Thu Nov 14, 2024 4:29 pm

FYI - SUP-170853

Hello,
Thank you for the report.

We were able to reproduce your issue in our labs.
Our developers have already considered this issue, and it will be fixed in future releases, but unfortunately, I cannot share any ETA yet.

Best regards

DaveN · Tue Nov 26, 2024 2:47 pm

I have not tested the fix, but it is now available in a release candidate.

What's new in 7.17rc1 (2024-Nov-22 11:42):
*) log - fixed e-mail logging (introduced in v7.16);

gbtest85 · Sun Dec 01, 2024 1:51 pm

Yeah not fixed in 7.16.1, waiting for 7.17, thank you!

7.16 logging email not sent immediately after boot

7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Re: 7.16 logging email not sent immediately after boot

Who is online