Rules with IntervalTimer are not enforced

lparsy · May 28, 2021, 5:32pm

Creating a simple rule with a timer ( core.st2.IntervalTimer or CronTimer) does nothing,
It is not called. (tried with no-op action and local_command creating a test a file)

Any idea of how to fix this or which logs I could investigate on this subject?

rule below:

{
  "tags": [],
  "uid": "rule:packs:test-timer",
  "metadata_file": "",
  "name": "test-timer",
  "ref": "packs.test-timer",
  "description": "desc",
  "pack": "packs",
  "type": {
    "ref": "standard",
    "parameters": {}
  },
  "trigger": {
    "type": "core.st2.IntervalTimer",
    "parameters": {
      "delta": 10,
      "unit": "seconds",
      "timezone": "UTC"
    },
    "ref": "core.50338bb7-f65b-46bf-ada1-d6280f2edd37",
    "description": "Triggers on specified intervals. e.g. every 30s, 1week etc."
  },
  "criteria": {},
  "action": {
    "ref": "core.noop",
    "parameters": {},
    "description": "Action that does nothing"
  },
  "context": {
    "user": "username"
  },
  "enabled": true,
  "id": "60b119244ac572b35efea8c1"
}

amanda11 · May 29, 2021, 9:02am

A few things to check:
st2 rule list - and check the rule is loaded and enabled. If not then maybe a st2ctl reload to reload rules.

Rule is not Being Matched — StackStorm 3.4.0 documentation - might help you to follow through the rule, trigger, action chain.

You could also look in the rulesengine.log.

The only thing that strikes me as different to the rules that I use, is the “context”, “user” fields- I’m not sure if that is the problem. So I’d maybe try removing that.

lparsy · May 30, 2021, 4:51pm

thank you for your quick reply.
I tried searching thoroughly with the help of your advices and even if I found new informations I don’t really understand the cause of the problem.

I would say that it has to do with the timer system.
Before today I never saw the rule matched with st2 rule and no trigger executed on st2 trigger-instance
Worse, while reloading the st2rulesengines and st2timersengine, my rule matched once… and then never again, even while retrying the same steps

when i rerun the only match i had with st2-rule-tester I get an error (maybe because i rechanged the rule or reloaded stackstorm in between)

sudo st2-rule-tester --rule-ref=mypack.myrule --trigger-instance-id=60b3b0fd76ec9b09e90a9d63 --config-file=/etc/st2/st2.conf

2021-05-30 18:30:15,696 INFO [-] Connecting to database "st2" @ "127.0.0.1:27017" as user "None".
2021-05-30 18:30:15,699 INFO [-] Successfully connected to database "st2" @ "127.0.0.1:27017" as user "None".
Traceback (most recent call last):
  File "/usr/bin/st2-rule-tester", line 21, in <module>
    rule_tester.main()
  File "/usr/lib/python3/dist-packages/st2reactor/cmd/rule_tester.py", line 57, in main
    matches = tester.evaluate()
  File "/usr/lib/python3/dist-packages/st2reactor/rules/tester.py", line 70, in evaluate
    if rule_db.trigger != trigger_db.ref:
AttributeError: 'NoneType' object has no attribute 'ref'

I notices that I apparently have 3 timers running on my server, is it normal?

myuser@mysrv:~$ sudo st2 timer list
+--------------------------+-----------------------+------+-----------------------+-----------------------+-----------------------+
| id                       | uid                   | pack | name                  | type                  | parameters            |
+--------------------------+-----------------------+------+-----------------------+-----------------------+-----------------------+
| 60b2b47d4ac572b35efea8c2 | trigger:core:b1a253fe | core | b1a253fe-0a73-4ffe-93 | core.st2.IntervalTime | {'delta': 10, 'unit': |
|                          | -0a73-4ffe-9388-8cc43 |      | 88-8cc43844922c       | r                     | 'seconds'}            |
|                          | 844922c:aba138edb6d32 |      |                       |                       |                       |
|                          | 02c02b4da94cee70b1f   |      |                       |                       |                       |
| 60b2b4904ac572b35efea8c3 | trigger:core:b49cac00 | core | b49cac00-370b-45d1-9e | core.st2.IntervalTime | {'delta': 10, 'unit': |
|                          | -370b-45d1-9ee0-5f78b |      | e0-5f78b81d5b86       | r                     | 'seconds',            |
|                          | 81d5b86:d6a146a61f811 |      |                       |                       | 'timezone': 'UTC'}    |
|                          | baecbaecc963d78b759   |      |                       |                       |                       |
| 60b3b88568b86302c44ee1c0 | trigger:core:f92d2e6c | core | f92d2e6c-0555-4033-ba | core.st2.IntervalTime | {'unit': 'seconds',   |
|                          | -0555-4033-babf-6d9db |      | bf-6d9db1074dd3       | r                     | 'delta': 5}           |
|                          | 1074dd3:889c1c0b04f53 |      |                       |                       |                       |
|                          | 100997af85f35ad3979   |      |                       |                       |                       |
+--------------------------+-----------------------+------+-----------------------+-----------------------+-----------------------+

