"Closing..." time

[natew]

Hi

 

If you turn off snapshots you will lose the ability to restore the system back to a point in time. Your backup will just be a jumble of files that you need to wade through manually when you want to restore.

 

Security information isn't required for workstation systems but it is critical for servers. Backing up security information, the registry and active directory takes a while. 5 minutes is not unusual from my experience. A server with many files can take an hour or more just to build the snapshot.

 

Thanks

Nate

[Lennart_T]

Hi.

 

Then I better enable the Snapshots all the time. ;-)

 

I still don't understand why there is five minutes "Closing..." AFTER the snapshot already has been stored???

 

Thanks

Lennart

[natew]

Hi

 

I agree. The Retrospect screen could be more clear about exactly what is happening. The disk activity shows that it is at least doing something. i.e. it isn't just stuck somewhere.

 

Are you using open file backup? I wonder if unmounting the virtual disks used for open file backup isn't taking some time?

 

Thanks

Nate

[Lennart_T]

Hi.

 

Would you file an "official" feature request on more detalied messages, telling the users what's (really) happening?

Thanks.

 

Yes, on some scripts we use Open File Backup, but it doesn't seem to have any impact on "Closing..." time.

 

Thanks

Lennart

[Lennart_T]

Hi.

 

This is turning into a real problem for us. We have just installed an MS Exchange server and added it to the backup, backing up each mailbox separately. For each of the 55 mailboxes there is over three minutes "Closing..." time. Three minutes times 55 mailboxes is almost three hours wasted each night. What gives?

 

Just FYI: The differential Exchange backup took 3:48:46 is that normal? There isn't much data on the server (yet).

 

Thanks

Lennart

[Lennart_T]

Hi.

 

This is WEIRD:

The same hardware, script, backup set, everything and last night it took 1:21:05 to backup the Exchange server, not 3:48:46. What gives? (Both were Normal backups, the Full backup on new tapes runs only on weekends.)

 

("Closing..." time was about 30 seconds)

 

Thanks

Lennart

[Lennart_T]

The same hardware, script, backup set, everything and last night it took 5:27:11 to backup the Exchange server.

What gives? (Both were Normal backups, the Full backup on new tapes runs only on weekends.)

 

Over 5 hours!!!!! This can't possibly be normal!!!

 

Nate, where are you?????

[Lennart_T]

Hi Nate.

 

Today is Friday, which means a "New backup set" backup here. The old problem with the "Backup Report" is back: Now there are NO events in the Backup Report. We didn't have this problem for a short while (a few weeks), after importing the 6.5 prefs files for the second time. Due to the "Closing.." time, you suspected corruption (see earlier in this thread) so I renamed the old prefs files and entered all users, scripts etc again. This did not only NOT fix the "Closing..." time, but it ruined the Backup Report as well...

 

Now what?

[natew]

Hi

 

Exchange backup and file backup are fundamentally different. Exchange backups call Microsoft APIs to get the data. Regular backups just pull data off the disk.

 

My point is the slow closing time is affecting both types of backup which is really odd. At one point you used an analyzer to show that Retrospect was writing and reading a lot to disk during the closing phase. Can we try storing the catalog file on a USB disk or network share or something to see if anything changes? Basically I want to try storing the catalog anywhere but the internal disk. Its a long shot but what are the chances of a problem with the internal hard disk?

 

In regard to the backup report, does relaunching Retrospect have any effect on it? There are some cases I have seen where the backup report is slow to refresh. Giving Retrospect a bounce can help with that.

 

Thanks

nate

[Lennart_T]

Hi.

 

 

 

OK, today we added a SCSI disk for the catalog files. It doesn't seems to help, but I will know tomorrow. Note that the system is still on the ATA disk.

 

 

 

I also noted two odd lines in the log just prior to shutting down the server to insert the disk:

 

 

 

+ Normal backup using Bärbara at 2005-11-15 13:41 (Execution unit 1)

 

To Backup Set AIT [077]...

 

 

 

- 2005-11-15 13:41:13: Copying Macintosh HD on usrpja

 

2005-11-15 13:41:13: Connected to usrpja

 

2005-11-15 13:49:59: Snapshot stored, 68,4 MB

 

2005-11-15 14:01:48: Execution completed successfully

 

Completed: 80 files, 36,6 MB

 

Performance: 2,9 MB/minute

 

Duration: 00:20:34 (00:08:21 idle/loading/preparing)

 

 

 

napiRvAvail: unexpected PitonNSPacket 0xd80d1843

 

 

 

+ Normal backup using Bärbara at 2005-11-15 14:06 (Execution unit 1)

 

To Backup Set AIT [077]...

 

 

 

- 2005-11-15 14:06:55: Copying Mjukdisk on usrte

 

2005-11-15 14:06:55: Connected to usrte

 

