[Git 5864] FOGTaskScheduler consumes 100% cpu for about 2 minutes rests for a bit then tries again

[george1421]

I just updated the dev box to 5864 and I noticed that the FOGTaskScheduler service consumes 100% cpu for 2 minutes then rests for 1-2 minutes then comes back for another 2 minutes. This is a continual cycle.

This is the content of the task scheduler log.

[01-05-16 7:37:05 pm] Interface Ready with IP Address: 192.168.1.88
[01-05-16 7:37:05 pm]  * Starting TaskScheduler Service
[01-05-16 7:37:05 pm]  * Checking for new items every 60 seconds
[01-05-16 7:37:05 pm]  * Starting service loop
[01-05-16 7:37:05 pm]  * 1 active task awaiting check-in.
[01-05-16 7:37:05 pm]  | Sending WOL Packet(s)
[01-05-16 7:37:05 pm]           - Host: MDTx86Golden WOL sent to all macs associated
[01-05-16 7:37:06 pm]  * 1 task found.
[01-05-16 7:40:23 pm]  * Task run time: Wed, 31 Dec 1969 19:00:00 -0500
[01-05-16 7:40:23 pm]  * Found a task that should run...
[01-05-16 7:40:23 pm]            - Is a host based task.
[01-05-16 7:40:23 pm]            - Task Started for host MDTx86Target!
[01-05-16 7:40:23 pm]            - Cron style - No cleaning!
[01-05-16 7:41:23 pm]  * 1 active task awaiting check-in.
[01-05-16 7:41:23 pm]  | Sending WOL Packet(s)
[01-05-16 7:41:23 pm]           - Host: MDTx86GOLD WOL sent to all macs associated
[01-05-16 7:41:24 pm]  * 1 task found.

To clarify a bit, I tried to launch the WOL task about 3 weeks ago to start up a downed computer and the task still is listed in the Active Tasks. Killing that active task did not change the CPU usage for the FOGTaskScheduler task. Now that I think about this a bit more, when I launched the installer for this version of the trunk it took about 20 seconds for any text to be displayed by the installer. I first thought something was wrong with the installer script, but it may have been this background task consuming 100% of the CPU. So its possible that this has been an issue since mid Dec when I last upgraded the dev box.

[Wayne Workman]

@george1421 said:

when I launched the installer for this version of the trunk it took about 20 seconds for any text to be displayed by the installer.

I too have experienced this recently with FOG Trunk, but it wasn’t 20 seconds. Maybe 4 or 5 for me - but still significantly longer to start than before.

Also - just before school’s holiday break, there was work done to get cron WOL to work for groups. My group cron WOL tasks don’t show up in scheduled tasks and at the moment I can’t upgrade at work.

[george1421]

Wow the forum site crashed as I was submitting a follow up.

It does appear to be something related to the cron task scheduler. I found another task hanging about on the system I tried launch a cron style wol and then an active wol for this computer with no luck.

