Recurring logics Fails with Smart Proxy Errors

Problem:

Recurring logics wont work in the change of the date.
Example:
Last occurrence: 2022-02-17 00:15:02 +0100
Next occurrence: 2022-02-16 23:25:00 +0100

If you disable this recurring logic and try to reanable it the following error occurs :
ERF28-1357 [ForemanTasks::RecurringLogicCancelledException]: Cannot update a cancelled Recurring Logic.

Expected outcome:
The Recurring logics work even if the date changes

Foreman and Proxy versions:

Foreman foreman-3.1.1-1.el7.noarch
Smart proxy: 3.1.1
Katello: katello-4.3.0-1.el7.noarch

Distribution and version:
CentOS 7 with latest stable installation

Other relevant data:
We Updated the System from foreman 2.5 to 3.0 and then directly to 3.1

In the Production Log we see then some errors like the one below:

2022-02-18T00:24:36 [I|bac|4d8319e1] Task {label: Actions::RemoteExecution::RunHostJob, id: 7121b685-a61f-452e-9fdf-d304d16cd1d0, execution_plan_id: 07885e6a-55be-4a25-8165-de51bd3c5929} state changed: stopped  
result: error
2022-02-18T00:24:36 [E|bac|4d8319e1] Proxy task gone missing from the smart proxy (Actions::ProxyAction::ProxyActionMissing)
 4d8319e1 | 
2022-02-18T00:24:36 [E|bac|4d8319e1] Proxy task gone missing from the smart proxy (Actions::ProxyAction::ProxyActionMissing)
 4d8319e1 | 
2022-02-18T00:24:36 [E|bac|4d8319e1] Proxy task gone missing from the smart proxy (Actions::ProxyAction::ProxyActionMissing)
 4d8319e1 | 

A Task shows the following Error:

RuntimeError: The only applicable proxy hostname.tld is down

Any suggestion what could cause these errors and how to fix them?

As I talked to a colleague of the thread author, just some details to add.

The scheduling is 25,55 * * * *, the last execution is running 20 minutes which is likely a timeout caused by Foreman being backup-ed with foreman-maintain in this timeframe. So it could also be some problem of Dynflow not correctly picking up the tasks again, as I think handling midnight should not be the problem.

@aruzicka do you have any idea how to debug this further or what could be the cause?

Not really no. ForemanTasks::RecurringLogicCancelledException means the recurring logic has no scheduled task so there’s nothing to modify. If you grep for Failed to run hook 'trigger_repeat' in production.log you might get some hits. Sadly unless you had debug logging turned on, you won’t get why.

It might be related to this thread https://community.theforeman.org/t/recurring-logic-next-occurence-is-older-than-last-occurence but I haven’t had any luck reproducing that one either, let alone fixing it.

This shouldn’t be related to recurring logics in any way.

Although I can’t rule this out, I’m inclined to say that this is not the case. Most likely foreman tried to schedule another repetition and failed. After that, the recurring logic got stuck and there’s no way how to revive it once the in-flight task data is gone.

If what I wrote above holds (failed to run hook in logs should confirm it), then there really isn’t a way how to rescue the situation and you’d be better off just recreating the jobs from scratch.

1 Like

Hi aruzickaaruzicka,

unfortunally we haven’t found any log-entry from the last 14 days with Failed to run hook 'trigger_repeat'.
So there are no Log Entrys befor or after the updates of the System.

What we see is, that our Backup is running about half an hour before of the recurring logics.
In the Picture below you see one of our problematic recurring logic.

Our Backup is configured like this:
Cronjob:

#Ansible: katello_backup
17 21 * * * root /usr/local/bin/katello_backup.sh >/dev/null

Backup-Script:

#!/bin/sh