2005-11-15 14:23:43: Snapshot stored, 84,7 MB

 

2005-11-15 14:34:56: Execution completed successfully

 

Completed: 336 files, 252,5 MB

 

Performance: 20,3 MB/minute

 

Duration: 00:28:01 (00:15:36 idle/loading/preparing)

 

 

 

Exit at 2005-11-15 14:35

 

TVxBlockRunTimeLinking: LockUnlockCd not available!

 

 

 

+ Retrospect version 7.0.326

 

Launched at 2005-11-15 15:23 in user account MACTIVE\Administrator

 

+ Retrospect Update, version 7.0.8.103

 

 

 

 

 

Thanks.

 

Lennart

 

 

 

EDIT:

 

I mean the lines:

 

napiRvAvail: unexpected PitonNSPacket 0xd80d1843

 

TVxBlockRunTimeLinking: LockUnlockCd not available!

 

I have never seen those before.

 

 

 

Also note the "Closing" time on usrte: More than 10 minutes.

[Lennart_T]

Hi.

 

No luck using the SCSI drive for the catalog files. The "Closing" time is still 10(!) minutes. The LED for the internal IDE (system) drive is dark with a rare short blink during the "Closing" time. (The SCSI drive doesn't have a LED.)

 

Last night I also downloaded and installed the latest Retrospect Update 7.0.9.103. It didn't make any difference.

 

The catalog file is the only file on the SCSI drive. I didn't check yesterday, but today (after a night's backup) it's got 7 fragments.

 

Regards

Lennart

[natew]

Hi

 

Thanks for trying this. So now it looks like Retrospect is just sitting around? The backup speed looks slow too.

 

Can you tell me about any of the non-default settings you use in the Retrospect preferences or script options?

 

Thanks

nate

[Lennart_T]

Hi.

 

 

 

Performance is usually good, 600MB/min on local backups, around 250-300MB/min over the network. Don't really know why it wasn't with these clients.

 

 

 

