Automation

Hi,

I have some doubts related to the matching of time-based events within an event-policy: I am expericencing a behaviour different from what I would expect.

I configured the router to generate a time-based event every 5 minutes:

e0# show generate-event   
every-5-minutes time-interval 300;

And a policy to match this event, in order to restart eventd (this need is due to some event-script tests):

re0# show policy match-5-minutes                               
events every-5-minutes;
within 300 {
    trigger on 1;
}
then {
    execute-commands {
        commands {
            "restart event-processing";
        }
        output-filename every-5-minutes-policy;
        destination local;
        output-format text;
    }
}

It seems like the policy is being executed every few seconds, instead of every 5 minutes, these are the log messages:

re0# run show log messages | last 20                         
May 20 09:09:33  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_LElRvh, output to /tmp/evt_op_DuUy7f in text format
May 20 09:09:33 _re0 mgd[55517]: UI_RESTART_EVENT: User 'root' restarting daemon 'Event processing process'
May 20 09:09:33  _re0 eventd: exiting on signal 15
May 20 09:09:38  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_rQ2Gs8, output to /tmp/evt_op_zENxd4 in text format
May 20 09:09:38  _re0 eventd: exiting on signal 15
May 20 09:09:44  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_gbSNvw, output to /tmp/evt_op_nnbOdq in text format
May 20 09:09:44  _re0 eventd: exiting on signal 15
May 20 09:09:49  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_V0EHAb, output to /tmp/evt_op_VhdcC0 in text format
May 20 09:09:49  _re0 mgd[55562]: UI_RESTART_EVENT: User 'root' restarting daemon 'Event processing process'
May 20 09:09:49  _re0 eventd: exiting on signal 15
May 20 09:09:54  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_mCmdPb, output to /tmp/evt_op_6VUfmu in text format
May 20 09:09:55  _re0 eventd: exiting on signal 15
May 20 09:10:00  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_qod91q, output to /tmp/evt_op_CLQGYZ in text format
May 20 09:10:00  _re0 eventd: exiting on signal 15
May 20 09:10:05  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_NcFAy2, output to /tmp/evt_op_6ObcaK in text format
May 20 09:10:06  _re0 eventd: exiting on signal 15
May 20 09:10:11  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_hDTntt, output to /tmp/evt_op_0tDvuy in text format
May 20 09:10:11  _re0 eventd: exiting on signal 15
May 20 09:10:17  _re0 logger: invoke-commands: Executed /tmp/evt_cmd_rsAYcy, output to /tmp/evt_op_PUdbyl in text format
May 20 09:10:17  _re0 eventd: exiting on signal 15

And this is am extract of the traceoptions file of the event-options

re0# run show log event-policy.log | match every-5 | last 20
May 20 09:10:44 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_TALPrp' as the temporary command file, and '/tmp/evt_op_YNuYvg' as the temporary output file
May 20 09:10:49 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_xbNU6N' as the temporary command file, and '/tmp/evt_op_Tjh3yI' as the temporary output file
May 20 09:10:55 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_6Fr7Ez' as the temporary command file, and '/tmp/evt_op_is0fii' as the temporary output file
May 20 09:11:00 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_hQS948' as the temporary command file, and '/tmp/evt_op_3SlSAr' as the temporary output file
May 20 09:11:06 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_rfwl01' as the temporary command file, and '/tmp/evt_op_OOm6gq' as the temporary output file
May 20 09:11:11 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_18oK0l' as the temporary command file, and '/tmp/evt_op_YpgtE9' as the temporary output file
May 20 09:11:17 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_vrIBze' as the temporary command file, and '/tmp/evt_op_9T5zcC' as the temporary output file
May 20 09:11:22 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_DZ4UnL' as the temporary command file, and '/tmp/evt_op_ylUcBM' as the temporary output file
May 20 09:11:28 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_NZy91D' as the temporary command file, and '/tmp/evt_op_yEHMrA' as the temporary output file
May 20 09:11:33 executing commands for policy 'match-5-minutes' triggered on receipt of event 'EVERY-5-MINUTES', with '/tmp/evt_cmd_bbfPUg' as the temporary command file, and '/tmp/evt_op_QNHktM' as the temporary output file

Beside that, another weird thing is that the expected output file, /var/tmp/every-5-minutes-policy is not being created!

Maybe I made some mistakes in the configuration? The scripts are running on a mx480 box, JUNOS 10.4R4.5.

Thanks in advance for your reply,

Mattia

When you restart the event process it is restarting all the timers, and I believe they fire initially and then wait for their specified interval. To confirm that this is what is happening, try restarting a different process and verify that the same behavior is not seen.

Hi Curtis, thanks for your reply; you hit the point, in fact, the policy works well if I try to restart another process or to execute a different command.