Issues with automation triggers running both interface down and up at the same time

[brandonb]

Has anyone ever had issues with the automation triggers being duplicated?   For example I have two triggers,  interface down, and interface up, connected to two different stitches.   Whenever I down an interface to test, it runs both the interface down, and the interface up automations.    I contacted support about this previously and they just had me shut off the automation then start it again, it didn't do it again immediately so they considered it solved. 

config system automation-trigger
edit "Network Down"
set description "Default automation trigger configuration for when a network connection goes down."
set event-type event-log
set logid 20099
config fields
edit 1
set name "status"
set value "DOWN"
next
edit "Network Up"
set event-type event-log
set logid 20099
config fields
edit 1
set name "status"
set value "UP"
next
end

edit "ALARM - Interface Down"
set trigger "Network Down"
config actions
edit 2
set action "Default Email"
set required enable
next
edit 3
set action "Send INTF Alarm Test"
set delay 15
set required enable
next
end
next

edit "ALARM - Interface Up"
set trigger "Network Up"
config actions
edit 2
set action "Default Email"
set required enable
next
edit 3
set action "CLEAR INTF Alarm"
set delay 15
set required enable
next
end
next

[xshkurti]

@brandonb 

Please try this as i have already tested and it doesn't trigger both but only once at a time:

config system automation-stitch
edit "Interface Down"
set trigger "Interface down"
config actions
edit 1
set action "Email Notification"
set required enable
next
end
next
edit "Interface UP"
set trigger "Interface UP"
config actions
edit 1
set action "Email Notification"
set required enable
next
end
next
end

config system automation-trigger
edit "Interface down"
set event-type event-log
set logid 20099
config fields
edit 1
set name "status"
set value "DOWN"
next
end
next
edit "Interface UP"
set event-type event-log
set logid 20099
config fields
edit 1
set name "status"
set value "UP"
next
end
next
end

Regards,

[brandonb]

I deleted all of my existing stitches and triggers and recreated based on your reply. 

I enabled debugging

fw0-1 # diagnose debug enable

fw0-1 # diagnose debug application autod -1
Debug messages will be on for 30 minutes.

fw0-1 # pid:3473-__handle_msg()-271: Subscriber:4 received package. pubid:1 pkgid:417
pid:3473-__pkg_open()-170: Subscriber:4 processing package id:417 from pubisher:1
pid:3473-__handle_pkg_logs()-215: Subscriber:4 processing package size:37070 logs:47 pickup:2
pid:3473-miglog_subscr_pkg_close()-89: close package size:37070 logs:47
__action_email_hdl()-173: email action (Default Email) is called.
from:
to:[myemail];
subject:Interface status changed
__action_email_hdl()-173: email action (Default Email) is called.
from:
to:[myemail];
subject:Interface status changed

The debug shows it being called twice; and I received 4 emails total.  This is a HA pair.

Email 1:

date=2023-12-04 time=10:20:20 devid="FG4H0FT923902847" devname="fw0-2" eventtime=1701706820238803877 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="DOWN" msg="Link monitor: Interface Alarm Test was turned down" 

Email 2:

date=2023-12-04 time=10:20:21 devid="FG4H0FT923902847" devname="fw0-2" eventtime=1701706820740794568 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="UP" msg="Link monitor: Interface Alarm Test was turned up"

Email 3:

date=2023-12-04 time=10:20:19 devid="FG4H0FT923902840" devname="fw0-1" eventtime=1701706819753337116 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="UP" msg="Link monitor: Interface Alarm Test was turned up"

Email 4:

date=2023-12-04 time=10:20:19 devid="FG4H0FT923902840" devname="fw0-1" eventtime=1701706819257377805 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="DOWN" msg="Link monitor: Interface Alarm Test was turned down" 

[brandonb]

I deleted all of my existing stitches and triggers and recreated based on your reply. 

I enabled debugging

fw0-1 # diagnose debug enable

fw0-1 # diagnose debug application autod -1
Debug messages will be on for 30 minutes.

fw0-1 # pid:3473-__handle_msg()-271: Subscriber:4 received package. pubid:1 pkgid:417
pid:3473-__pkg_open()-170: Subscriber:4 processing package id:417 from pubisher:1
pid:3473-__handle_pkg_logs()-215: Subscriber:4 processing package size:37070 logs:47 pickup:2
pid:3473-miglog_subscr_pkg_close()-89: close package size:37070 logs:47
__action_email_hdl()-173: email action (Default Email) is called.
from:
to:[myemail];
subject:Interface status changed
__action_email_hdl()-173: email action (Default Email) is called.
from:
to:[myemail];
subject:Interface status changed

So by all appearances it only sent once.   But my email tells a different story.   This is a HA pair, so it sends the UP and DOWN immediately for each member of the HA.

Email 1:

date=2023-12-04 time=10:20:20 devid="FG4H0FT923902847" devname="fw0-2" eventtime=1701706820238803877 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="DOWN" msg="Link monitor: Interface Alarm Test was turned down" 

Email 2:

date=2023-12-04 time=10:20:21 devid="FG4H0FT923902847" devname="fw0-2" eventtime=1701706820740794568 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="UP" msg="Link monitor: Interface Alarm Test was turned up"

Email 3:

date=2023-12-04 time=10:20:19 devid="FG4H0FT923902840" devname="fw0-1" eventtime=1701706819753337116 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="UP" msg="Link monitor: Interface Alarm Test was turned up"

Email 4:

date=2023-12-04 time=10:20:19 devid="FG4H0FT923902840" devname="fw0-1" eventtime=1701706819257377805 tz="-0600" logid="0100020099" type="event" subtype="system" level="warning" vd="root" logdesc="Interface status changed" action="interface-stat-change" status="DOWN" msg="Link monitor: Interface Alarm Test was turned down" 

[brandonb]

I'm guessing i'm going to have to go a different direction for alarming as automations isn't doing what I need it to and is a little too hit and miss to be useful in production.    

[Debbie_FTNT]

Hey brandonb,

just out of curiosity - did you (or anyone else) check what event logs are generated?

Because the email snippets you posted show both an interface down log AND an interface up log.

If this is correct, and FortiGate DOES generate both logs (an interface down and an interface up log) at the same time, then of course the automation stitches trigger - they are each configured to act on an event log, and both event logs are generated, so two logs (and thus two stitches triggering two mails) per device.

In that case, you can reconfigure the stitches as much as you like, but the underlying issue is the log messages being generated, the stitches only do exactly what they are supposed to, trigger when a log is observed.

The question then becomes why is both an interface-down and an interface-up log generated at the same time?