ReadyNAS RN104 Power Timer not switching off

[ReadyNASinUK]

After working for years, our ReadyNAS has stopped switching off out-of-hours. 

I have tried switching the power timer off and back on.  Also using State and Event switching, though when it was working it was set to State.

It remains on even with the network cable unplugged, so I don't think it is kept on by some other device in the network.

All apps have been uninstalled.

Any suggestions what to look at?  Are there some log files than I can check?

Thanks!

Other notes: in case it makes any difference, it has 6GB compared to the 2GB when orginally purchased)

Firmware is 6.10.6.  I don't know exactly when the power timer stopped working, at least a couple of updates ago.

The disks spin down as expected

[StephenB · Accepted solution]

---

@ReadyNASinUK wrote:

---

Thanks for the suggestion though, anything else I could try? 

---

This suggestion will require ssh.

The poweroff script checks for running backup jobs using this check:

  # Check for running backups.
  if grep -q 'IN_PROGRESS' /var/log/frontview/backup/status*; then
    OK_TO_HALT=0
    CAUSE="backup job `grep -l 'IN_PROGRESS' /var/log/frontview/backup/status* | sed 's/.*status_backup_//' | xargs echo`"
  fi

This is intending to search files like

1. status_backup_001
2. status_backup_002
3. ...

for "IN_PROGRESS".  If it sees that string in any of those files, it holds off the shutdown.  Though the search is broader than needed (all files that start with status are being scanned).

status_backup_XXX seems to be renamed to backup_XXX_status in the log zip.

Backup jobs on all my OS 6 ReadyNAS start with 001. So one puzzle is why status_backup_000 exists at all.  I don't program the backup button, so one possibility is that 000 is used for that???  Just a total guess.

One thing you could do remove all backup jobs from from the backup button sequence (just in case the guess is correct).  Then enable ssh and rename /var/log/frontview/backup/status_backup_000 to xstatus_backup_000.  Reboot the NAS, and the power schedule should then work correctly.  After you've confirmed that, you can re-add the backup jobs to the backup button sequence.

[Sandshark]

Does the log show it's trying to shut down and fails, or is there no shut-down entry?

[StephenB]

---

@ReadyNASinUK wrote:

Other notes: in case it makes any difference, it has 6GB compared to the 2GB when orginally purchased)

---

The RN104 memory is soldered on (and it came with 512 mb, not 2 GB).  Can you double check the NAS model?

---

@ReadyNASinUK wrote:

After working for years, our ReadyNAS has stopped switching off out-of-hours. 

---

There are a couple of things that will hold off a scheduled shutdown

1. Backup job in progress (including ReadyDR)
2. volume being resynced/reshaped/recovered
3. RAID group in process of being deleted

Have you checked that those don't apply?

[ReadyNASinUK]

---

@Sandshark wrote:

Does the log show it's trying to shut down and fails, or is there no shut-down entry?

---

The main log says every day: "System: Scheduled power off was delayed."  I was hoping there might be some more detailed info that I can access somewhere.

[ReadyNASinUK]

---

@StephenB wrote:

---

@ReadyNASinUK wrote:

Other notes: in case it makes any difference, it has 6GB compared to the 2GB when orginally purchased)

---

The RN104 memory is soldered on (and it came with 512 mb, not 2 GB).  Can you double check the NAS model?

The model is as stated in the header, orgininally with 2x 1GB disks but now with 3GB disks.  Can't see how that would make a difference but...

---

@ReadyNASinUK wrote:

After working for years, our ReadyNAS has stopped switching off out-of-hours. 

---

There are a couple of things that will hold off a scheduled shutdown

1. Backup job in progress (including ReadyDR)
2. volume being resynced/reshaped/recovered
3. RAID group in process of being deleted

Have you checked that those don't apply?

---

1. ReadyDR does not run on RN104 afaik.  All jobs are completed or failed (failed, if that PC is away for example) long before shut down time.

2. Nothing I can see in the main log.  Bear in mind this fails every day.  Is there somewhere to check if the system thinks one of these is in progress? - maybe not completed for some obscure reason?  NB this error survives reboots and firmware upgrades.

3.  Ditto as 2

[StephenB]

---

@ReadyNASinUK wrote:
Nothing I can see in the main log.  Bear in mind this fails every day.  Is there somewhere to check if the system thinks one of these is in progress? - maybe not completed for some obscure reason? 

Have you downloaded the log zip file?

Look in system.log (searching for "Shutdown delayed").

[ReadyNASinUK]

---

@StephenB wrote:

---

@ReadyNASinUK wrote:
Nothing I can see in the main log.  Bear in mind this fails every day.  Is there somewhere to check if the system thinks one of these is in progress? - maybe not completed for some obscure reason? 

Have you downloaded the log zip file?

Look in system.log (searching for "Shutdown delayed").

---

Ah yes... I have looked in these logs before but clearly not well enough.

1. Strange, but the logs only seem to have activity for today.  I don't recall clearing them.

2. Looking at a log from a few months back, there is a daily: Shutdown delayed due to backup job 000 in progress.

3.  In both sets of logs, there is no file  backup_000.log

4.  In both sets there is a file backup_000_status with one line: BACKUP_STATUS__IN_PROGRESS,0!!1434962034!!OK

