Daily wake-up routine not working after update

Tom Elliott

@altitudehack What about output of:

systemctl status -l FOGScheduler.service?

altitudehack

# systemctl status -l FOGScheduler.service
● FOGScheduler.service - FOGScheduler
   Loaded: loaded (/usr/lib/systemd/system/FOGScheduler.service; enabled; vendor preset: disabled)
   Active: active (running) since Tue 2021-03-30 09:24:36 CDT; 2h 20min ago
 Main PID: 14299 (php)
   Memory: 13.6M
   CGroup: /system.slice/FOGScheduler.service
           ├─14299 php /opt/fog/service/FOGTaskScheduler/FOGTaskScheduler
           └─14300 php /opt/fog/service/FOGTaskScheduler/FOGTaskScheduler

Mar 30 09:24:36 fog.my.domain.com systemd[1]: Started FOGScheduler.

altitudehack

@Tom-Elliott I rebooted the server this morning about six minutes prior to the scheduled wake-up time. Still nothing showing in the schedule log:

/var/log/fog/fogscheduler.log
[03-31-21 5:54:00 am] 
==================================
=== ==== ===== ====
=== ========= == === == ===
=== ======== ==== == ==== ===
=== ======== ==== == =========
=== ==== ==== == =========
=== ======== ==== == === ===
=== ======== ==== == ==== ===
=== ========= == === == ===
=== ========== ===== ====
==================================
===== Free Opensource Ghost ======
==================================
============ Credits =============
= https://fogproject.org/Credits =
==================================
== Released under GPL Version 3 ==
==================================


[03-31-21 5:54:00 am] Interface Ready with IP Address: [privateIP]
[03-31-21 5:54:00 am] Interface Ready with IP Address: 127.0.0.1
[03-31-21 5:54:00 am] Interface Ready with IP Address: 127.0.1.1
[03-31-21 5:54:00 am] Interface Ready with IP Address: fog.domain.com
[03-31-21 5:54:00 am] * Starting TaskScheduler Service
[03-31-21 5:54:00 am] * Checking for new items every 60 seconds
[03-31-21 5:54:00 am] * Starting service loop
[03-31-21 5:54:00 am] * 61 tasks found.
[03-31-21 5:54:00 am] * Task run time: Thu, 01 Apr 2021 05:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500
[03-31-21 5:54:00 am] * Task run time: Wed, 31 Mar 2021 06:00:00 -0500

I still have the entries showing up in scheduled tasks:

Tom Elliott

@altitudehack All of the tasks are purely WOL tasks, correct?

Just want clarification as I want to try to clear out the DB of erroneous entries that I suspect are playing a bit of a role in the issue.

Tom Elliott

@altitudehack If you can try:

UPDATE tasks SET taskStateID=5 WHERE taskStateID IN ('0','',NULL,'1','2','3') AND taskTypeID=14;

Then restart FOGScheduler

If you can let us know what your log shows?

Thank you,

altitudehack

@tom-elliott

MariaDB [fog]> UPDATE tasks SET taskStateID=5 WHERE taskStateID IN ('0','',NULL,'1','2','3') AND taskTypeID=14;
Query OK, 0 rows affected, 1 warning (0.000 sec)
Rows matched: 0  Changed: 0  Warnings: 1

And the logs after restarting the service:

/var/log/fog/fogscheduler.log
[03-31-21 7:04:29 am] 
==================================
=== ==== ===== ====
=== ========= == === == ===
=== ======== ==== == ==== ===
=== ======== ==== == =========
=== ==== ==== == =========
=== ======== ==== == === ===
=== ======== ==== == ==== ===
=== ========= == === == ===
=== ========== ===== ====
==================================
===== Free Opensource Ghost ======
==================================
============ Credits =============
= https://fogproject.org/Credits =
==================================
== Released under GPL Version 3 ==
==================================


[03-31-21 7:04:29 am] Interface Ready with IP Address: [localIP]
[03-31-21 7:04:29 am] Interface Ready with IP Address: 127.0.0.1
[03-31-21 7:04:29 am] Interface Ready with IP Address: 127.0.1.1
[03-31-21 7:04:29 am] Interface Ready with IP Address: fog.domain.com
[03-31-21 7:04:29 am] * Starting TaskScheduler Service
[03-31-21 7:04:29 am] * Checking for new items every 60 seconds
[03-31-21 7:04:29 am] * Starting service loop
[03-31-21 7:04:29 am] * 61 tasks found.
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 05:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500
[03-31-21 7:04:29 am] * Task run time: Thu, 01 Apr 2021 06:00:00 -0500

altitudehack

@Tom-Elliott any other places to check? I don’t mind clearing out all scheduled tasks since I don’t have much in there. Just not sure how to do a safe reset.

altitudehack

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

altitudehack

@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

@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

@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

@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

@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

@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

@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

@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

@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

@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

@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

@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.

Daily wake-up routine not working after update

158

11.6k

17.1k

154.6k