Daily wake-up routine not working after update

altitudehack · Apr 22, 2021, 12:22 PM

Seems similar to @Petěrko’s issue over at:
https://forums.fogproject.org/topic/15342/scheduled-wake-on-lan

altitudehack · Apr 23, 2021, 12:01 PM

@Tom-Elliott Just an update that this is still occurring after the latest update to dev branch 1.5.9.67. The scheduler log spits out a one-time block of text upon service start, but nothing else:

/var/log/fog/fogscheduler.log

[04-21-21 4:38:37 pm] 
==================================
=== ==== ===== ====
=== ========= == === == ===
=== ======== ==== == ==== ===
=== ======== ==== == =========
=== ==== ==== == =========
=== ======== ==== == === ===
=== ======== ==== == ==== ===
=== ========= == === == ===
=== ========== ===== ====
==================================
===== Free Opensource Ghost ======
==================================
============ Credits =============
= https://fogproject.org/Credits =
==================================
== Released under GPL Version 3 ==
==================================


[04-21-21 4:38:37 pm] Interface Ready with IP Address: [localIP]
[04-21-21 4:38:37 pm] Interface Ready with IP Address: 127.0.0.1
[04-21-21 4:38:37 pm] Interface Ready with IP Address: 127.0.1.1
[04-21-21 4:38:37 pm] Interface Ready with IP Address: fog.my.domain.com
[04-21-21 4:38:37 pm] * Starting TaskScheduler Service
[04-21-21 4:38:37 pm] * Checking for new items every 60 seconds
[04-21-21 4:38:37 pm] * Starting service loop
[04-21-21 4:38:37 pm] * 61 tasks found.
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 05:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500
[04-21-21 4:38:37 pm] * Task run time: Thu, 22 Apr 2021 06:00:00 -0500

Tom Elliott · Apr 23, 2021, 12:05 PM

@altitudehack From the sounds of things, the scheduled task is essentially generating subsequent scheduled tasks which then causes a weird freeze to the system.

I base this on the fact that it appears to generate the task (in scheduled tasks) as a host task, when the originating “creator” is a group task?

I haven’t delved into the code for 1.5.x in a while as I’ve been working mainly with the 1.6 code base.

Tom Elliott · Apr 23, 2021, 1:03 PM

@altitudehack While I’m not holding my breath too much, please try installing the latest. I’ve tried to be a bit more verbose in the logging to hopefully narrow down where the error is happening.

If you can run the update and post the logs after the service is restarted?

Thank you,

altitudehack · Apr 23, 2021, 1:03 PM

@tom-elliott Good morning Tom! Thanks for your thoughts on this, and for checking into the scheduler’s code. There were two scheduled tasks - one for a group and one for an individual PC. I deleted both of them before seeing your latest update, so now there are zero scheduled tasks:

I ran the upgrade to version 1.5.9.69 and this is the contents of my log file:

/var/log/fog/fogscheduler.log

[04-23-21 7:57:42 am] 
==================================
=== ==== ===== ====
=== ========= == === == ===
=== ======== ==== == ==== ===
=== ======== ==== == =========
=== ==== ==== == =========
=== ======== ==== == === ===
=== ======== ==== == ==== ===
=== ========= == === == ===
=== ========== ===== ====
==================================
===== Free Opensource Ghost ======
==================================
============ Credits =============
= https://fogproject.org/Credits =
==================================
== Released under GPL Version 3 ==
==================================


[04-23-21 7:57:42 am] Interface Ready with IP Address: [privateIP]
[04-23-21 7:57:42 am] Interface Ready with IP Address: 127.0.0.1
[04-23-21 7:57:42 am] Interface Ready with IP Address: 127.0.1.1
[04-23-21 7:57:42 am] Interface Ready with IP Address: fog.my.domain.com
[04-23-21 7:57:42 am] * Starting TaskScheduler Service
[04-23-21 7:57:42 am] * Checking for new items every 60 seconds
[04-23-21 7:57:42 am] * Starting service loop
[04-23-21 7:57:42 am] * 59 tasks found.
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500
[04-23-21 7:57:42 am] * Task run time: Mon, 26 Apr 2021 06:00:00 -0500

Thank you!

Tom Elliott · Apr 23, 2021, 3:19 PM

@altitudehack I know I’m asking a lot, but please bare with me.

Can you upgrade and try again?

I added more logging and all that too. No real change in operation, just more logging to try to narrow further.

Thank you,

altitudehack · Apr 23, 2021, 4:46 PM

@tom-elliott said in Daily wake-up routine not working after update:

I know I’m asking a lot, but please bare with me.