rm -rf /var/backup/katello/*
foreman-maintain backup offline -y --skip-pulp-content /var/backup/katello >/dev/null

exit 0

Could this may cause any Problems?
If we activate the debug logging, on wich level should we activate it?

unfortunally we haven’t found any log-entry from the last 14 days with Failed to run hook 'trigger_repeat'.

Could you run the following sql query for me and post results?

select * from dynflow_delayed_plans;

Right now from what you’ve shared here I can’t really tell in which state the whole thing is and because of that I can’t really tell what to look out for in the logs. The output of the query is essential, whole production.log would be helpful.

Could this may cause any Problems?

Hard to say. Any time you stop it while it is actively doing something is potentially risky.

If we activate the debug logging, on wich level should we activate it?

I don’t think I follow. Debug is the level

Could you run the following sql query for me and post results?

Sure here is the Output, hope it helps:

         execution_plan_uuid          |          start_at          | start_before |               args_serializer                | frozen |                                                                        
                                                                                                                                                                                                                   
           serialized_args                                                                                                                                                                                         
                                                                                                              | data 
--------------------------------------+----------------------------+--------------+----------------------------------------------+--------+------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------+------
 e23f55f1-a286-4767-adb9-9168eb9b3955 | 2022-03-01 11:36:36.84632  |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373b653746f72656456616c756573436c65616e75704a6f6
2a66a6f625f6964d92465323366353566312d613238362d343736372d616462392d393136386562396233393535af70726f76696465725f6a6f625f6964d92465323366353566312d613238362d343736372d616462392d393136386562396233393535aa7175657565
5f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e74739181d9205f616a5f686173685f776974685f696e646966666572656e745f616363657373c3aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66
c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7175657565645f6174b4323032322d30322d32385432333a33363a33365a | 
 ec9e7808-5ae5-4660-9377-3bc28865b56d | 2022-03-01 11:36:51.720604 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373b653746f72656456616c756573436c65616e75704a6f6
2a66a6f625f6964d92465633965373830382d356165352d343636302d393337372d336263323838363562353664af70726f76696465725f6a6f625f6964d92465633965373830382d356165352d343636302d393337372d336263323838363562353664aa7175657565
5f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e74739181d9205f616a5f686173685f776974685f696e646966666572656e745f616363657373c3aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66
c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7175657565645f6174b4323032322d30322d32385432333a33363a35315a | 
 918b72bb-de23-44ad-a93b-bb794e139cdb | 2022-03-01 11:36:51.739335 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373b64372656174655273734e6f74696669636174696f6e7
3a66a6f625f6964d92439313862373262622d646532332d343461642d613933622d626237393465313339636462af70726f76696465725f6a6f625f6964d92439313862373262622d646532332d343461642d613933622d626237393465313339636462aa7175657565
5f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e74739181d9205f616a5f686173685f776974685f696e646966666572656e745f616363657373c3aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66
c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7175657565645f6174b4323032322d30322d32385432333a33363a35315a | 
 bfe0552b-4769-438b-b83e-7dbb00e3e85e | 2022-03-01 11:37:06.717954 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373b64372656174655273734e6f74696669636174696f6e7
3a66a6f625f6964d92462666530353532622d343736392d343338622d623833652d376462623030653365383565af70726f76696465725f6a6f625f6964d92462666530353532622d343736392d343338622d623833652d376462623030653365383565aa7175657565
5f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e74739181af5f616a5f73796d626f6c5f6b65797390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a
3555443ab656e7175657565645f6174b4323032322d30322d32385432333a33373a30365a                                     | 
 1b40cf53-a63d-4bd9-84ff-418af1edbeda | 2022-03-01 11:37:21.872381 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373bb53656e64457870697265536f6f6e4e6f74696669636
174696f6e73a66a6f625f6964d92431623430636635332d613633642d346264392d383466662d343138616631656462656461af70726f76696465725f6a6f625f6964d92431623430636635332d613633642d346264392d383466662d343138616631656462656461aa
71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7175657565645
f6174b4323032322d30322d32385432333a33373a32315a                                                               | 
 d7001504-a826-4332-8aac-2d6fd0eeea0f | 2022-03-01 11:37:36.770009 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373bb53656e64457870697265536f6f6e4e6f74696669636
174696f6e73a66a6f625f6964d92464373030313530342d613832362d343333322d386161632d326436666430656565613066af70726f76696465725f6a6f625f6964d92464373030313530342d613832362d343333322d386161632d326436666430656565613066aa
71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7175657565645
f6174b4323032322d30322d32385432333a33373a33365a                                                               | 
 28ec021a-3d3a-435e-bbcf-d085a92756a5 | 2022-03-01 11:37:51.772128 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373bb53656e64457870697265536f6f6e4e6f74696669636
174696f6e73a66a6f625f6964d92432386563303231612d336433612d343335652d626263662d643038356139323735366135af70726f76696465725f6a6f625f6964d92432386563303231612d336433612d343335652d626263662d643038356139323735366135aa
71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7175657565645
f6174b4323032322d30322d32385432333a33373a35315a                                                               | 
 7c8180a3-6650-4373-b905-7e694d532893 | 2022-03-01 11:40:37.098172 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373d92043726561746550756c704469736b53706163654e6
f74696669636174696f6e73a66a6f625f6964d92437633831383061332d363635302d343337332d623930352d376536393464353332383933af70726f76696465725f6a6f625f6964d92437633831383061332d363635302d343337332d623930352d37653639346435
3332383933aa71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7
175657565645f6174b4323032322d30322d32385432333a34303a33375a                                                   | 
 8b65cce3-42bf-4732-9e29-a0456b91eff6 | 2022-03-01 11:40:37.158469 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373d92043726561746550756c704469736b53706163654e6
f74696669636174696f6e73a66a6f625f6964d92438623635636365332d343262662d343733322d396532392d613034353662393165666636af70726f76696465725f6a6f625f6964d92438623635636365332d343262662d343733322d396532392d61303435366239
3165666636aa71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7
175657565645f6174b4323032322d30322d32385432333a34303a33375a                                                   | 
 374a6ac6-ba34-4afe-9225-affa4f806acb | 2022-03-01 11:40:37.251361 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373d92043726561746550756c704469736b53706163654e6
f74696669636174696f6e73a66a6f625f6964d92433373461366163362d626133342d346166652d393232352d616666613466383036616362af70726f76696465725f6a6f625f6964d92433373461366163362d626133342d346166652d393232352d61666661346638
3036616362aa71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab656e7
175657565645f6174b4323032322d30322d32385432333a34303a33375a                                                   | 
 6d06de5a-6d04-4b7c-b5fd-186d44c60cb8 | 2022-03-02 01:37:00        |              | Actions::Serializers::ActiveRecordSerializer | f      | \x9183b46163746976655f7265636f72645f6f626a656374c3aa636c6173735f6e616d6
5b14b6174656c6c6f3a3a53796e63506c616ea2696402                                                                                                                                                                      
                                                                                                                                                                                                                   
                                                                                                              | 
 ffbabc25-a86a-47e3-9602-053c941885f2 | 2022-02-21 21:15:00        |              | Actions::Serializers::ActiveRecordSerializer | t      | \x9183b46163746976655f7265636f72645f6f626a656374c3aa636c6173735f6e616d6
5aa5363634163636f756e74a2696401                                                                                                                                                                                    
                                                                                                                                                                                                                   
                                                                                                              | 
 363fbe9b-af96-4a83-b243-4a4f6eca1332 | 2022-02-21 21:15:00        |              | Actions::Serializers::ActiveRecordSerializer | t      | \x9183b46163746976655f7265636f72645f6f626a656374c3aa636c6173735f6e616d6
5aa5363634163636f756e74a2696401                                                                                                                                                                                    
                                                                                                                                                                                                                   
                                                                                                              | 
 3a41d344-2e43-42f4-8026-f20501b1f5a2 | 2022-02-21 21:44:00        |              | Actions::Serializers::ActiveRecordSerializer | t      | \x9183b46163746976655f7265636f72645f6f626a656374c3aa636c6173735f6e616d6
5b14b6174656c6c6f3a3a53796e63506c616ea2696403                                                                                                                                                                      
                                                                                                                                                                                                                   
                                                                                                              | 
 67711e3a-5333-43fd-85b9-f667b053d7cb | 2022-03-01 11:16:03.393874 |              | Dynflow::Serializers::Noop                   | f      | \x918ba96a6f625f636c617373d922437265617465457870697265644d616e696665737
44e6f74696669636174696f6e73a66a6f625f6964d92436373731316533612d353333332d343366642d383562392d663636376230353364376362af70726f76696465725f6a6f625f6964d92436373731316533612d353333332d343366642d383562392d6636363762
30353364376362aa71756575655f6e616d65a764656661756c74a87072696f72697479c0a9617267756d656e747390aa657865637574696f6e7300b4657863657074696f6e5f657865637574696f6e7380a66c6f63616c65a2656ea874696d657a6f6e65a3555443ab6
56e7175657565645f6174b4323032322d30322d32385431313a31363a30335a                                               | 
(15 rows)

This just confirms what I suspected previously. The recurring logics (the part that keeps track) got out of sync with delayed plans (the actual runtime unit representing something to happen in the future). Usually, this manifests itself with the trigger_repeat error, but it is possible that if you stop the workers at the right time, it will just fail silently.

I know this is a rather bad workaround, but would it be possible for you not to take offline backups while actively using the system?