{"action":"created","issue":{"url":"https://api.github.com/repos/StackStorm/st2/issues/2715","repository_url":"https://api.github.com/repos/StackStorm/st2","labels_url":"https://api.github.com/repos/StackStorm/st2/issues/2715/labels{/name}","comments_url":"https://api.github.com/repos/StackStorm/st2/issues/2715/comments","events_url":"https://api.github.com/repos/StackStorm/st2/issues/2715/events","html_url":"https://github.com/StackStorm/st2/issues/2715","id":157079116,"number":2715,"title":"Cron timer triggers not found this morning","user":{"login":"codyaray","id":44062,"avatar_url":"https://avatars.githubusercontent.com/u/44062?v=3","gravatar_id":"","url":"https://api.github.com/users/codyaray","html_url":"https://github.com/codyaray","followers_url":"https://api.github.com/users/codyaray/followers","following_url":"https://api.github.com/users/codyaray/following{/other_user}","gists_url":"https://api.github.com/users/codyaray/gists{/gist_id}","starred_url":"https://api.github.com/users/codyaray/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/codyaray/subscriptions","organizations_url":"https://api.github.com/users/codyaray/orgs","repos_url":"https://api.github.com/users/codyaray/repos","events_url":"https://api.github.com/users/codyaray/events{/privacy}","received_events_url":"https://api.github.com/users/codyaray/received_events","type":"User","site_admin":false},"labels":[],"state":"closed","locked":false,"assignee":null,"milestone":null,"comments":9,"created_at":"2016-05-26T21:05:33Z","updated_at":"2016-06-22T15:52:32Z","closed_at":"2016-06-22T15:52:32Z","body":"Issue from https://stackstorm-community.slack.com/archives/community/p1464270424007061\r\n\r\nLooks like none of our cron rules ran last night. Found these in the st2rulesengine.log file\r\n\r\nstackstorm blueprint node 1:\r\n```\r\n2016-05-26 02:15:00,010 140197381803856 ERROR worker [-] Failed to create trigger_instance {'trace_context': <st2common.models.api.trace.TraceContext object at 0x7f823efd9dd0>, 'trigger': {'uid': u'trigger:core:5201a528-83a8-45a3-afed-1324d19d799c:184474b72fcfb6391b701239c1323bd2', 'parameters': {u'minute': 15, u'hour': 2}, 'description': None, 'ref_count': 1, 'name': u'5201a528-83a8-45a3-afed-1324d19d799c', 'type': u'core.st2.CronTimer', 'id': '57217437f469fc4355dd5e85', 'pack': u'core'}, 'payload': {'executed_at': '2016-05-26 07:15:00.004733+00:00', 'schedule': None}}.\r\nTraceback (most recent call last):\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/rules/worker.py\", line 51, in process\r\n    raise_on_no_trigger=True)\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/container/utils.py\", line 51, in create_trigger_instance\r\n    raise StackStormDBObjectNotFoundError('Trigger not found for %s', trigger)\r\nStackStormDBObjectNotFoundError: ('Trigger not found for %s', {'uid': u'trigger:core:5201a528-83a8-45a3-afed-1324d19d799c:184474b72fcfb6391b701239c1323bd2', 'parameters': {u'minute': 15, u'hour': 2}, 'description': None, 'ref_count': 1, 'name': u'5201a528-83a8-45a3-afed-1324d19d799c', 'type': u'core.st2.CronTimer', 'id': '57217437f469fc4355dd5e85', 'pack': u'core'})\r\n--\r\n2016-05-26 03:00:00,023 140197381803696 ERROR worker [-] Failed to create trigger_instance {'trace_context': <st2common.models.api.trace.TraceContext object at 0x7f823ed2c0d0>, 'trigger': {'uid': u'trigger:core:65d02cf0-b01c-4e78-a904-daf1893f1e37:91302ea65fcee79862b663963e207d22', 'parameters': {u'hour': 3, u'minute': 0}, 'description': None, 'ref_count': 0, 'name': u'65d02cf0-b01c-4e78-a904-daf1893f1e37', 'type': u'core.st2.CronTimer', 'id': '572aaca559e5f159727c5134', 'pack': u'core'}, 'payload': {'executed_at': '2016-05-26 08:00:00.006160+00:00', 'schedule': None}}.\r\nTraceback (most recent call last):\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/rules/worker.py\", line 51, in process\r\n    raise_on_no_trigger=True)\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/container/utils.py\", line 51, in create_trigger_instance\r\n    raise StackStormDBObjectNotFoundError('Trigger not found for %s', trigger)\r\nStackStormDBObjectNotFoundError: ('Trigger not found for %s', {'uid': u'trigger:core:65d02cf0-b01c-4e78-a904-daf1893f1e37:91302ea65fcee79862b663963e207d22', 'parameters': {u'hour': 3, u'minute': 0}, 'description': None, 'ref_count': 0, 'name': u'65d02cf0-b01c-4e78-a904-daf1893f1e37', 'type': u'core.st2.CronTimer', 'id': '572aaca559e5f159727c5134', 'pack': u'core'})```\r\n```\r\n\r\nstackstorm blueprint node 2:\r\n```\r\n2016-05-26 03:00:00,018 140303599906160 ERROR worker [-] Failed to create trigger_instance {'trace_context': <st2common.models.api.trace.TraceContext object at 0x7f9afa0a10d0>, 'trigger': {'uid': u'trigger:core:9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82:e6d9bf27b0ede4bf3d03616c685a1e38', 'parameters': {u'day_of_week': u'0-4', u'minute': 0, u'hour': 3}, 'description': None, 'ref_count': 1, 'name': u'9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82', 'type': u'core.st2.CronTimer', 'id': '573b7ee559e5f1422b7ba7ec', 'pack': u'core'}, 'payload': {'executed_at': '2016-05-26 08:00:00.004615+00:00', 'schedule': None}}.\r\nTraceback (most recent call last):\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/rules/worker.py\", line 51, in process\r\n    raise_on_no_trigger=True)\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/container/utils.py\", line 51, in create_trigger_instance\r\n    raise StackStormDBObjectNotFoundError('Trigger not found for %s', trigger)\r\nStackStormDBObjectNotFoundError: ('Trigger not found for %s', {'uid': u'trigger:core:9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82:e6d9bf27b0ede4bf3d03616c685a1e38', 'parameters': {u'day_of_week': u'0-4', u'minute': 0, u'hour': 3}, 'description': None, 'ref_count': 1, 'name': u'9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82', 'type': u'core.st2.CronTimer', 'id': '573b7ee559e5f1422b7ba7ec', 'pack': u'core'})\r\n--\r\n2016-05-26 06:30:00,017 140303599906160 ERROR worker [-] Failed to create trigger_instance {'trace_context': <st2common.models.api.trace.TraceContext object at 0x7f9afa323c50>, 'trigger': {'uid': u'trigger:core:ffcf42ce-9514-484d-8193-9c60ddb661da:a0e7c2879668bb12ef7e519b29742d2f', 'parameters': {u'minute': 30, u'hour': 6}, 'description': None, 'ref_count': 1, 'name': u'ffcf42ce-9514-484d-8193-9c60ddb661da', 'type': u'core.st2.CronTimer', 'id': '57217437f469fc4355dd5e81', 'pack': u'core'}, 'payload': {'executed_at': '2016-05-26 11:30:00.010405+00:00', 'schedule': None}}.\r\nTraceback (most recent call last):\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/rules/worker.py\", line 51, in process\r\n    raise_on_no_trigger=True)\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/container/utils.py\", line 51, in create_trigger_instance\r\n    raise StackStormDBObjectNotFoundError('Trigger not found for %s', trigger)\r\nStackStormDBObjectNotFoundError: ('Trigger not found for %s', {'uid': u'trigger:core:ffcf42ce-9514-484d-8193-9c60ddb661da:a0e7c2879668bb12ef7e519b29742d2f', 'parameters': {u'minute': 30, u'hour': 6}, 'description': None, 'ref_count': 1, 'name': u'ffcf42ce-9514-484d-8193-9c60ddb661da', 'type': u'core.st2.CronTimer', 'id': '57217437f469fc4355dd5e81', 'pack': u'core'})\r\n```\r\n\r\nTrying to figure out ​why the cron triggers don't exist anymore.\r\n\r\nDoesn't look like these types of triggers show up in `st2 trigger list` but I see the last five days (not today) in `st2 trigger-instance list --trigger=core.9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82`\r\n\r\nOne exception: `core.65d02cf0-b01c-4e78-a904-daf1893f1e37` doesn't show up in the trigger-instance list (today or any previous days).\r\n\r\nLooking directly in mongo, I find that the jobs are still in the \r\n\r\n```\r\nstackstorm:SECONDARY> db.trigger_d_b.find({\"name\": \"9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82\"})\r\n{ \"_id\" : ObjectId(\"573b7ee559e5f1422b7ba7ec\"), \"uid\" : \"trigger:core:9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82:e6d9bf27b0ede4bf3d03616c685a1e38\", \"name\" : \"9d5eb720-e95e-475c-8a6d-c0bf0dc3bc82\", \"pack\" : \"core\", \"type\" : \"core.st2.CronTimer\", \"parameters\" : { \"minute\" : 0, \"day_of_week\" : \"0-4\", \"hour\" : 3 }, \"ref_count\" : 1 }\r\n\r\nstackstorm:SECONDARY> db.trigger_d_b.find({\"name\":\"65d02cf0-b01c-4e78-a904-daf1893f1e37\"})\r\n{ \"_id\" : ObjectId(\"572aaca559e5f159727c5134\"), \"uid\" : \"trigger:core:65d02cf0-b01c-4e78-a904-daf1893f1e37:91302ea65fcee79862b663963e207d22\", \"name\" : \"65d02cf0-b01c-4e78-a904-daf1893f1e37\", \"pack\" : \"core\", \"type\" : \"core.st2.CronTimer\", \"parameters\" : { \"minute\" : 0, \"hour\" : 3 }, \"ref_count\" : 0 }\r\n```\r\n\r\nAs a sanity check, I updated one of these rules to run at current time and watched it successfully complete. Interestingly, another rule that I hadn't touched and was scheduled for this afternoon should have just ran a few minutes ago as well but also failed with the same error.\r\n\r\n```\r\n2016-05-26 15:50:00,018 140632250726512 ERROR worker [-] Failed to create trigger_instance {'trace_context': <st2common.models.api.trace.TraceContext object at 0x7fe77f498610>, 'trigger': {'uid': u'trigger:core:f618fa96-8838-4a8c-8664-e476fc653fe1:7ea45d3da0596aa5ba162d5f81049b44', 'parameters': {u'day_of_week': u'0-4', u'minute': 50, u'hour': 15}, 'description': None, 'ref_count': 2, 'name': u'f618fa96-8838-4a8c-8664-e476fc653fe1', 'type': u'core.st2.CronTimer', 'id': '57449a5859e5f17e2c71902c', 'pack': u'core'}, 'payload': {'executed_at': '2016-05-26 20:50:00.001940+00:00', 'schedule': None}}.\r\nTraceback (most recent call last):\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/rules/worker.py\", line 51, in process\r\n    raise_on_no_trigger=True)\r\n  File \"/opt/stackstorm/st2/local/lib/python2.7/site-packages/st2reactor/container/utils.py\", line 51, in create_trigger_instance\r\n    raise StackStormDBObjectNotFoundError('Trigger not found for %s', trigger)\r\nStackStormDBObjectNotFoundError: ('Trigger not found for %s', {'uid': u'trigger:core:f618fa96-8838-4a8c-8664-e476fc653fe1:7ea45d3da0596aa5ba162d5f81049b44', 'parameters': {u'day_of_week': u'0-4', u'minute': 50, u'hour': 15}, 'description': None, 'ref_count': 2, 'name': u'f618fa96-8838-4a8c-8664-e476fc653fe1', 'type': u'core.st2.CronTimer', 'id': '57449a5859e5f17e2c71902c', 'pack': u'core'})\r\n```\r\n\r\nOne thing that may be relevant is that one of our users has been having trouble with writing recursive workflows the last week or so (somehow it keeps getting re-enabled/re-deployed). As a result, I've had to restart st2ctl when actionrunners were pegging the CPU a few times. I'm not sure if there could have been a bad state or some persistence lost in the triggers after my restarts. (Specifically, I believe that I did a `st2ctl restart` on the two stackstorm nodes yesterday afternoon but did not run a `st2ctl reload --register-all`; I would assume that's not required to fix/remap cron trigger types to triggers etc, but this may be relevant since the updated rule fired correctly.\r\n\r\nI'm tempted to blow away this cluster state and rebuild. I don't know what kinda funky state is going on right now.\r\n\r\nI'm not sure where else to look to troubleshoot this but its super concerning for our use case. Help?"},"comment":{"url":"https://api.github.com/repos/StackStorm/st2/issues/comments/227788707","html_url":"https://github.com/StackStorm/st2/issues/2715#issuecomment-227788707","issue_url":"https://api.github.com/repos/StackStorm/st2/issues/2715","id":227788707,"user":{"login":"codyaray","id":44062,"avatar_url":"https://avatars.githubusercontent.com/u/44062?v=3","gravatar_id":"","url":"https://api.github.com/users/codyaray","html_url":"https://github.com/codyaray","followers_url":"https://api.github.com/users/codyaray/followers","following_url":"https://api.github.com/users/codyaray/following{/other_user}","gists_url":"https://api.github.com/users/codyaray/gists{/gist_id}","starred_url":"https://api.github.com/users/codyaray/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/codyaray/subscriptions","organizations_url":"https://api.github.com/users/codyaray/orgs","repos_url":"https://api.github.com/users/codyaray/repos","events_url":"https://api.github.com/users/codyaray/events{/privacy}","received_events_url":"https://api.github.com/users/codyaray/received_events","type":"User","site_admin":false},"created_at":"2016-06-22T15:52:32Z","updated_at":"2016-06-22T15:52:32Z","body":"Actually, looks like this failed at a different spot this time.\r\n\r\n```\r\n2016-06-22 06:30:00,018 140040664910416 ERROR consumers [-] StagedQueueConsumer failed to process message:\r\n```\r\n\r\ninstead of\r\n\r\n```\r\n2016-05-26 02:15:00,010 140197381803856 ERROR worker [-] Failed to create trigger_instance\r\n```\r\n\r\nClosing issue and creating new one."}}
{"actor":{"display_login":"codyaray"}}