You are so generous with your time and resources, and polite to boot. I can’t tell you how much I appreciate you digging into this particular issue for me.
I’ve been waking up early to click the WakeUp link for all our employees once the functionality stopped working.

Here’s what’s in the logs after updating to the .70 branch:

...
===== Free Opensource Ghost ======
==================================
============ Credits =============
= https://fogproject.org/Credits =
==================================
== Released under GPL Version 3 ==
==================================


[04-23-21 11:37:32 am] Interface Ready with IP Address: [privateIP]
[04-23-21 11:37:32 am] Interface Ready with IP Address: 127.0.0.1
[04-23-21 11:37:32 am] Interface Ready with IP Address: 127.0.1.1
[04-23-21 11:37:32 am] Interface Ready with IP Address: fog.my.domain.com
[04-23-21 11:37:32 am] * Starting TaskScheduler Service
[04-23-21 11:37:32 am] * Checking for new items every 60 seconds
[04-23-21 11:37:32 am] * Starting service loop
[04-23-21 11:37:32 am] * 59 tasks found.

Again, I deleted the scheduled tasks I had in there so I’m not sure where the 59 task count is coming from.

Tom Elliott · Apr 23, 2021, 4:53 PM

@altitudehack One more time please?

Yes I try to be polite. I realize this isn’t a scenario anybody wants and also understand peoples work lives.

altitudehack · Apr 23, 2021, 5:02 PM

@tom-elliott Well this is getting interesting:

[04-23-21 11:58:31 am] 
==================================
=== ==== ===== ====
=== ========= == === == ===
=== ======== ==== == ==== ===
=== ======== ==== == =========
=== ==== ==== == =========
=== ======== ==== == === ===
=== ======== ==== == ==== ===
=== ========= == === == ===
=== ========== ===== ====
==================================
===== Free Opensource Ghost ======
==================================
============ Credits =============
= https://fogproject.org/Credits =
==================================
== Released under GPL Version 3 ==
==================================


[04-23-21 11:58:31 am] Interface Ready with IP Address: [privateIP]
[04-23-21 11:58:31 am] Interface Ready with IP Address: 127.0.0.1
[04-23-21 11:58:31 am] Interface Ready with IP Address: 127.0.1.1
[04-23-21 11:58:31 am] Interface Ready with IP Address: fog.my.domain.com
[04-23-21 11:58:31 am] * Starting TaskScheduler Service
[04-23-21 11:58:31 am] * Checking for new items every 60 seconds
[04-23-21 11:58:31 am] * Starting service loop
[04-23-21 11:58:31 am] * 59 tasks found.
[04-23-21 11:58:31 am] * Running loop of all tasks.
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 52 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 54 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 62 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 65 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 67 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 81 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 82 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 83 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 84 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 85 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 86 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
[04-23-21 11:58:31 am] * 87 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement
...
[04-23-21 11:58:31 am] * 94 Does not appear to be valid
[04-23-21 11:58:31 am] * Attempting to run checks for PowerManagement

It also helps that you guys have made the upgrade process so painless

Tom Elliott · Apr 23, 2021, 5:25 PM

@altitudehack What does it look like now? (after updating/installing again of course.)

(These tasks all appear to be powermanagement tasks.) So I separated the logic that handles power management vs scheduled tasks.

Tom Elliott · Apr 23, 2021, 5:32 PM

@altitudehack Just cause you like that command so much, here’s a pretty cool command to loop through. Does the same, but in a more compressed format.

for i in FOG{Scheduler,PingHosts,{Image,Snapin}Replicator,MulticastManager,ImageSize,SnapinHash}.service; do systemctl restart $i; done

Tom Elliott · Apr 23, 2021, 5:49 PM

@altitudehack To further help. now that we know the power management tasks were what was causing this you can clean this up with:

TRUNCATE TABLE powerManagement

Mind you this will completely clear out the power management table. I don’t know if these tasks were intentionally created or if this was how you were configuring WOL tasks for these hosts?

altitudehack · Apr 23, 2021, 7:52 PM

@tom-elliott said in Daily wake-up routine not working after update:

What does it look like now?

[04-23-21 1:27:29 pm] Interface Ready with IP Address: [privateIP]
[04-23-21 1:27:29 pm] Interface Ready with IP Address: 127.0.0.1
[04-23-21 1:27:29 pm] Interface Ready with IP Address: 127.0.1.1
[04-23-21 1:27:29 pm] Interface Ready with IP Address: fog.my.domain.com
[04-23-21 1:27:29 pm] * Starting TaskScheduler Service
[04-23-21 1:27:29 pm] * Checking for new items every 60 seconds
[04-23-21 1:27:29 pm] * Starting service loop
[04-23-21 1:27:29 pm] * 59 tasks found.
[04-23-21 1:27:29 pm] * 0 scheduled task(s) to run.
[04-23-21 1:27:29 pm] * 59 power management task(s) to run.