No, Retrospect isn't just sitting around, it's using the hard drive heavily. The hard drive with the catalog file, that is. The disk LED is (almost) constantly lit when "Closing..." And while we used the SCSI drive (which didn't have a LED), I could hear the disk heads rattling from heavy use.

 

 

 

OK, we do a new media backup every Friday. Then we use the same backup set until the next Friday (for all scripts).

 

 

 

Our weedend script non-default settings:

 

No verification

 

Backup server AND workstation security info

 

Backup open files, 5 min timeout

 

Force backup of MS Outlook data

 

 

 

Our Mon-Thurs night server script non-default settings:

 

No verification

 

Backup open files (5 min timeout)

 

Force backup of MS Outlook data

 

Exchange server: Differential

 

Don't backup Windows Security info from Workstations

 

 

 

Our Mon-Thurs night workstation script non-default settings:

 

No verification

 

Don't backup open files

 

Force backup of MS Outlook data

 

Exchange server: Differential

 

Don't backup Windows Security info from Workstations

 

 

 

Our Proactive daytime script fro laptops non-default settings:

 

No verification

 

Don't backup open files

 

Force backup of MS Outlook data

 

Don't backup Windows Security info from Workstations

 

Never shut down Mac clients

 

Backup every 21 hours

 

Client countdown 10 seconds

 

 

 

Our preferences non-default settings:

 

Always run Retrospect as specified user (which is the administrator user)

 

Send e-mail for failure and media requests (which works fine)

 

 

 

Thanks

 

Lennart

[Lennart_T]

Hi Nate.

 

I don't know if it's related, but it might explain the slow backup you noticed earlier.

During a Proactive backup, Retrospect was sitting idle for 7 minutes, 10 second saying "Copying Local Disk (C:) on pc-sjo". The "completed" time was stuck at 00:06:34, no processor usage, no hard drive usage, nothing happened. No files were backed up (66535 files, 10.7GB waiting to be backed up). Then suddenly Retrospect started to actually backing up the files. At that moment the "completed" time jumped from 00:06:34 to 00:13:44. The backup speed started out at real low values, but are now reaching normal values (backup is two-thirds complete).

 

So, why is Retrospect REALLY idling for 7 minutes, 10 seconds?

 

Thanks

Lennart

[Lennart_T]

Hi.

 

Today is Friday, which means "New backup set" backup here. I exited Retrospect before the backup and relaunched it. When the backup started the Backup Report was wiped clean. After the backup I exited Retrospect and re-launched it. The Backup Report is still empty (apart from the backup that just ran.)

 

/Lennart

[Lennart_T]

Another Friday has passed and the backup report was emptied AGAIN.

And no sign of "Closing..." time being reduced.

 

Nate, where are you?

[natew]

Hi

 

>>Nate, where are you?

 

On vacation. Well, I was anyway...

 

One other thing we have not considered so far is that Retrospect may be paging memory. That could slow things down.

 

Try this, Open the retro.ini file located in the Retrospect program folder. Currently the MaxMemPercent value is set to 30. Try raising that value to 70 and see if the backups run faster.

 

This value affects the point at which Retrospect starts paging memory. It may run faster if you give it more RAM to use for the backup.

 

Thanks

nate

[Lennart_T]

Welcome back from your vacation.

 

Unfortunately, changing the MaxMemPercent value to 70 didn't improve matters.

 

The PC has 1GB physical RAM. In Windows Task manager, the peak usage is about 623MB (since last reboot which was about 10 days ago).

When Retrospect was polling proactive clients, the memory usage was about 115MB. When backing up a Macintosh (OS X) client, the usage peaked at 222MB when the snapshot was built. During the "Closing..." time the usage was slightly lower.

 

Regards

Lennart

[natew]

Hi Lennart,

 

I haven't been able to reproduce the problems here but my test environment is really small.

 

Have you been able to reproduce this problem on another computer running Retrospect? Even a small test backup with proactive would tell us if this is reproducable.

 

Thanks

Nate

[Lennart_T]

Hi.

 

This week we bought a tape station and Retrospect Single Server to run them in the Exchange server. It has dual 3GHz Intel Xeon processors, 3GB of RAM and fast hard drives. The "Closing..." time for mailbox backup varies between 20 seconds and 30 seconds.

I also tried a proactive backup of just two clients. The "Closing..." time was about 11 seconds, which is entirely acceptable. Up to 30 seconds for closing a mailbox backup isn't acceptable.

 

Our old backup server is currently at 3 minutes "Closing..." time. It does no longer backup the Exchange server, so it manages the night backup during the night (JUST). It starts at 5pm (with our servers) and ends around 6am (with the last workstation). Any problem and the backup lags into the morning when people try to work. (Some comes to work at 7am).

 

Thanks

Lennart

[natew]

Interesting...

 

So the client closing time is slow on one server but not the other?

 

Does the size of the mailbox have any impact on the amount of time for closing? 30 seconds does not sound unusual especially for a large mailbox.

 

Thanks

nate

[Lennart_T]

Hi.

 

I have a feeling that "Closing.." time is somewhat dependant on the size of the catalog file, but that is not consistent. The time is shorter when the file is small (as Fridays directly after New Backup Set backup), but Thursdays does not necessarily have the longest times. It might be Mondays, Tuesdays or Wednesdays.

 

No, the size of the mailbox doesn't seem to have any impact on "Closing..." time.

One user has 31000+ messages and about 2.3GB, but it doesn't take longer "Closing..." than a couple of hundred messages and a few MB.

 

The "fast" server is much faster (in terms of processor, RAM size, disk speed) and it also just backs up local drives/mailboxes.

 

Thanks

Lennart

[natew]

Hi

 

I've asked around and that was the consensus. The size of the catalog file and the number of snapshots inside it could be slowing things down.

 

One thing I would like to go back to:

According to your previous posts, turning off snapshots resolved the problem.

 

Security information take time to collect and building snapshots require CPU and memory. It is probably the biggest bottleneck in Retrospect at this point. A faster machine and a smaller catalog file should make both of those faster.

 

I don't know why it would be slower in Retrospect 7. My guess is we are handling snapshots a bit differently and there is simply more overhead involved.

 

Thanks

Nate

 

Thanks

Nate

[Lennart_T]

>According to your previous posts, turning off snapshots resolved the problem.

 

That creates a bigger problem and I quote YOU from earlier in this thread: "If you turn off snapshots you will lose the ability to restore the system back to a point in time."

 

What use do we have of a backup system that can't restore a computer properly?

 

We DO have asked for funds to buy a faster backup server some time next year, but until that happens???

 

Last night, the backup started at 5 pm and ended this morning at 8:13 am

 

>Security information take time to collect and building snapshots require CPU and memory. It is probably the biggest bottleneck in Retrospect at this point. A faster machine and a smaller catalog file should make both of those faster.

 

I am aware of that, but you are not explaining the large VARIATION in time that we see.

 

It seems as Retrospect is re-writing the catalog file for every backup. Why? Why doesn't it just append that latest client???

 

And finally: You haven't provided a solution for the Backup Report that gets completely wiped out for every "New Backup Set" backup. This does happen on both our backup servers. Why?

[Lennart_T]

This night, Retrospect has been "Building Snapshot" for over 7 hours. I had to use Task manager to End Task as Retrospect couldn't stop the backup normally. (sigh)

 

Prior to that, the "Closing Time" was about 5 minutes compared to 7 minutes the night before. This night, the catalog file is larger than the night before (since we only use one catalog file per week)