SSMTP not sending email, no log line

[RHCPNG]

Hi guys,

I've been debugging SSMTP for quite some time now and am not able to get it working. I've followed the instructions and read a lot of posts. The one thing that's different from other posts is that I don't get an event of sending the email in the log file. The only log I get from zmfilter is this:

2017-09-19 13:19:01.198900 zmfilter 1960 INF Scanning for events using filter '_TempFilter1505819940' zmfilter.pl

It seems as if the send mail command is not even triggered.

See here screenshot of my options screen:

2017-09-19_13-29-19.png (60.19 KiB) Viewed 12142 times

I've tested ssmtp from the command line and that works.

Can you guys help me out here? Thanks.

[rockedge]

Does the filter work with SMTP and trigger the send mail event? Does the filter work in any conditions at all?

[RHCPNG]

Does the filter work with SMTP and trigger the send mail event? Does the filter work in any conditions at all?

The mail trigger doesn't seem to trigger at all, in no circumstances. At least, I don't see it in the log. The filter itself does give me results, as to events to mail. I force a new event every time I test the filter. I think I have tried deactivating and activating all checkmarks in the options, but I do not get anything about sending an email in the log.

[rockedge]

which operating system and version of zoneminder are you running?

[RHCPNG]

I'm running Debian 8 in a docker. The version of ZoneMinder is 1.30.4.

[marco123]

mail.png (67.12 KiB) Viewed 12096 times

filtre.png (20.84 KiB) Viewed 12096 times

smtp is okay on 1.29 with raspberry 3

[RHCPNG]

Thanks for the screenshots. My settings are identical. The weird part is that I do not see any log about sending an email. I don't know how to debug this any further.

[RHCPNG]

When I look in the debug log file I get this:

Code: Select all

09/26/17 09:16:49.936818 zmfilter[19294].DBG [LogOpts: level=DBG/DBG, screen=OFF, database=INF, logfile=DBG->/var/log/zm/zm_debug.log.19294, syslog=DBG]
09/26/17 09:16:50.003846 zmfilter[19294].INF [Scanning for events using filter '_TempFilter1506410209']
09/26/17 09:16:50.023871 zmfilter[19294].DBG [Reloading filters]
09/26/17 09:16:50.024547 zmfilter[19294].DBG [Found filter '_TempFilter1506410209']
09/26/17 09:16:50.072299 zmfilter[19294].DBG [SQL:SELECT E.*,
       unix_timestamp(E.StartTime) as Time,
       M.Name as MonitorName,
       M.DefaultRate,
       M.DefaultScale
         FROM Events as E
         INNER JOIN Monitors as M on M.Id = E.MonitorId
          where not isnull(E.EndTime) and ( E.StartTime > '2017-09-26 10:16:50' ) and ( E.Videoed = 0 or E.Emailed = 0 ) order by E.StartTime asc]
09/26/17 09:16:50.072456 zmfilter[19294].DBG [Got 1 filters]
09/26/17 09:16:50.072529 zmfilter[19294].DBG [Checking filter '_TempFilter1506410209', video, email]

I would have thought to see more after the last line.

[snake]

I've written a bit on this on the wiki. Did you look at this?
https://wiki.zoneminder.com/SMS_Notifications

The existing wiki guides cover SMTP setup well. At least for Devuan / Debian Jessie and Ubuntu 14.04.

Specifically, you should be following the "How to get ssmtp working with Zoneminder" wiki guide.
https://wiki.zoneminder.com/How_to_get_ ... Zoneminder

[RHCPNG]

I've written a bit on this on the wiki. Did you look at this?
https://wiki.zoneminder.com/SMS_Notifications

The existing wiki guides cover SMTP setup well. At least for Devuan / Debian Jessie and Ubuntu 14.04.

Specifically, you should be following the "How to get ssmtp working with Zoneminder" wiki guide.
https://wiki.zoneminder.com/How_to_get_ ... Zoneminder

Thanks! I have worked through the second link multiple times, but didn't know about the first. I will take a look at it!

[RHCPNG]

Ok, I took a look at the other post, but haven't made any progress in finding a solution.