should I delete them in the st2 mongodb , or clean the stackstorm entirely?

st2timersengine is up according to systemctl.
I tried changing the local_timezone to the server’s one in the st2.conf
and logs don’t show errors, but maybe the trigger is not re-emmitted every 10 seconds like it implies in the logs:

may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,202 INFO [-] Added job "St2Timer._emit_trigger_instance" to job store "default"
may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,202 INFO [-] Job 345d081226aa443cb2f7e813665d592b scheduled.
may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,203 INFO [-] Added job "St2Timer._emit_trigger_instance" to job store "default"
may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,203 INFO [-] Job a2424b244fc642f0b202dc60a191c20c scheduled.
may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,204 INFO [-] Added job "St2Timer._emit_trigger_instance" to job store "default"
may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,204 INFO [-] Job e4530261389546098354567a83f6b4db scheduled.
may 30 18:08:20 myserv st2timersengine[7838]: 2021-05-30 18:08:20,205 INFO [-] Connected to amqp://guest:**@127.0.0.1:5672//
may 30 18:08:30 myserv st2timersengine[7838]: 2021-05-30 18:08:30,203 INFO [-] Running job "St2Timer._emit_trigger_instance (trigger: interval[0:00:10], next run at: 2021-05-30 18:08:30 CEST)" (scheduled at 2021-05-30 18:08:30.202274+02:00)
may 30 18:08:30 myserv st2timersengine[7838]: 2021-05-30 18:08:30,212 INFO [-] Running job "St2Timer._emit_trigger_instance (trigger: interval[0:00:10], next run at: 2021-05-30 16:08:30 UTC)" (scheduled at 2021-05-30 16:08:30.203337+00:00)
may 30 18:08:30 myserv st2timersengine[7838]: 2021-05-30 18:08:30,218 INFO [-] Job "St2Timer._emit_trigger_instance (trigger: interval[0:00:10], next run at: 2021-05-30 18:08:40 CEST)" executed successfully

here is also a part of my rulesengines.log, if useful

2021-05-30 18:07:24,548 140278377033232 INFO (unknown file) [-] Connecting to database "st2" @ "127.0.0.1:27017" as user "None".
2021-05-30 18:07:24,551 140278377033232 INFO (unknown file) [-] Successfully connected to database "st2" @ "127.0.0.1:27017" as user "None".
2021-05-30 18:07:24,883 140278377033232 INFO (unknown file) [-] (PID=7768) RulesEngine started.
2021-05-30 18:07:24,884 140278377033232 INFO (unknown file) [-] Starting TriggerInstanceDispatcher...
2021-05-30 18:07:24,890 140278349311672 INFO mixins [-] Connected to amqp://guest:**@127.0.0.1:5672//
2021-05-30 18:07:42,708 140278362322144 INFO (unknown file) [-] Found 0 rules defined for trigger core.b1a253fe-0a73-4ffe-9388-8cc43844922c
2021-05-30 18:07:42,709 140278362322144 INFO (unknown file) [-] No matching rules found for trigger instance 60b3b84e5ac412df85364160.
2021-05-30 18:07:42,716 140278344941808 INFO (unknown file) [-] Found 0 rules defined for trigger core.b49cac00-370b-45d1-9ee0-5f78b81d5b86
2021-05-30 18:07:42,717 140278344941808 INFO (unknown file) [-] No matching rules found for trigger instance 60b3b84e5ac412df85364162.

thank you for your help,
sorry for the lenghty post, I tried being as exhaustive as I could.