altitudehack · Apr 23, 2021, 7:54 PM

@tom-elliott I created the tasks through the GUI to wake the groups up. After the last update, I see a bunch of this instead:

[04-23-21 2:51:51 pm] Interface not ready, waiting for it to come up:

Tom Elliott · Apr 23, 2021, 8:14 PM

@altitudehack What I meant about the GUI wake, was this a group -> task -> wol -> Scheduled as cron or Group -> Power Management -> Cron time -> WOL?

You should be able to run systemctl restart FOGScheduler to fix the interfact not ready message. This shouldn’t be anything programming wise as that portion hasn’t changed.

altitudehack · Apr 23, 2021, 8:18 PM

@tom-elliott Group -> Power Management -> Cron time -> WOL. But I deleted it earlier today so I’m not sure why it’s still there.
After restarting the service the logs look like this:

[04-23-21 3:15:06 pm] * Starting TaskScheduler Service
[04-23-21 3:15:06 pm] * Checking for new items every 60 seconds
[04-23-21 3:15:06 pm] * Starting service loop
[04-23-21 3:15:06 pm] * 59 tasks found.
[04-23-21 3:15:06 pm] * 0 scheduled task(s) to run.
[04-23-21 3:15:06 pm] * 59 power management task(s) to run.

Tom Elliott · Apr 23, 2021, 8:23 PM

@altitudehack Well when done through Group all it does is create individual tasks for each of the hosts in the group (hence the high number)

As you’re using the 1.5.9.72 version, I think there’s a potential issue with deleting group items in such a way. I’m assuming going back to the group -> power management after you have “deleted it” it has the same task reappeared?

I still believe you will need to clean out the powerManagement table using the

TRUNCATE TABLE powerManagement

Then restart the FOGScheduler service and you should then see: 0 scheduled task(s) to run and 0 power management task(s) to run.

Then I think you should use Group -> Task -> Advanced -> WOL. This will create a single task that does the exact same thing (but simpler) for your hosts in that group. It won’t see x number. it will show 1 scheduled task to run.

altitudehack · Apr 23, 2021, 8:23 PM

I went ahead and re-created the wakeup cron using the breadcrumbs described and nothing happened in the logs for ~five minutes. So I restarted the service again and now have 79 tasks found:

[04-23-21 3:21:35 pm] * Starting TaskScheduler Service
[04-23-21 3:21:35 pm] * Checking for new items every 60 seconds
[04-23-21 3:21:35 pm] * Starting service loop
[04-23-21 3:21:35 pm] * 79 tasks found.
[04-23-21 3:21:35 pm] * 0 scheduled task(s) to run.
[04-23-21 3:21:35 pm] * 79 power management task(s) to run.

Tom Elliott · Apr 23, 2021, 8:27 PM

@altitudehack I am running a test and just wanted to follow similar route:

Here’s what I see:

[04-23-21 3:25:49 pm]  * Starting TaskScheduler Service
[04-23-21 3:25:49 pm]  * Checking for new items every 60 seconds
[04-23-21 3:25:49 pm]  * Starting service loop
[04-23-21 3:25:49 pm]  * 1 task found.
[04-23-21 3:25:49 pm]  * Power Management Task run time: Fri, 23 Apr 2021 15:50:00 -0500
[04-23-21 3:25:49 pm]  * This is a cron style task that should not run now.
[04-23-21 3:26:49 pm]  * 1 task found.
[04-23-21 3:26:49 pm]  * Power Management Task run time: Fri, 23 Apr 2021 15:50:00 -0500
[04-23-21 3:26:49 pm]  * This is a cron style task that should not run now.

altitudehack · Apr 23, 2021, 8:27 PM

@tom-elliott said in Daily wake-up routine not working after update:

TRUNCATE TABLE powerManagement

I missed that in your previous post. Thank you! I think this one’s solved!

[04-23-21 3:25:27 pm] * Starting TaskScheduler Service
[04-23-21 3:25:27 pm] * Checking for new items every 60 seconds
[04-23-21 3:25:27 pm] * Starting service loop
[04-23-21 3:25:27 pm] * No tasks found!
[04-23-21 3:26:27 pm] * 1 task found.
[04-23-21 3:26:27 pm] * 1 scheduled task(s) to run.
[04-23-21 3:26:27 pm] * 0 power management task(s) to run.

I’ll find out Monday. Have a great weekend, @Tom-Elliott !

Daily wake-up routine not working after update

206

12.0k

17.3k

155.2k