Crontab jobs disappeared.

[dev_null]

Don't forget to add a logrotate file too. Perhaps daily and minsize 1024.

Agreed, but at worst the global setting is 4mb IIRC.

Over the course of the first day, my cronj.log is only 125kb, mostly dn-vnstat . I'm using the "full tracking" version of @dave14305 's script. If one only monitors changes to cron jobs, it would be a fraction of that.

 

[elorimer]

Agreed, but at worst the global setting is 4mb IIRC.

I don't mean to take this off-topic. A00global sets that, but in my experience above 1mb uiScribe will bog down. Going to change my A00global right now.

 

[RMerlin]

I had no idea that "/dev/null" was a person! I always thought of it as /the/ available black hole!

He's a hoarder.

 

[dev_null]

He's a hoarder.

Actually recently did my kids a favor and sold the house and purged most everything in it!

 

[glens]

I think I saw that episode.

 

[dave14305]

It seems so far, no one has seen their cronjobs disappear?

 

[Ripshod]

It seems so far, no one has seen their cronjobs disappear?

I was running amtm 4.2 by accident and everything seemed stable. Just upgraded to 4.3 a few hours ago (back to the original conditions) and running fine for now. Don't want to imply anything about amtm though.

 

[ColinTaylor]

I was running amtm 4.2 by accident and everything seemed stable. Just upgraded to 4.3 a few hours ago (back to the original conditions) and running fine for now. Don't want to imply anything about amtm though.

amtm doesn't "run". amtm is a frontend menu for installing other things, e.g. Entware, Diversion, disk check, etc. You run amtm, install something, and then it terminates.

 

[Ripshod]

Then no problems here

 

[dev_null]

It seems so far, no one has seen their cronjobs disappear?

No, but I haven't had this issue in several weeks. Initially the cronjob loss occurred when the internet was down for me, so I figured it might have been related to that, but after seeing this thread it got me thinking it could be something else.

But all good over the past couple of days.

 

[aru]

I executed the update script provided by dave14305 and observed changes throughout the entire day. Using Notepad++, I filtered logs with the keyword 'cru' and saved the results into an attached file.

The initial Jobs count is 25. It then gradually changes through additions and deletions. From the logs, it can be seen that the Jobs count fluctuates between 20-25, triggered by additions and deletions of different cru jobs.

Here is the analysis of the scripts causing jobs increase:

Scripts that decreased jobs:

Skynet_save: line 1871 deleted this job causing jobs to decrease from 25 to 24.
Skynet_banmalware: line 1874 deleted this job causing jobs to decrease from 24 to 23.
Skynet_autoupdate: line 1881 deleted this job causing jobs to decrease from 23 to 22.
CheckVPNServer1: line 1882 deleted this job causing jobs to decrease from 22 to 21.
Skynet_checkupdate: line 1888 deleted this job causing jobs to decrease from 21 to 20.
CheckVPNServer1: line 1994 deleted this job causing jobs to decrease from 24 to 23.

Scripts that increased jobs:

Skynet_banmalware: line 1895 added this job causing jobs to increase from 20 to 21.
Skynet_autoupdate: line 1902 added this job causing jobs to increase from 21 to 22.
Skynet_save: line 1914 added this job causing jobs to increase from 22 to 23.
CheckVPNServer1: line 1931 added this job causing jobs to increase from 23 to 24.
CheckVPNServer1: line 2032 added this job causing jobs to increase from 23 to 24.
Skynet_genstats: line 2086 added this job causing jobs to increase from 24 to 25.

It was mainly the addition and deletion operations of Skynet and VPN related scripts that caused the decrease and increase in the jobs count.

In addition, the fluctuations in the number of crontab jobs were concentrated around 3am according to the logs, when most people are asleep. This could make the root causes of the crontab jobs disappeared harder to notice.

 

[aru]

Today, I found only the following messages. It appears that the total number of crontab tasks does not exhibit regular fluctuations during the early morning hours.

Line 3532: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22269]: Action: d, JobID: Diversion_LocalBackup, Args: d Diversion_LocalBackup
Line 3533: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22269]: Calling PID: 22207, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Line 3534: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22269]: Jobs before: 25, after: 25
Line 3535: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22297]: Action: a, JobID: Diversion_UpdateBL, Args: a Diversion_UpdateBL 00 2 * * Mon /bin/sh /opt/share/diversion/file/update-bl.div reset
Line 3536: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22297]: Calling PID: 22207, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Line 3537: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22297]: Jobs before: 25, after: 25
Line 3538: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22327]: Action: a, JobID: Diversion_RotateLogs, Args: a Diversion_RotateLogs 20 5 * * * /bin/sh /opt/share/diversion/file/rotate-logs.div
Line 3539: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22327]: Calling PID: 22207, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Line 3540: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22327]: Jobs before: 25, after: 25
Line 3541: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22353]: Action: a, JobID: Diversion_CountAds, Args: a Diversion_CountAds 20 17 * * * diversion count_ads count
Line 3542: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22353]: Calling PID: 22207, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Line 3543: Feb 11 04:25:08 GT-AX6000-0FC8 cru[22353]: Jobs before: 25, after: 25

 

