jhuckaby
commented
6 years ago Thank you for the bug reports. I think there are two separate issues going on there. The first one sounds like filesystem corruption, which can happen if Cronicle crashes, is uncleanly shut down or the server is rebooted while data was being written to disk. Unfortunately the only real fix here is to delete your historical job data. If you don't want to delete your individual job logs and metadata, you can just delete and recreate the main completed list itself:
/opt/cronicle/bin/control.sh stop
/opt/cronicle/bin/storage-cli.js list_delete logs/completed
/opt/cronicle/bin/storage-cli.js list_create logs/completed
/opt/cronicle/bin/control.sh startThe second issue you reported is quite concerning (the ticker stopping), as I have just now run into this same thing on 4 different servers, all CentOS and all Node.js v10. I am actively investigating it, but it is very difficult to track down, because at least in my case it takes 20+ days of continuous running to reproduce it.
I'll let you know if/when I resolve this, and I am going to add a large, loud disclaimer to the top of the main repository README, alerting people to this one. This is really bad.
Here is more information about the bug:
Okay, so I am seeing more and more evidence that the root cause is in fact the master setInterval() timer, which actually lives in pixl-server, not even in Cronicle. Cronicle just uses it for a variety of things.
(1) The detached job queue system in Cronicle, which polls the /opt/cronicle/queue directory every minute, looking for detached job update JSON files, was clearly not working on bidi or dev05. This system works off the master pixl-server 1s tick timer.
(2) Cronicle's daily log rotation system, which runs on every server, also uses the pixl-server 1s tick timer, specifically the "day" event which is emitted at midnight, was not working on dev05 nor bidi. Both of them had old logs from August 21 (meaning the "day" tick did not fire at midnight on Aug 22). This is also more evidence that points directly at the master pixl-server 1s tick timer.
(3) When I logged into Cronicle on Stage, I noticed that the clock in the browser UI was not ticking up. The animated clock logo was not moving, and the time in the top-right was not changing. These things are all triggered by server-sent events, that work off the master pixl-server 1s tick timer.
These all point towards the master pixl-server 1s tick timer magically stopping for some reason. This is a global setInterval() timer that is set up at startup, and lives forever, until shutdown. I cannot fathom anything in code ever canceling this interval.
https://github.com/jhuckaby/pixl-server/blob/master/server.js#L272
Okay, I am seeing strong evidence that all the Node.js timers were failing. Check this out. In Stage, I see this logged:
[1534858789.948][2018-08-21 06:39:49][devrelease.xxx][Cronicle][debug][5][Marking slave as disabled: mgr01.xxx][]
[1534858789.955][2018-08-21 06:39:49][devrelease.xxx][Cronicle][debug][5][Marking slave as disabled: mgr02.xxx][]This is right when the master server lost connectivity with mgr01 and mgr02. Now, the Cronicle code automatically tries to reconnect to lost slaves right after this happens. It reconnects automatically and retries indefinitely. But it never happened. It never even tried once.
Check out the code: https://github.com/jhuckaby/Cronicle/blob/master/lib/comm.js#L231-L237
That bit of code never ran in Stage (i.e. it never logged "Reconnecting to slave:"), and this runs under its own separate setTimeout() call (i.e. not the pixl-server 1s interval timer). Meaning, this is evidence that the entire Node.js timer system got borked.
Furthermore, the other question is WHY did it lose connectivity with mgr01/mgr02 and at the same time as everything else? Well, the answer is again timers, I believe:
[1534858789.948][2018-08-21 06:39:49][devrelease.xxx][Error][error][server][Slave disconnected unexpectedly: mgr01.xxx][]
[1534858789.954][2018-08-21 06:39:49][devrelease.xxx][Error][error][server][Slave disconnected unexpectedly: mgr02.xxx][]As you can see here, devlelease.stage (Cronicle master) says that mgr01 and mgr02 disconnected unexpectedly. But look at what mgr01 and mgr02 have to say about this:
[1534858789.946][2018-08-21 06:39:49][mgr02.xxx][Cronicle][debug][5][Socket.io client disconnected: _IXAzsPZvXRS6aEpAAAA (IP: ::ffff:100.xx)][]
[1534858789.946][2018-08-21 06:39:49][mgr01.xxx][Cronicle][debug][5][Socket.io client disconnected: oyMlpxiFAbZp4uSzAAAA (IP: ::ffff:100.xx)][]They say that the MASTER disconnected from THEM! So both are pointing the finger at the other.
Here is what I believe actually happened. Socket.io fired a "disconnect" event for both servers on the master, but it never actually lost connectivity. It disconnected because of a loss of heartbeat. Socket.io has its own heartbeat "echo packet" system that keeps TCP connections alive, and it runs on its own setInterval. This also failed at the same time as everything else, resulting in the sockets hitting idle timeout and dying.
I still don't know WHY yet, but it looks like the entire Node.js timer subsystem failed. One reason could be that the event loop was totally CPU-bound, but I see no other evidence of that. The CPUs were asleep on all affected servers (dev05, bidi, and devrelease). If the main process was CPU-pinned (which would indeed cause timers to not fire), then we would have seen this in Performa. But no, the load averages were all very low all morning long.
Investigation ongoing, but I don't have much else to go on at the moment. Thank you for your report, however, because that allows me to rule out AWS / S3 as a culprit.
dropthemic
Summary
In the "All Complete Jobs" section of UI, the jobs listed are stale and paging through the records stops after the "3rd" next page.
I also have an issue where Cronicle stops running tasks with no seg fault or any errors. Looking over my log files, the scheduler tick never advances:
Another example of scheduler not advancing:
Steps to reproduce the problem
N/A
Your Setup
Vanilla Install
Operating system and version?
CentOS 6.10
Node.js version?
v10.9.0
Cronicle software version?
Version 0.8.24
Are you using a multi-server setup, or just a single server?
Single
Are you using the filesystem as back-end storage, or S3/Couchbase?
FS
Can you reproduce the crash consistently?
Yes
Log Excerpts