When I go into Task Management -> Scheduled task strange things happen. The http service jumps to 100% and stays there (along side the fogtaskscheduler. Eventually something shows up in the list (the wol task I created 3 weeks ago). It takes several minutes to show the pending/waiting task. After several minutes of waiting for the Scheduled Tasks pane to populate several new http processes are spawned. I think they are related to the pop up no tasks found that flashes (up at the top) when you are on the tasks menus. Eventually when that pending task shows that no tasks found changes to loading with a revolving arrow. That is when the real fun starts where a new httpd process is started every 2-3 seconds filling up top with httpd processes.

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 1883 apache    20   0  332m  20m 3820 R  7.7  1.1   0:22.71 httpd
 1884 apache    20   0  332m  20m 4004 R  7.7  1.1   0:15.61 httpd
 1885 apache    20   0  332m  20m 3828 R  7.7  1.1   3:01.27 httpd
 2220 apache    20   0  332m  20m 3552 R  7.7  1.1   0:09.17 httpd
 2227 apache    20   0  332m  20m 3552 R  7.7  1.1   0:07.52 httpd
 2234 apache    20   0  332m  20m 3552 R  7.7  1.1   0:06.09 httpd
 2252 apache    20   0  332m  20m 3552 R  7.7  1.1   0:02.77 httpd
 2274 apache    20   0  332m  20m 3552 R  7.7  1.1   0:00.63 httpd
 1878 apache    20   0  332m  20m 4012 R  7.4  1.1   0:27.58 httpd
 1881 apache    20   0  427m  20m 4028 R  7.4  1.1   0:14.06 httpd
 1882 apache    20   0  427m  20m 4044 R  7.4  1.1   0:18.21 httpd
 2236 apache    20   0  332m  20m 3552 R  7.4  1.1   0:05.30 httpd
 2238 apache    20   0  332m  20m 3552 R  7.4  1.1   0:04.86 httpd
 2245 apache    20   0  332m  20m 3552 R  7.4  1.1   0:03.75 httpd
 2259 apache    20   0  426m  19m 3816 R  7.4  1.0   0:00.34 httpd
 2263 apache    20   0  332m  20m 3552 R  7.4  1.1   0:01.86 httpd
 1879 apache    20   0  332m  20m 4136 R  7.1  1.1   0:31.02 httpd
 1880 apache    20   0  332m  20m 4004 R  7.1  1.1   0:16.85 httpd
 2216 apache    20   0  332m  20m 3552 R  7.1  1.1   0:10.62 httpd
 2218 apache    20   0  332m  20m 3552 R  7.1  1.1   0:09.63 httpd
 2225 apache    20   0  332m  20m 3552 R  7.1  1.1   0:07.96 httpd
 2229 apache    20   0  332m  20m 3552 R  7.1  1.1   0:06.54 httpd
 2243 apache    20   0  332m  20m 3552 R  7.1  1.1   0:04.18 httpd
 2250 apache    20   0  332m  20m 3552 R  7.1  1.1   0:03.19 httpd
 2254 apache    20   0  332m  20m 3552 R  7.1  1.1   0:02.28 httpd
 2268 apache    20   0  332m  20m 3552 R  7.1  1.1   0:01.42 httpd

Rebooting the fog server puts me back in the same condition. The other anomoliy I found is when eventually the page loads and it showed me I had a wakeup task scheduled, it has a start time of 46 years ago. Also noted in the fogtaskscheduler log with the task run time of 1969. (I do remember that year, and I’m pretty sure I didn’t launch the wol request then).

[george1421]

I ended up having to go into the database and manually deleting that 46 year old task. While that solves my problem, I still think there is something wonky with the task scheduler. Either I keyed in the wrong / unexpected values for that cron scheduled task or something is confused in the code.

[Wayne Workman]

@george1421 said:

he other anomoliy I found is when eventually the page loads and it showed me I had a wakeup task scheduled, it has a start time of 46 years ago. Also noted in the fogtaskscheduler log with the task run time of 1969. (I do remember that year, and I’m pretty sure I didn’t launch the wol request then).

My fiance, who “knows nothing about computers” just informed me that this is due to the Unix Epoch bug - and that facebook experienced the same issue today as well, saying people have been friends for 46 years and such, when they are not even 46 years old.

Unix time is interesting, I studied up on it in college for time keeping in MySQL. I haven’t even thought about the unix epoch since then.
https://en.wikipedia.org/wiki/Unix_time

Reading up on it, it has something to do with start times/dates being stored as 0 in Unix time.

[george1421]

@Wayne-Workman You better marry that girl, or I’m going to offer her a job up north (in snowy Michigan) in my group.

I think there is something with the tasks pages. When I just sit on the tasks page the little popup 0 active tasks found is consuming about 8% cpu according to top. On my first test of this that 8% cpu task persisted even when I moved to another page. Then I was getting a session time out popup. Closing the browser and going back in still netted the session timeout. I had to actually log out for that session cookie to reset.

[Edit] After additional testing that 8% httpd process seems to be related to that popup message (i.e. tasks/session/loading/load failed) [/Edit]