script execution termianted at specified stop time

[Chief Technician]

My configuration: OS X Tiger Server v10.4.4, G4/533MHz, 1.5GB RAM, Retrospect Workgroup v6.1.126, Device Access v1.0.107, Driver Update v6.1.5.102, and a Retrospect client on Windows XP Pro SP2 v7.0.112.

 

I have a backup set configured for Mon-Thur of each week. It is a recycle backup set, where the set is recycled on Monday and then normal backups occur on Tue-Thur.

 

The last two (2) Mondays, the backup operation has not completed. If I view the log, I see the following entry:

 

7/25/2006 7:48:01 AM: Script execution terminated at specified stop time.

 

The time makes sense, as that is the time I would specified for the script to termiante. However, what I would like to determine is why the script is not completing. On both occasions, the log reports that there are eleven (11) files remaining to be backed up, whose combined size is around 200MB. I am backing up to a firewire DVD-RW. I fail to see an entry in the log that explains why the backup operations is, conceptually, hanging with 11 files left. The first time this happened, the normal backup operation the day after (Tue) completed without incident. I hope the same thing happens later tonight, but I would like to determine why the recycle backup operation is not completing and why the only error in the log is the one noted above.

 

Any insight into this issue would be appreciated. Thanks for reading!

[nekr0phage]

Quote:

---

The time makes sense, as that is the time I would specified for the script to termiante.

 

---

 

I'm sorry I don't understand - you say you specified for the script to terminate at a specific time, then you're curious as to why it *terminates* at that time? If you want the script to complete why don't you remove the stop time and allow it to complete?

 

Perhaps I missed something.

[file82]

It is like you ask it to stop and complaint about why it stop

 

or you want the script to pause running during a certain time?

[Chief Technician]

Hello. Thank you for your responses. I see where I have you confused as to why I am posting this. I will try to elaborate on the issue.

 

I am fully aware that if I program a stop time of X, that the script will stop at time X. My issue is that in the incident that prompted my post, I had PLENTY of time to complete this backup. What happened is that with 11 files remaining on an XP network client, the backup stalled (conceptually anyway). If I look in my log file, Retrospect spent the last 02:33:22 of the script execution window in the idle/loading/preparing phase. I would like to know why this happened. Why did Retrospect sit there and do nothing (as far as the log indicates) for 2 hours, 33 minutes, and 22 seconds when there were 11 files remaining to be backed up?

 

I was tipped off to this problem when Retrospect reported "script execution terminated at specified stop time". Given that it appears to have idled/stalled for 02:33:22, I could have not specified a stop time (execute until finished) and the thing would still be idle/stalled with 11 files to go.

 

I hope this clears up what it is I am trying to understand and resolve. Thanks for reading!

[twickland]

So let me see if I have this right, with a bit of filling in between the lines in your post:

 

You are backing up a single client, which happens to be an XP client. During each recycle backup, Retrospect apparently stops backing up this client when there are 11 files remaining to be backed up, although it is still doing something, whatever that may be. There are no errors reported, such as file busy or file not found, and Retrospect does not get around to the Comparing phase. Then the next night, when running a nomal backup via the same script, the client backup completes normally.

 

Offhand, I can think of a number of possibilities, any of which would seem strange:

 

1) The 11 files consistently missed during each recycle backup are then consistently backed up in the following night's Normal backup without a problem. (Assuming that both scheduled backups are part of the same script with the same selectors active, this would seem especially odd.)

 

2) The 11 files were actually backed up during the recycle backup, but during whatever activity Retrospect then engaged in for hours, it didn't get around to updating the progress window or moving on to the Compare phase.

 

3) The 11 files were added to the catalog even though they were not actually backed up.

 

Do you have any idea what the 11 files are? How does the snapshot for the recycle backup compare to the actual contents of the source volume? Is there any evidence that the 11 files appear in the snapshot for the second night's backup?

 

On the morning after the recycle backup, what happens if you perform an immediate backup of the client, using the same selector(s) as in your scheduled script? What happens if you perform an immediate backup to a brand-new backup set, again with the same selectors?

 