I've set log levels to the following:

2017-09-28_14-56-10.png (61.54 KiB) Viewed 12025 times

But I don't see any logging about ssmtp or sending mail. I've tailed syslog and debug log.

Should there be a zmfilter.log file in the /var/log/zm folder? Because that doesn't exist in my setup.

[snake]

I don't see any logging about ssmtp or sending mail. I've tailed syslog and debug log.

Should there be a zmfilter.log file in the /var/log/zm folder? Because that doesn't exist in my setup.

Yes, there should be a zmfilter.log. And the LOG_DEBUG_FILE should have your output as well.

Maybe it's something to do with Docker.

You can add more comments to the perl script zmfilter.pl to see where the hangup is. On devuan/debian it's in /usr/bin/

[RHCPNG]

I don't see any logging about ssmtp or sending mail. I've tailed syslog and debug log.

Should there be a zmfilter.log file in the /var/log/zm folder? Because that doesn't exist in my setup.

Yes, there should be a zmfilter.log. And the LOG_DEBUG_FILE should have your output as well.

Maybe it's something to do with Docker.

You can add more comments to the perl script zmfilter.pl to see where the hangup is. On devuan/debian it's in /usr/bin/

Thanks for your reply! It indeed seems to be related to the docker image. I've deployed a clean image, but still the same problem and still no zmfilter.log. I will try and fiddle somewhat with the zmfilter.pl file.

[RHCPNG]

Ok, I have a breakthrough. It turns out that it has to do with a time difference between probably the database and zoneminder or something. I was testing with filters of greater than 1 minute and 1 hour ago, but this didn't trigger any events.

Now I tested with a filter of events greater than 3 hours ago and see me results. I executed the filter at 12:00 local time and see what SQL is executed:

Code: Select all

10/01/17 12:40:20.647789 zmfilter[9783].INF [Scanning for events using filter '_TempFilter1506854418']
10/01/17 12:40:20.678227 zmfilter[9783].DBG [Reloading filters]
10/01/17 12:40:20.678937 zmfilter[9783].DBG [Found filter '_TempFilter1506854418']
10/01/17 12:40:20.892509 zmfilter[9783].DBG [SQL:SELECT E.*,
       unix_timestamp(E.StartTime) as Time,
       M.Name as MonitorName,
       M.DefaultRate,
       M.DefaultScale
         FROM Events as E
         INNER JOIN Monitors as M on M.Id = E.MonitorId
          where not isnull(E.EndTime) and ( E.StartTime > '[b]2017-10-01 11:40:20[/b]' ) and ( E.Emailed = 0 ) order by E.StartTime asc]
10/01/17 12:40:20.892616 zmfilter[9783].DBG [Got 1 filters]
10/01/17 12:40:20.892655 zmfilter[9783].DBG [Checking filter '_TempFilter1506854418', email]
10/01/17 12:40:20.893290 zmfilter[9783].DBG [Checking event 2571]
10/01/17 12:40:20.893385 zmfilter[9783].INF [Creating notification email]
10/01/17 12:40:21.261688 zmfilter[9783].INF [Sending notification email 'ZoneMinder: Alarm - Garage-2571 (255 - 255 75)']
10/01/17 12:40:21.475982 zmfilter[9783].INF [Attaching '/usr/share/zoneminder/www/events/3/17/10/01/12/39/36/00026-capture.jpg]
10/01/17 12:40:35.705408 zmfilter[9783].INF [Notification email sent]

So I suppose that means the time used for creating the SQL was 14:40 at the time of execution.

Does anyone know how to proceed?

I have checked the mysql database and did a SQL-statement for the current time and the result of that was the correct time. And I've checked the variable TIME_ZONE and this is set to "SYSTEM". This is all rather new to me so I'm kind of freewheeling at the moment.

BTW I also checked the system date/time of the docker and that was correct also.

[RHCPNG]

Ok, I figured it out. For prosperity...

It was a docker issue. My timezone of the docker container was set to UTC and I'm in Europe/Amsterdam. After I changed the docker variable, the filters worked like to be expected.