email takes 5 minutes...

mrd · Post by **mrd** » Fri Oct 09, 2009 1:40 am

Why does the "Email details of all matches" filter feature take 5 minutes to actually send the email message in 1.24.2? This used to take around the same amount of time as the FILTER_EXECUTE_INTERVAL in previous versions.

The zmfilter.pl log indicated that the email message was sent as soon as the alarm is found by zmfilter.pl, but the actual mail message is not sent for a minimum of 5 minutes.

I have tested the code in zmfilter.pl by extracting the mail portion and executing a script that sends the mail immediately so I believe that ZM is buffering the action for some reason.

Post by **zoneminder** » Wed Oct 14, 2009 4:51 pm

Email timeouts like this are often related to DNS and name resolution issues.

Check you are not getting caught by something like this http://fedoraforum.org/forum/archive/in ... 85365.html

mrd · Post by **mrd** » Wed Oct 14, 2009 6:32 pm

Thank you for the reply! I was worried that no one cared for me...lol

I had a look at the thread and in fact, my hostname is simply system-z, but my /etc/hosts is in proper order and most importantly, I don't think I'm using sendmail unless Mime::Lite uses it under the covers?

I am able to create an exact duplication of the email portion of the zmfilter.pl script and it works perfectly so I would expect that if there was some sort of name resolution problem, it would occur in the isolated test too.

Here is the sub in my script that is actually extracted from zmfilter.pl:

Code: Select all

sub sendEmail
{
        my $config = shift();
        my @attachments;
        my $email_msg = "Just a test...";

            ### Create the multipart container
            my $mail = MIME::Lite->new (
                From => $config->{email_from},
                To => $config->{email_to},
                Subject => $config->{email_subj},
                Type => "multipart/mixed"
            );
            ### Add the text message part
            $mail->attach (
                Type => "TEXT",
                Data => ${email_msg}
            );
            ### Add the attachments
            foreach my $attachment ( @attachments )
            {
                Info( "Attaching '$attachment->{path}\n" );
                $mail->attach(
                    Path => $attachment->{path},
                    Type => $attachment->{type},
                    Disposition => "attachment"
                );
            }
            ### Send the Message
            MIME::Lite->send( "smtp", $config->{smtp_server}, Timeout=>60 );
            $mail->send();
}

I simply provide the same variables that ZM provides by passing a hash ref into the sub.

It seems to be that the main ZM process that calls zmfilter.pl is where the issue must be. There must be some sort of buffer or timer set that prevents the action from taking place immediately. I find it interesting that it always takes almost exactly 5 minutes (300 seconds) to send and the FILTER_RELOAD_DELAY = 300.

This was not a problem in earlier releases as I recall.

mrd · Post by **mrd** » Thu Oct 15, 2009 12:58 am

As an experiment I changed the FILTER_RELOAD_DELAY to 60, but the email still took 5 minutes to actually send.

I'm stumped!

mrd · Post by **mrd** » Mon Oct 19, 2009 3:33 pm

Can anyone out there verify that this is not just my problem?

Someone else must be using 1.24.2 and email alerts?

Post by **zoneminder** » Tue Oct 20, 2009 8:02 pm

You can run zmfilter from the command line. I would suggest maybe putting a few 'print's in there to try and figure out where it is getting snarled up.

mrd · Post by **mrd** » Wed Oct 21, 2009 1:00 am

I added some debug print statements to zmfilter.pl inside of the eval block hoping to see something blocking, but the code is executed at the exact time that I would expect.

10/20/09 20:39:03.789224 zmfilter[2911].INF [Scanning for events]
10/20/09 20:41:08.820503 zmfilter[2911].INF [Creating notification email]
10/20/09 20:41:08.821047 zmfilter[2911].INF [Sending notification email 'ZoneMinder: Alarm - Back_Door-434']
10/20/09 20:41:08.826409 zmfilter[2911].INF [About to send the real mail message.]
10/20/09 20:41:09.121150 zmfilter[2911].INF [Done sending the real mail message.]
10/20/09 20:41:09.121395 zmfilter[2911].INF [Notification email sent]

However, the actual email message takes 5 minutes to be sent from the system. I get the exact same result when I stop the filter from running in the background and execute zmfilter.pl on the command line. The log appears the same, but the mail message is not sent for 5 minutes.

Can you tell me what process calls zmfilter.pl?

There is nothing wrong with Mime::Lite since I can send mail with the exact code in zmfilter extracted to another script.