[dave14305]

Today, I found only the following messages. It appears that the total number of crontab tasks does not exhibit regular fluctuations during the early morning hours.

Nothing too interesting there. It looks like the dnsmasq restart associated with daily Skynet list update. We’re looking for anything that jumps to or from 0 jobs.

 

[Ripshod]

Has anyone else using @dev_null's cronj syslog-ng.d script noticed it disappear? It was logging fine last night, gone this morning
This is the last cronj log entry followed by the first log entry after re-adding the cronj script (Ive forced a logrotate but that didn't run):

Feb 10 21:45:51 ripshod cru[14663]: Action: a, JobID: Diversion_WeeklyStats, Args: a Diversion_WeeklyStats 30 1 * * Sat /bin/sh /opt/share/diversion/file/stats.div
Feb 10 21:45:51 ripshod cru[14663]: Calling PID: 14419, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Feb 10 21:45:51 ripshod cru[14663]: Jobs before: 20, after: 20
Feb 11 08:58:45 ripshod cru[12243]: Action: a, JobID: logrotate, Args: a logrotate 5 0 * * * /opt/sbin/logrotate /opt/etc/logrotate.conf >> /opt/tmp/logrotate.daily 2>&1
Feb 11 08:58:45 ripshod cru[12243]: Calling PID: 10347, CMD: /bin/sh-/jffs/scripts/scribe
Feb 11 08:58:45 ripshod cru[12243]: Jobs before: 19, after: 20

As an aside I was rebuilding my server yesterday and afterwards syslog-ng kept stalling. Was a few hours before I noticed I hadn' t enabled the syslog server's receive function. So syslog-ng doesn't like sending logs to a nonexistent syslog server, and clearly doesn't mitigate such an event.

 

[alan6854321]

Had something even weirder last night!

My WAN connection went down/up but dnsmasq didn't restart afterward.

It always crashes when the WAN goes down (That's another conundrum), but then gets restarted by a watchdog daemon when the WAN comes back up, didn't happen last night.

Meant that anything that was connected stayed connected, but anything trying to connect couldn't get an IP address.

 

[Ripshod]

Well I'm already doing a rebuild and I'm really struggling. Right now the WAN(PPPoE) just will not connect.
It seems to me right now, syslog-ng is stalling for other reasons (it's not even logging my ssh logins), and scribe and uiScribe are all I have installed right now. Massive migraine.

@dev_null it seems your cronj script is causing problems. After a reboot it just stops after 10 cru adds:

Feb 11 12:10:29 ripshod cru[5923]: Action: a, JobID: Diversion_UpdateBL, Args: a Diversion_UpdateBL 00 2 * * Sat /bin/sh /opt/share/diversion/file/update-bl.div reset
Feb 11 12:10:29 ripshod cru[5923]: Calling PID: 5151, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Feb 11 12:10:29 ripshod cru[5923]: Jobs before: 6, after: 7
Feb 11 12:10:29 ripshod cru[5955]: Action: a, JobID: Diversion_RotateLogs, Args: a Diversion_RotateLogs 20 5 * * * /bin/sh /opt/share/diversion/file/rotate-logs.div
Feb 11 12:10:29 ripshod cru[5955]: Calling PID: 5151, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Feb 11 12:10:29 ripshod cru[5955]: Jobs before: 7, after: 8
Feb 11 12:10:29 ripshod cru[5984]: Action: a, JobID: Diversion_CountAds, Args: a Diversion_CountAds 20 17 * * * diversion count_ads count
Feb 11 12:10:29 ripshod cru[5984]: Calling PID: 5151, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Feb 11 12:10:29 ripshod cru[5984]: Jobs before: 8, after: 9
Feb 11 12:10:29 ripshod cru[6013]: Action: a, JobID: Diversion_WeeklyStats, Args: a Diversion_WeeklyStats 30 1 * * Sat /bin/sh /opt/share/diversion/file/stats.div
Feb 11 12:10:29 ripshod cru[6013]: Calling PID: 5151, CMD: /bin/sh/jffs/scripts/dnsmasq.postconf/etc/dnsmasq.conf
Feb 11 12:10:29 ripshod cru[6013]: Jobs before: 9, after: 10
Feb 11 12:10:31 ripshod cru[6260]: Action: d, JobID: LetsEncrypt, Args: d LetsEncrypt
Feb 11 12:10:31 ripshod cru[6260]: Calling PID: 6259, CMD: /sbin/ddns_updated
Feb 11 12:10:31 ripshod cru[6260]: Jobs before: 10, after: 9
Feb 11 12:10:31 ripshod cru[6288]: Action: d, JobID: LetsEncrypt, Args: d LetsEncrypt
Feb 11 12:10:31 ripshod cru[6288]: Calling PID: 6284, CMD: le_acme
Feb 11 12:10:31 ripshod cru[6288]: Jobs before: 9, after: 9
Feb 11 12:10:31 ripshod cru[6312]: Action: a, JobID: LetsEncrypt, Args: a LetsEncrypt 39 6 */7 * * service restart_letsencrypt
Feb 11 12:10:31 ripshod cru[6312]: Calling PID: 6284, CMD: le_acme
Feb 11 12:10:31 ripshod cru[6312]: Jobs before: 9, after: 10

At the point I noticed I actually have all 20 cronjobs added. Other syslog-ng logs continue to populate but this one just stalls. Reloading syslog-ng brings your logging back (don't know how long for though):

Feb 11 12:22:13 ripshod cru[19042]: Action: a, JobID: logrotate, Args: a logrotate 5 0 * * * /opt/sbin/logrotate /opt/etc/logrotate.conf >> /opt/tmp/logrotate.daily 2>&1
Feb 11 12:22:13 ripshod cru[19042]: Calling PID: 17408, CMD: /bin/sh-/jffs/scripts/scribe
Feb 11 12:22:13 ripshod cru[19042]: Jobs before: 19, after: 20

To confirm, the cronj file was removed overnight, it exists in the 1AM backup.

 

[dev_null]

Well I'm already doing a rebuild and I'm really struggling. Right now the WAN(PPPoE) just will not connect.
It seems to me right now, syslog-ng is stalling for other reasons (it's not even logging my ssh logins), and scribe and uiScribe are all I have installed right now. Massive migraine.

@dev_null it seems your cronj script is causing problems. After a reboot it just stops after 10 cru adds:


To confirm, the cronj file was removed overnight, it exists in the 1AM backup.

What I posted is just a filter for scribe. On my router it's still running fine, though overnight I see a bunch of "failed to acquire lock" messages, which I think is related to the actual "new cru" script rather than the filtering.

You may try changing the order of the filtering by renaming the filter and reloading and restarting scribe - rl & rs. I have it as 4_cronj which means it's filtering later than some of the other "heavy" filters like 2_skynet and 0_blank.

I've got 48 hours-plus of data so I'm backing off this cron job monitoring, but I'd suggest looking more closely at the "new cru" script rather than scribe or filtering.

 

[Ripshod]

What I posted is just a filter for scribe. On my router it's still running fine, though overnight I see a bunch of "failed to acquire lock" messages, which I think is related to the actual "new cru" script rather than the filtering.

You may try changing the order of the filtering by renaming the filter and reloading and restarting scribe - rl & rs. I have it as 4_cronj which means it's filtering later than some of the other "heavy" filters like 2_skynet and 0_blank.

I've got 48 hours-plus of data so I'm backing off this cron job monitoring, but I'd suggest looking more closely at the "new cru" script rather than scribe or filtering.

Well something is failing on bootup (20 cronjobs), stopping the cronj.log, and it's not the new cru script or syslog-ng. No "cru" entries in the "System Messages" log at that time either. All running fine right now, under normal load.
I guess I should just accept something is stopping cronj logging, and I should just live with it.
If that's the case I'll just remove it and filter messages on the syslog server.

 

[Ripshod]

1. Proper locking to prevent concurrent updates.

Did you achieve this? I have had no mass disappearances since running your cru script alongside @dev_null's filter.
One thing I did see was in the actual cron jobs. A spdMerlin job clashed with BACKUPMON (01:15) and I felt that was my cause. Removing your cru confirmed (after 7 days running) that the collision was the probable cause.
As no-one else has mentioned further events can we take it your cru script, along with it's locking has cured this? Would it be possible to have your script included in further releases of Asuswrt-Merlin? Or is that closed source?

 

[dave14305]

Did you achieve this? I have had no mass disappearances since running your cru script alongside @dev_null's filter.
One thing I did see was in the actual cron jobs. A spdMerlin job clashed with BACKUPMON (01:15) and I felt that was my cause. Removing your cru confirmed (after 7 days running) that the collision was the probable cause.
As no-one else has mentioned further events can we take it your cru script, along with it's locking has cured this? Would it be possible to have your script included in further releases of Asuswrt-Merlin? Or is that closed source?

My cru script only added logging. It would not fix anything itself.