natew Posted December 9, 2005 Report Share Posted December 9, 2005 Hi My point is this: The evidence in this case shows that Snapshots are responsible for slowing down the "closing" time. So far you have indicated that Retrospect is accessing the disk during this time. That tells me Retrospect is doing what it should be doing. The time you reported on Oct 25 still sounds normal to me... Keep in mind that snapshot takes time regardless if any files were backed up. On my Celeron 1.8 GHz machine backup of the D drive takes 8 minutes even when _no_ files need to be copied. This is normal. It simply takes time to get all the Windows security information for the snapshot. In regard to the variations: -Do any sources _always_ take longer than expected to complete the closing/snapshot process? -Does the slowness tend to occur on one particular day? -Do the number of files and folders on the disk seem to correspond with the backup speed in any way? -Does this machine do anything other than run Retrospect? -How many executions do you run in paralell? -What is the speed of the CPU? In regard to the backup report: New-backup set backups create a completely new backup set. When that occurs all records from the original backup set are removed removed from the backup report. Other reports from other backup sets should still remain the backup report. Can you please verify if this is the case in your environment? Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 9, 2005 Author Report Share Posted December 9, 2005 Hi. Quote: Keep in mind that snapshot takes time regardless if any files were backed up. On my Celeron 1.8 GHz machine backup of the D drive takes 8 minutes even when _no_ files need to be copied. This is normal. It simply takes time to get all the Windows security information for the snapshot. The time Retrospect spend "Building Snapshot" is NOT included in the times I mention here. And, yes, 8 minutes building the snapshot is normal. -Do any sources _always_ take longer than expected to complete the closing/snapshot process? No. -Does the slowness tend to occur on one particular day? No. (Well, it doesn't seem to happen during the weekend right after the New Backup Set backup) -Do the number of files and folders on the disk seem to correspond with the backup speed in any way? No, not the "Closing..." time. (Odd, isn't it?) But scanning, matching, actual copy etc is of course faster with fewer files. -Does this machine do anything other than run Retrospect? No. -How many executions do you run in paralell? One. -What is the speed of the CPU? 2GHz Pentium 4. 1GB physical RAM. Quote: In regard to the backup report: New-backup set backups create a completely new backup set. When that occurs all records from the original backup set are removed removed from the backup report. Other reports from other backup sets should still remain the backup report. Can you please verify if this is the case in your environment? Yes, this is the case. We only use one backup set. Why delete it immediately? That prevents us from checking any client that hasn't been backed up for days. This is especially important on laptops/proactive backups, where the computer may be on the road for weeks at a time. Question: It seems as Retrospect is re-writing the whole catalog file during the "Closing..." time. Why? (Why's doesn't Retrospect simply append the last backup to the end of the file?) Regards Link to comment Share on other sites More sharing options...
natew Posted December 12, 2005 Report Share Posted December 12, 2005 Hi Thanks for the additional info. >The time Retrospect spend "Building Snapshot" is NOT included in the >times I mention here. Where are you getting your time stats? I'm a bit puzzled as to how you are able to seperate the snapshot creation time from the closing time. New media backup sets are meant to replace existing sets. The backup report is designed to highlight the most recent backup activity. Entries in the backup report about older sets that have been replaced by new media backups are removed for clarity. In regard to the catalog, I don't know for sure. There is a lot of copying and compression that occurs for each backup. Retrospect just does what it needs to... Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 12, 2005 Author Report Share Posted December 12, 2005 Hi. Quote: Where are you getting your time stats? I'm a bit puzzled as to how you are able to seperate the snapshot creation time from the closing time. Two methods: By sitting and watch what happens when the actual file copying is about to finish (and what happens after). In the log, there is a timestamp when "Snapshot stored" and another when "Execution completed". Between those timestamps is the "Closing..." time. (I have been watching what happens with the log window open so I know this is what happens) Quote: New media backup sets are meant to replace existing sets. The backup report is designed to highlight the most recent backup activity. Entries in the backup report about older sets that have been replaced by new media backups are removed for clarity. Any way to get this changed in a future version? To only delete events after a selectable number of days. (You DO see why I want this, right?) Quote: In regard to the catalog, I don't know for sure. There is a lot of copying and compression that occurs for each backup. Retrospect just does what it needs to... The catalog files are NOT compressed. WHY does Retrospect need to rewrite the entire file??? Thanks Lennart Link to comment Share on other sites More sharing options...
Lennart_T Posted December 13, 2005 Author Report Share Posted December 13, 2005 Hi. Today I thought I discovered something new. In the following log, one client has a much shorter "Closing.." time than the others. I figured it's probably because it's the first backup for this client (usrga) in the backup set. Quote: + Normal backup using B‰rbara at 2005-12-13 09:50 (Execution unit 1) To Backup Set AIT [081]... - 2005-12-13 09:50:34: Copying Cesselilia on usrcjo 2005-12-13 09:50:34: Connected to usrcjo 2005-12-13 10:13:53: Snapshot stored, 91,5 MB 2005-12-13 10:25:04: Execution completed successfully Completed: 260 files, 320,7 MB Performance: 25,2 MB/minute Duration: 00:34:29 (00:21:46 idle/loading/preparing) + Normal backup using B‰rbara at 2005-12-13 10:32 (Execution unit 1) To Backup Set AIT [081]... - 2005-12-13 10:32:30: Copying Macintosh HD on usrga 2005-12-13 10:32:30: Connected to usrga 2005-12-13 11:03:09: Snapshot stored, 129,0 MB 2005-12-13 11:03:34: Execution completed successfully Completed: 28961 files, 6,3 GB Performance: 354,0 MB/minute Duration: 00:31:03 (00:13:05 idle/loading/preparing) + Normal backup using B‰rbara at 2005-12-13 11:11 (Execution unit 1) To Backup Set AIT [081]... - 2005-12-13 11:11:07: Copying Patriks on usrpgu 2005-12-13 11:11:07: Connected to usrpgu 2005-12-13 11:25:46: Snapshot stored, 58,8 MB 2005-12-13 11:33:04: Execution completed successfully Completed: 166 files, 14,4 MB Performance: 1,8 MB/minute Duration: 00:21:57 (00:14:15 idle/loading/preparing) Further investigation showed that wasn't the case. Both of these were backed up (at least) the second time in the backup set. Quote: + Normal backup using B‰rbara at 2005-12-12 15:42 (Execution unit 1) To Backup Set AIT [081]... - 2005-12-12 15:42:17: Copying Mac OS X on usrllo 2005-12-12 15:42:17: Connected to usrllo 2005-12-12 16:02:13: Snapshot stored, 80,2 MB 2005-12-12 16:13:15: Execution completed successfully Completed: 191 files, 1,3 GB Performance: 83,3 MB/minute Duration: 00:30:57 (00:16:07 idle/loading/preparing) + Normal backup using B‰rbara at 2005-12-12 16:19 (Execution unit 1) To Backup Set AIT [081]... - 2005-12-12 16:19:59: Copying Macintosh HD on usrpja 2005-12-12 16:19:59: Connected to usrpja 2005-12-12 16:26:31: Snapshot stored, 67,7 MB 2005-12-12 16:26:57: Execution completed successfully Completed: 43 files, 500 KB Performance: 0,5 MB/minute Then I thought, it could be user specific after all. But NOOoooo. Quote: - 2005-12-05 16:33:10: Copying Macintosh HD on usrga 2005-12-05 16:33:10: Connected to usrga 2005-12-05 17:00:40: Snapshot stored, 130,1 MB 2005-12-05 17:11:04: Execution completed successfully Completed: 21174 files, 5,6 GB Performance: 224,7 MB/minute Duration: 00:37:54 (00:12:23 idle/loading/preparing) Duration: 00:06:58 (00:06:03 idle/loading/preparing) What is going on here? (You DO see the differences in time between "Snapshot stored" and "Execution completed successfully", right? Sometimes over 10 minutes, sometimes just over 20 seconds.) Thanks Lennart Link to comment Share on other sites More sharing options...
natew Posted December 14, 2005 Report Share Posted December 14, 2005 Hi What is the total number of files and folders for each of the volumes listed in your logs above and what are the OSes of each computer? It may be unrelated but what SCSI card do you use? Apparently there is a known issue with the adaptec 29160 drivers on Windows 2000. Updating those drivers improves performance drastically. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 14, 2005 Author Report Share Posted December 14, 2005 Hi. OK, let's see... usrga, 482121 files, 95713 folders, Mac OS X 10.4.3 usrpja, 260873 files, 61782 folders, Mac OS X 10.3.9 usrpgu, 219545 files, 53836 folders, Mac OS X 10.3.9 usrcjo, 331579 files, 82629 folders, Mac OS X 10.4.3 usrllo is currently on the road. I GUESS around 300000 files, 60000 folders, Mac OS X 10.4.3. Yes, we do have the Adaptec 29160 card (with only the tape loader connected; no hard drives). We did have the latest drivers available through Windows Update, which was 4.2.0.0. We are now on 6.4.630.100 from Adaptec's web site. I'll keep you posted on any improvement (or lack thereof). Thanks Lennart Link to comment Share on other sites More sharing options...
natew Posted December 15, 2005 Report Share Posted December 15, 2005 Hi Thank you for the information. Do you ever do backups of a local volume on the backup server? Does that seem to go slowly or quickly? Is it consistent one way or another? I'll try this with some OSX clients here to see if the same thing occurs. Although I will be using a FW disk as a destination not a tape... When Retrospect is apparently just being slow, does the client control panel say that the backup has completed? Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 15, 2005 Author Report Share Posted December 15, 2005 Hi. Yes, we do backup two local volumes. Drive C with the system and drive D with uncompressed catalog files. Quote: New Backup Set backup using Nya kassetter at 2005-12-09 10:00 (Execution unit 1) To Backup Set AIT [080]... * Resolved container My Computer container to 2 volumes: Local Disk (C:) Local Disk (D:) 2005-12-09 10:00:00: Use new Backup Set: Replaced with AIT [081] - 2005-12-09 10:00:00: Copying Local Disk (C:) 2005-12-09 10:24:21: Snapshot stored, 23,6 MB 2005-12-09 10:24:33: Execution completed successfully Completed: 11581 files, 9,6 GB Performance: 449,5 MB/minute Duration: 00:24:32 (00:02:49 idle/loading/preparing) - 2005-12-09 10:24:33: Copying Local Disk (D:) 2005-12-09 11:02:39: Snapshot stored, 16 KB 2005-12-09 11:02:42: Execution completed successfully Completed: 15 files, 28,0 GB Performance: 750,4 MB/minute Duration: 00:38:08 (00:00:03 idle/loading/preparing) 2005-12-09 11:02:42: Execution completed successfully Total performance: 641,1 MB/minute Total duration: 01:02:40 (00:02:52 idle/loading/preparing) It is always consistent and fast. The "Closing..." time is slow, except for the New Backup Set backup. At other times it is normally 5 minutes. The "Closing..." time is nothing unique to Mac clients. It's the same for PC-clients (and local backups). I have to get back regarding what the client says during "Closing". Thanks Lennart Link to comment Share on other sites More sharing options...
Lennart_T Posted December 15, 2005 Author Report Share Posted December 15, 2005 Quote: When Retrospect is apparently just being slow, does the client control panel say that the backup has completed? Hi. No, it's still "In use by...." Thanks Lennart Link to comment Share on other sites More sharing options...
natew Posted December 20, 2005 Report Share Posted December 20, 2005 Hi Interesting. This could mean that closing the network connection is what is taking time. But that wouldn't explain why the local backups are slower than you expect. I notice you have verification disabled. Just for grins can you try a backup with verification enabled and see if the behavior is any different? Can you run a test backup to a disk backup set stored on a hard disk? I ran some tests over the last week with a couple of OSX clients and a slow (P3 667) backup server. Closing times were speedy for me but I was on XP using Disk as the destination. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 20, 2005 Author Report Share Posted December 20, 2005 Hi. No, since local backups are slow "closing.." too, I don't think it's the network. Turned on verification, but it didn't affect the "Closing..." time. Another observation: I have a short script that I use for backing up a client or two as needed. When I run this script, the "Closing..." time seems to be much shorter than the other scripts we run. The only thing I can see that is different is that this scripts has the clients added directly, while the ordinary scripts uses "Source Groups" from Configure->Volumes. The Source Groups are named PC laptops, PC desktops, Mac laptops, Mac desktops, PC servers, Mac servers. (Their contents should be obvious...) I don't think this should matter, but I thought I should mention it anyway. I'm sorry, but we don't have a spare hard drive. The SCSI drive I used for testing a while ago is no longer available. The internal hard drive has only 25 GB free on the system partition and 9GB on the catalog file partition. Why do you want me to test a disk backup set? Regards Lennart Link to comment Share on other sites More sharing options...
natew Posted December 22, 2005 Report Share Posted December 22, 2005 Hi Thanks for the info. I wanted to use disk sets to try to rule out the backup device & backup set type as a problem. Even a small backup with a restrictive selector would tell us that. In regard to source groups, I had not used them in my tests here. I will do so. I'm curious what would happen if you moved your sources in the "fast" script into a source group and ran the backup with the group as the source. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 22, 2005 Author Report Share Posted December 22, 2005 Hi. Here's what I did: I used my private 200GB hard drive (that I'm going to put in my Mac at home) and installed it in the server. I created a Disk backup set on the new drive (unfortunately, the catalog file wound up on the C: drive) I duplicated the small "fast" script and changed the destination to the new disk backup set. I ran it a few times, but got short "Closing..." times. I added more clients (no source groups) and ran it through the night. Now the "Closing..." time started to increase. It's currently at over 2 minutes. So it doesn't seem as source groups is part of the equation. I will move the catalog file to the new drive (G:) and continue testing. Regards Lennart Link to comment Share on other sites More sharing options...
Lennart_T Posted December 22, 2005 Author Report Share Posted December 22, 2005 Hi. Unfortunately, the new drive (G:) became too full to try a new client, but the "closing..." time after moving the catalog file to the new G: drive was almost 2 minutes on the "old" clients. Regards Lennart Link to comment Share on other sites More sharing options...
natew Posted December 27, 2005 Report Share Posted December 27, 2005 Hi Following this logic, the greater the number of sources in the script the longer the closing time. Does this fit with what you are seeing? We are talking only about proactive backup here right? Please let me know if it also happens with standard scripts. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 27, 2005 Author Report Share Posted December 27, 2005 Quote: Following this logic, the greater the number of sources in the script the longer the closing time. Does this fit with what you are seeing? Hi. Wrong. I just made a test to verify that: 3 clients or 65 didn't have any impact. The time increases with the size of the catalog file, but there are exceptions: A) The first time a client get's backed up, the time is short. The second, third etc it's slow. Except: If very few files (20 or less) changed since last backup, the time is short. 150 or more files: long time. Quote: We are talking only about proactive backup here right? Please let me know if it also happens with standard scripts. Wrong. We're talking both Proactive as well as standard scripts. No difference. Regards Lennart Link to comment Share on other sites More sharing options...
natew Posted December 28, 2005 Report Share Posted December 28, 2005 Hi I'm reviewing everything here to make sure I have the facts straight. Am I correct in thinking that regardless of the catalog size the closing time is always fast for a source the first time it is backed up? How big are your Retrospect config files? Do they get smaller after you do the new media backup? After a new snapshot is stored the previous snapshot for that source is removed from the catalog file. I'm wondering if that is where the slowdown occurs. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 28, 2005 Author Report Share Posted December 28, 2005 Hi. >Am I correct in thinking that regardless of the catalog size the closing time is always fast for a source the first time it is backed up? Yes, that is correct. >How big are your Retrospect config files? 3.6MB (there is only one, apart from a small launcher file and a 3.1MB .bak file) >Do they get smaller after you do the new media backup? I don't know that. (I'll check Friday) >After a new snapshot is stored the previous snapshot for that source is removed from the catalog file. I'm wondering if that is where the slowdown occurs. That seems to be it. Does that mean the entire catalog file needs to be copied (minus the old snapshot)? So we need a faster hard drive, then? Request: Can the text "Closing..." be changed to something more informative, such as "Removing old snapshot" Regards Lennart Link to comment Share on other sites More sharing options...
natew Posted December 29, 2005 Report Share Posted December 29, 2005 Hi I will log that as a feature request. A lot of little things happen during closing. I suspect including details on all of them hasn't been practical. I don't think an entirely new catalog is created every time. If that were the case it seems that the closing time would be more uniform. The catalog does a lot of reading and writing internally without the use of temp files. For example if catalog compression is enabled all of the compression happens within the catalog file itself. I suspect the same is true for the closing phase. I'll see if I can verify that. Disk backup sets with grooming enabled will keep old snapshots in the catalog. If deleting the old snapshots is really the culprit then backup to a disk set with grooming enabled should be speedy all the time. Since time is an issue here one possible workaround here would be to backup to disk first and then do a snapshot transfer to tape afterward. That would even allow you to run multiple executions at night so your backups would complete sooner. You could then run the transfer to tape during the day with minimal impact on users. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 29, 2005 Author Report Share Posted December 29, 2005 Hi. Quote: I will log that as a feature request. A lot of little things happen during closing. I suspect including details on all of them hasn't been practical. No, but the most time-consuming ones would be nice. Quote: Disk backup sets with grooming enabled will keep old snapshots in the catalog. If deleting the old snapshots is really the culprit then backup to a disk set with grooming enabled should be speedy all the time. Since time is an issue here one possible workaround here would be to backup to disk first and then do a snapshot transfer to tape afterward. That would even allow you to run multiple executions at night so your backups would complete sooner. You could then run the transfer to tape during the day with minimal impact on users. That sounds like a good idea. Any guidelines available on how to set it up? (Chapter 9 in Retrospect User's guide did not provide step-by-step instructions. Pages 211 and 212 are the closest I can find. Or did I miss something?) Regards Lennart Link to comment Share on other sites More sharing options...
natew Posted December 30, 2005 Report Share Posted December 30, 2005 Hi To enable grooming just create a disk backup set. It will ask you what you want to do when the disk gets full. Choose the middle option and set the number of snapshots to 20 or so. That will keep all the snapshots in the catalog file. Thanks Nate Link to comment Share on other sites More sharing options...
Lennart_T Posted December 30, 2005 Author Report Share Posted December 30, 2005 Thank You! Happy New Year! Link to comment Share on other sites More sharing options...
Recommended Posts
Archived
This topic is now archived and is closed to further replies.