What do you see if you disable your custom schedule, allowing Retrospect to continue so that you can view the progress window while it's still active?

[Chief Technician]

Quote:

---

So let me see if I have this right, with a bit of filling in between the lines in your post:

 

You are backing up a single client, which happens to be an XP client.

 

---

I am backing up three (3) clients, the problem client is an XP client.

Quote:

---

During each recycle backup, Retrospect apparently stops backing up this client when there are 11 files remaining to be backed up, although it is still doing something, whatever that may be. There are no errors reported, such as file busy or file not found, and Retrospect does not get around to the Comparing phase. Then the next night, when running a nomal backup via the same script, the client backup completes normally.

 

---

You are correct!

Quote:

---

Offhand, I can think of a number of possibilities, any of which would seem strange:

 

1) The 11 files consistently missed during each recycle backup are then consistently backed up in the following night's Normal backup without a problem. (Assuming that both scheduled backups are part of the same script with the same selectors active, this would seem especially odd.)

 

---

Both scheduled backups are part of the same script. I had selection criteria from months ago that has been disabled for some time (it was disabled before this problem surfaced), and have now deleted that selection criteria entirely.

 

Quote:

---

2) The 11 files were actually backed up during the recycle backup, but during whatever activity Retrospect then engaged in for hours, it didn't get around to updating the progress window or moving on to the Compare phase.

 

---

If that is the case, would this behavior be classified as a bug?

 

Quote:

---

3) The 11 files were added to the catalog even though they were not actually backed up.

 

Do you have any idea what the 11 files are?

 

---

Yes, I do.

Quote:

---

How does the snapshot for the recycle backup compare to the actual contents of the source volume?

 

---

When I navigate to Reports-->Contents, then select the backup set and choose to view the session for the backup in question, it is indeed missing 11 files that are present on the source volume.

Quote:

---

Is there any evidence that the 11 files appear in the snapshot for the second night's backup?

 

---

Nine (9) of the eleven (11) files appear in the snapshot for the second night's backup.

Quote:

---

On the morning after the recycle backup, what happens if you perform an immediate backup of the client, using the same selector(s) as in your scheduled script? What happens if you perform an immediate backup to a brand-new backup set, again with the same selectors?

 

What do you see if you disable your custom schedule, allowing Retrospect to continue so that you can view the progress window while it's still active?

 

---

Which path would you follow first? The immediate backup path or the disabling of the custom schedule?

 

Thank you for taking the time to respond!

[twickland]

Since you know the 11 files, I'd be inclined to try an immediate backup to an empty test backup set. and see how that goes. To speed the test up, you might, if feasible, try defining as a subvolume a folder that contains all 11 files (though this would add another variable to your test).

 

Since you're about to hit your Monday recycle backup, I'd also disable your custom schedule so you can see what Retrospect is doing when you arrive the following morning. If it's stuck as usual, you could then manually stop execution and try running an immediate normal backup of the client to the same backup set. This would give you an additional data point.

[Chief Technician]

Quote:

---

Since you know the 11 files, I'd be inclined to try an immediate backup to an empty test backup set.

 

---

I did this. I found an interesting occurrence. I was prompted for a 2nd DVD-RW disc! Why am I ? I have two (2) other backup sets that backup the same sources of data, recycle-style, on two other occasions. Neither of those recycle backups prompts me for a 2nd DVD-RW disc, and they both report completion without errors.

 

Now, I suppose it is possible that I never saw Retrospect prompting for a 2nd DVD-RW disc because when I viewed the screen, my defined execution time had elapsed. However, I believe that it would be wise to have an entry in the log that states "Backup could not complete because media is full," or something to that effect.

 

At least I know what is going on. I do have a question related to this. The amount of data that had to be burned to the 2nd DVD-RW disc was small enough to fit on a CD-RW. The system I have Retrospect installed on has two (2) optical drives. Is it possible to instruct Retrospect to start with the DVD-RW disc and then automatically move to a CD-RW disc in another drive when the DVD-RW disc is full?

 

Thanks for the help!