So my question is, how do I find out what backup job 000 is so I can delete it?  I have many jobs, so I would rather not delete them all and start again.  I don't see a reference number in the job settings.

I guess, if there is not a simple answer, I could write down all the jobs that have a log file, and check against the list of jobs.  Or is job 000 some system backup?

Thanks for a very helpful answer.

[ReadyNASinUK]

I keep trying to post a reply which seems to work but when I go back to the topic - nothing there.  Is the forum moderated - is there a delay after posting?

[ReadyNASinUK]

@StephenB  Can't seem to post my reply so trying first half:

Ah yes... I have looked in these logs before but clearly not well enough.

Strange, but the logs only seem to have activity for today. I don't recall clearing them.

Looking at a log from a few months back, there is a daily: Shutdown delayed due to backup job 000 in progress.

In both sets of logs, there is no file backup_000.log

to be continued....

[ReadyNASinUK]

@StephenBfor some reason I can't post part of my message so here it is by screenshot!

[ReadyNASinUK]

@StephenB 

LOL in frustration, the screenshot shows in my draft but not later!

Basically, backup job 000 seems to be the problem, how do I find out which one that is or is it some hidden system activity?

[Sandshark]

See backup_000.log in the downloaded logs .zip.

[ReadyNASinUK]

---

@Sandshark wrote:

See backup_000.log in the downloaded logs .zip.

---

@SandsharkSee my comments above, there is no log for job 000, just a short status which does not look useful:  BACKUP_STATUS__IN_PROGRESS,0!!1434962034!!OK

There is a log file for all my backup jobs, and only for my jobs.  So, what is backup job 000 ??

[StephenB]

---

@ReadyNASinUK wrote:

@StephenBfor some reason I can't post part of my message so here it is by screenshot!

---

Are you seeing any file names starting with backup and including 143462034 in the log zip file?  For instance, something like

backup_008_copy.1434962034.log

If you do, that will tell you the backup job number (008 in this case).

If not, open each backup status log in turn

backup_001_status
backup_002_status
...

and until you find the one  where the content includes a match for that number

BACKUP_STATUS__IN_PROGRESS!!1434962034!! ...

[ReadyNASinUK]

---

@StephenB wrote:

---

---

Are you seeing any file names starting with backup and including 143462034 in the log zip file?  For instance, something like

backup_008_copy.1434962034.log

---

No, a few files like that but all with a number starting 1641...

---

If not, open each backup status log in turn

backup_001_status
backup_002_status
...

and until you find the one  where the content includes a match for that number

BACKUP_STATUS__IN_PROGRESS!!1434962034!! ...

---

Once again no luck.  For interest, they start with 1641... and 1642... so nothing even similar.

Thanks for the suggestion though, anything else I could try? 

[StephenB · Accepted solution]

---

@ReadyNASinUK wrote:

---

Thanks for the suggestion though, anything else I could try? 

---

This suggestion will require ssh.

The poweroff script checks for running backup jobs using this check:

  # Check for running backups.
  if grep -q 'IN_PROGRESS' /var/log/frontview/backup/status*; then
    OK_TO_HALT=0
    CAUSE="backup job `grep -l 'IN_PROGRESS' /var/log/frontview/backup/status* | sed 's/.*status_backup_//' | xargs echo`"
  fi

This is intending to search files like

1. status_backup_001
2. status_backup_002
3. ...

for "IN_PROGRESS".  If it sees that string in any of those files, it holds off the shutdown.  Though the search is broader than needed (all files that start with status are being scanned).

status_backup_XXX seems to be renamed to backup_XXX_status in the log zip.

Backup jobs on all my OS 6 ReadyNAS start with 001. So one puzzle is why status_backup_000 exists at all.  I don't program the backup button, so one possibility is that 000 is used for that???  Just a total guess.

One thing you could do remove all backup jobs from from the backup button sequence (just in case the guess is correct).  Then enable ssh and rename /var/log/frontview/backup/status_backup_000 to xstatus_backup_000.  Reboot the NAS, and the power schedule should then work correctly.  After you've confirmed that, you can re-add the backup jobs to the backup button sequence.

[ReadyNASinUK]

@StephenB  your SUPERGURU status is well deserved!

---

@StephenB wrote:

---

Backup jobs on all my OS 6 ReadyNAS start with 001. So one puzzle is why status_backup_000 exists at all.  I don't program the backup button, so one possibility is that 000 is used for that???  Just a total guess.One thing you could do remove all backup jobs from from the backup button sequence (just in case the guess is correct).  Then enable ssh and rename /var/log/frontview/backup/status_backup_000 to xstatus_backup_000.  Reboot the NAS, and the power schedule should then work correctly.  After you've confirmed that, you can re-add the backup jobs to the backup button sequence.

---

I tried exactly this and the power off sequence works now, as expected.  I rarely used the backup button, if that was the source of the 000 file - so I'll let that sleeping dog lie and do without it.

I did consider diving into the NAS filesystem and looking for a file like this to delete, but would not have dared to do it without your advice, in case of unexpected damage.

Thanks again, Angus.

PS there was a typo in the path you suggested which I have fixed in the quote above, for info to anyone finding this solution in the future.