TSM backup stg to copy pool taking days to compleate.

[NateDJ]

I am currently getting about 10MB per hour throughput to my LTO4 tapes.

This is a new installation and I am new to TSM. I have read the online help pages as much as I can and still can not track down what is causing my problem.

System:
Windows 2008 Server x64 with latest service packs and updates rome Microsoft.
Server is a Dell Power Edge R510 with
500GB C: drive
500GB D: Drive
6.0TB E: Drive

OS is on C:
Database and Active Log on D:
Disk Dev, File Dev, Active Mirror, Primary and Secondary Archive are all on E:

Server has 16GB ram
2 E5620 Quad Core Xeon processors with hyper-threading turned off. (8 CPU show in the task monitor)
SCSI Ultra320 connected LTO4 24tape library (x2)

I can archive over 1TB per day but when I run >backup stg File1 LTOCopy1 it takes 12-24h to copy over ~1GB

The server has nothing else running on it at the time. The CPU load is an average of 25% with each CPU going 100% for 1-10 sec then dropping and the next CPU picking it up.
Used memory is 6.64GB and steady.

The total data in the FILE1 storage pool is about 500GB

The Database is only about 3GB and backed up every night.

>q db f=d
Database Name: TSMDB1
Total Size of File System (MB): 476,286
Space Used by Database(MB): 3,616
Free Space Available (MB): 437,961
Total Pages: 312,324
Usable Pages: 312,188
Used Pages: 305,060
Free Pages: 7,128
Buffer Pool Hit Ratio: 100.0
Total Buffer Requests: 219,045,827,798
Sort Overflows: 0
Lock Escalation: 0
Package Cache Hit Ratio: 99.8
Last Database Reorganization:
Full Device Class Name: LTOCLASS1
Incrementals Since Last Full: 0
Last Complete Backup Date/Time: 09/01/2010 06:00:06

The Total Buffer Request number is climbing at a rate of ~2 million per second. (This can't be good can it?)

Any Idea what I have configured incorrectly that would have caused this?
Everything seems configured according to IBM specifications, but somewhere I must have missed something.

Any help would be appreciated!

 

[Raakin]

TSM DB and Log volumes should be on different hard drives though I would be floored if that is the only issue.

Have you attempted to backup directly to tape? If so, do you see the same speeds?
How many Tape drives do you have?
Have you tried using MaxPr=<#of tape drives> to ensure it uses all of your drives?
Windows service 'Removable Storage', is it running?
Any other tests you may have ran directly to tape?

 

[NateDJ]

Archive directly to tape is over 1TB per 12 hours.
Not tried to backup directly to tape, backing up to disk then migrating to file then backup storage pool to tape.
Only 1 drive in each library.
Removable Storage service set to disabled.

All drives in this server are 6Gb/s SATA3 drives so they should be able to handle the I/O i would think.

 

[Raakin]

Please post the following:
q stg File1 f=d
q stg LTOCopy1 f=d
q devc f=d

 

[NateDJ]

>q stg file1 f=d

Storage Pool Name: FILE1
Storage Pool Type: Primary
Device Class Name: FILEDEV1
Estimated Capacity: 4,096 G
Space Trigger Util: 43.2
Pct Util: 10.8
Pct Migr: 10.8
Pct Logical: 79.1
High Mig Pct: 90
Low Mig Pct: 70
Migration Delay: 0
Migration Continue: Yes
Migration Processes: 1
Reclamation Processes: 1
Next Storage Pool:
Reclaim Storage Pool:
Maximum Size Threshold: No Limit
Access: Read/Write
Description:
Overflow Location:
Cache Migrated Files?:
Collocate?: No
Reclamation Threshold: 60
Offsite Reclamation Limit:
Maximum Scratch Volumes Allowed: 20
Number of Scratch Volumes Used: 5
Delay Period for Volume Reuse: 0 Day(s)
Migration in Progress?: No
Amount Migrated (MB): 0.00
Elapsed Migration Time (seconds): 0
Reclamation in Progress?: No
Last Update by (administrator): TSMINST1
Last Update Date/Time: 08/19/2010 08:06:39
Storage Pool Data Format: Native
Copy Storage Pool(s):
Active Data Pool(s):
Continue Copy on Error?: Yes
CRC Data: No
Reclamation Type: Threshold
Overwrite Data when Deleted:
Deduplicate Data?: Yes
Processes For Identifying Duplicates: 1
Duplicate Data Not Stored: 0 (0%)
Auto-copy Mode: Client
Contains Data Deduplicated by Client?: No

 

[NateDJ]

>q stg ltocopy1 f=d

Storage Pool Name: LTOCOPY1
Storage Pool Type: Copy
Device Class Name: LTOCLASS1
Estimated Capacity: 38,411 G
Space Trigger Util:
Pct Util: 1.1
Pct Migr:
Pct Logical: 100.0
High Mig Pct:
Low Mig Pct:
Migration Delay:
Migration Continue:
Migration Processes:
Reclamation Processes: 1
Next Storage Pool:
Reclaim Storage Pool:
Maximum Size Threshold:
Access: Read/Write
Description:
Overflow Location:
Cache Migrated Files?:
Collocate?: No
Reclamation Threshold: 100
Offsite Reclamation Limit: No Limit
Maximum Scratch Volumes Allowed: 24
Number of Scratch Volumes Used: 1
Delay Period for Volume Reuse: 0 Day(s)
Migration in Progress?:
Amount Migrated (MB):
Elapsed Migration Time (seconds):
Reclamation in Progress?: No
Last Update by (administrator): TSMINST1
Last Update Date/Time: 08/02/2010 16:02:40
Storage Pool Data Format: Native
Copy Storage Pool(s):
Active Data Pool(s):
Continue Copy on Error?:
CRC Data: No
Reclamation Type: Threshold
Overwrite Data when Deleted:
Deduplicate Data?: No
Processes For Identifying Duplicates:
Duplicate Data Not Stored:
Auto-copy Mode:
Contains Data Deduplicated by Client?: No

 

[NateDJ]

>q devc f=d

Device Class Name: DBBACKUPCLASS
Device Access Strategy: Sequential
Storage Pool Count: 1
Device Type: FILE
Format: DRIVE
Est/Max Capacity (MB): 4,096.0
Mount Limit: 20
Mount Wait (min):
Mount Retention (min):
Label Prefix:
Drive Letter:
Library:
Directory: E:\TSM\SERVER1\DBBACKUP
Server Name:
Retry Period:
Retry Interval:
Twosided:
Shared:
High-level Address:
Minimum Capacity:
WORM: No
Drive Encryption:
Scaled Capacity:
Last Update by (administrator): TSMINST1
Last Update Date/Time: 08/19/2010 08:14:39

Device Class Name: DISK
Device Access Strategy: Random
Storage Pool Count: 1
Device Type:
Format:
Est/Max Capacity (MB):
Mount Limit:
Mount Wait (min):
Mount Retention (min):
Label Prefix:
Drive Letter:
Library:
Directory:
Server Name:
Retry Period:
Retry Interval:
Twosided:
Shared:
High-level Address:
Minimum Capacity:
WORM: No
Drive Encryption:
Scaled Capacity:
Last Update by (administrator):
Last Update Date/Time: 07/28/2010 16:17:09

Device Class Name: FILEDEV1
Device Access Strategy: Sequential
Storage Pool Count: 1
Device Type: FILE
Format: DRIVE
Est/Max Capacity (MB): 204,800.0
Mount Limit: 32
Mount Wait (min):
Mount Retention (min):
Label Prefix:
Drive Letter:
Library:
Directory: E:\TSM\SERVER1\FILE1
Server Name:
Retry Period:
Retry Interval:
Twosided:
Shared:
High-level Address:
Minimum Capacity:
WORM: No
Drive Encryption:
Scaled Capacity:
Last Update by (administrator): TSMINST1
Last Update Date/Time: 07/29/2010 14:51:58

Device Class Name: LTOARCHIVE1
more... (<ENTER> to continue, 'C' to cancel)

Device Access Strategy: Sequential
Storage Pool Count: 0
Device Type: LTO
Format: ULTRIUM4C
Est/Max Capacity (MB):
Mount Limit: DRIVES
Mount Wait (min): 60
Mount Retention (min): 60
Label Prefix: ADSM
Drive Letter:
Library: LIB2
Directory:
Server Name:
Retry Period:
Retry Interval:
Twosided:
Shared:
High-level Address:
Minimum Capacity:
WORM: No
Drive Encryption: Allow
Scaled Capacity:
Last Update by (administrator): TSMINST1
Last Update Date/Time: 08/16/2010 09:07:19

Device Class Name: LTOCLASS1
Device Access Strategy: Sequential
Storage Pool Count: 2
Device Type: LTO
Format: ULTRIUM4C
Est/Max Capacity (MB):
Mount Limit: DRIVES
Mount Wait (min): 60
Mount Retention (min): 60
Label Prefix: ADSM
Drive Letter:
Library: LIB1
Directory:
Server Name:
Retry Period:
Retry Interval:
Twosided:
Shared:
High-level Address:
Minimum Capacity:
WORM: No
Drive Encryption: Allow
Scaled Capacity:
Last Update by (administrator): TSMINST1
Last Update Date/Time: 08/25/2010 10:43:04

Device Class Name: LTOCLASS2
Device Access Strategy: Sequential
Storage Pool Count: 1
Device Type: LTO
Format: ULTRIUM4C
Est/Max Capacity (MB):
Mount Limit: DRIVES
Mount Wait (min): 60
Mount Retention (min): 60
Label Prefix: ADSM
Drive Letter:
Library: LIB2
Directory:
Server Name:
Retry Period:
Retry Interval:
Twosided:
Shared:
High-level Address:
Minimum Capacity:
WORM: No
Drive Encryption: Allow
Scaled Capacity:
Last Update by (administrator): TSMINST1
Last Update Date/Time: 08/13/2010 12:22:39

 

[Raakin]

Nothing is sticking out to me as incorrect configuration.
I see the Library: LIB2 associated with LTOARCHIVE1 and LTOCLASS2; and LIB1 associated with LTOCLASS1, which is where the backup is going. A thought at this point is to confirm everything is the same with connections, etc to LIB1 comparing to LIB2 seeing works with the archive just fine.
Another thought is to test the backup directly to tape, perhaps the dedupe is causing a delay (Processes For Identifying Duplicates: 1 - perhaps higher is better??) but I'm not familiar with TSM dedupe.

 

[NateDJ]

The dedupe process is idle, it only runs when the copy has finished. I have archived to lib1 before I attached lib2 and had no trouble. Lib1 and lib2 configurations are the same.

 

[rszkolni]

My TSM 6.2.1 system is also experiencing slow throughput copying my backup disk FILE storage pool. This is a new system as I am trying to get some seat time with TSM 6.

The backup disk storage pool has dedup enabled and I have completed the identify dedup process. Now when I am copying this storage pool, I am getting very poor throughput, roughly 20GB every 12 hours.

My CPU is very busy when running the backup stgpool processes so my working theory is that my TSM server is reconstructing the data before it gets sent over to my virtual volume destination. I need to test this out once my copy storage pool actually completes. I am looking at a few more days until it is done.

The storage pool is about 300GB and I have about 19GB of dedup data identified.

For your situation, my guess is that you have dedup data already identified by TSM on FILE1 and that your slowness is because of data reconstruction. Just a guess.

What are the results of this command ...
show deduppending FILE1

This will show how much duplicate data is pending for removal on the FILE1 storage pool. If it is more than 0 then there is likely some reconstruction going on during the backup storage pool. That's the way I interpret the situation based on my experience. I need to test out this theory once I get things under control.

Robert,
The City of Winnipeg

 

[NateDJ]

Here is my finding of a clean, single node backup ran last night.

Each Physical file takes approximately 17 min. reguardless of file size.

Here is a parsed log:

9/9/2010 1:15:21 PM Bytes Backed Up: 742,186,915
Current Physical File (bytes): 202,097,597
17 Min.

9/9/2010 1:32:38 PM Bytes Backed Up: 944,284,512
Current Physical File (bytes): 66,696,103
17 Min.

9/9/2010 1:49:55 PM Bytes Backed Up: 1,010,980,615
Current Physical File (bytes): 336,932,749
17 Min.

9/9/2010 2:07:12 PM Bytes Backed Up: 1,347,913,364
Current Physical File (bytes): 305,397,939
17 Min.

9/9/2010 2:24:29 PM Bytes Backed Up: 1,653,311,303
Current Physical File (bytes): 105,858,766
18 Min.

9/9/2010 2:42:49 PM Bytes Backed Up: 1,759,170,069
Current Physical File (bytes): 98,194,799
17 Min.

9/9/2010 3:00:06 PM Bytes Backed Up: 1,857,364,868
Current Physical File (bytes): 603,437,019
17 Min.

9/9/2010 3:17:23 PM Bytes Backed Up: 2,460,801,887
Current Physical File (bytes): 508,477,992
17 Min.

9/9/2010 3:34:40 PM Bytes Backed Up: 2,969,279,879
Current Physical File (bytes): 400,197,366
17 Min.

9/9/2010 3:51:57 PM Bytes Backed Up: 3,369,477,245
Current Physical File (bytes): 72,273,616
17 Min.

9/9/2010 4:09:14 PM Bytes Backed Up: 3,441,750,861
Current Physical File (bytes): 180,347,010
17 Min.

9/9/2010 4:26:31 PM Bytes Backed Up: 3,622,097,871
Current Physical File (bytes): 63,883,643
17 Min.

9/9/2010 4:43:48 PM Bytes Backed Up: 3,685,981,514
Current Physical File (bytes): 4,033
17 Min.

9/9/2010 5:01:05 PM Bytes Backed Up: 3,685,985,547
Current Physical File (bytes): 25,284,315
17 Min.

9/9/2010 5:18:23 PM Bytes Backed Up: 3,711,269,862
Current Physical File (bytes): 33,878,185
17 Min.

9/9/2010 5:35:40 PM Bytes Backed Up: 3,745,148,047
Current Physical File (bytes): 29,455,673

9/9/2010 5:52:57 PM Bytes Backed Up: 3,774,603,720
Current Physical File (bytes): 1,254,566

9/9/2010 6:10:14 PM Bytes Backed Up: 3,775,858,286
Current Physical File (bytes): 4,842,267

9/9/2010 6:28:32 PM Bytes Backed Up: 3,780,700,553
Current Physical File (bytes): 11,724,542

9/9/2010 6:45:49 PM Bytes Backed Up: 3,792,425,095
Current Physical File (bytes): 9,552,672

9/9/2010 7:03:06 PM Bytes Backed Up: 3,801,977,767
Current Physical File (bytes): 80,846

9/9/2010 7:20:22 PM Bytes Backed Up: 3,802,058,613
Current Physical File (bytes): 26,739,877

9/9/2010 7:36:38 PM Bytes Backed Up: 3,828,798,490
Current Physical File (bytes): 1,497,073

9/9/2010 7:53:56 PM Bytes Backed Up: 3,830,295,563
Current Physical File (bytes): 13,704,654

9/9/2010 8:13:15 PM Bytes Backed Up: 3,844,000,217
Current Physical File (bytes): 6,685,403

9/9/2010 8:33:35 PM Bytes Backed Up: 3,850,685,620
Current Physical File (bytes): 4,767,241

9/9/2010 8:53:55 PM Bytes Backed Up: 3,855,452,861
Current Physical File (bytes): 3,170,060

9/9/2010 9:12:13 PM Bytes Backed Up: 3,858,622,921
Current Physical File (bytes): 2,876,919

9/9/2010 9:31:32 PM Bytes Backed Up: 3,861,499,840
Current Physical File (bytes): 3,238,303

9/9/2010 9:49:51 PM Bytes Backed Up: 3,864,738,143
Current Physical File (bytes): 4,364,937

9/9/2010 10:09:11 PM Bytes Backed Up: 3,869,103,080
Current Physical File (bytes): 6,098,795

9/9/2010 10:26:32 PM Bytes Backed Up: 3,875,201,875
Current Physical File (bytes): 7,078,163

9/9/2010 10:42:55 PM Bytes Backed Up: 3,882,280,038
Current Physical File (bytes): 5,910,903

9/9/2010 11:00:29 PM Bytes Backed Up: 3,888,190,941
Current Physical File (bytes): 13,609

9/9/2010 11:17:55 PM Bytes Backed Up: 3,888,204,550
Current Physical File (bytes): 27,922,735

9/9/2010 11:34:27 PM Bytes Backed Up: 3,916,127,285
Current Physical File (bytes): 20,668,623

9/9/2010 11:52:01 PM Bytes Backed Up: 3,936,795,908
Current Physical File (bytes): 15,731,778

9/10/2010 12:09:35 AM Bytes Backed Up: 3,952,527,686
Current Physical File (bytes): 17,536,863

9/10/2010 12:27:10 AM Bytes Backed Up: 3,970,064,549
Current Physical File (bytes): 14,200,381

9/10/2010 12:44:44 AM Bytes Backed Up: 3,984,264,930
Current Physical File (bytes): 15,190,590

9/10/2010 1:01:16 AM Bytes Backed Up: 3,999,455,520
Current Physical File (bytes): 7,536,487

9/10/2010 1:18:50 AM Bytes Backed Up: 4,006,992,007
Current Physical File (bytes): 622,697

9/10/2010 1:36:24 AM Bytes Backed Up: 4,007,614,704
Current Physical File (bytes): 14,621

9/10/2010 1:53:58 AM Bytes Backed Up: 4,007,629,325
Current Physical File (bytes): 12,396

9/10/2010 2:10:30 AM Bytes Backed Up: 4,007,641,721
Current Physical File (bytes): 3,055,717

9/10/2010 2:28:04 AM Bytes Backed Up: 4,010,697,438
Current Physical File (bytes): 1,167,671

9/10/2010 2:44:37 AM Bytes Backed Up: 4,011,865,109
Current Physical File (bytes): 11,858,976

9/10/2010 3:02:11 AM Bytes Backed Up: 4,023,724,085
Current Physical File (bytes): 9,805,657

9/10/2010 3:18:44 AM Bytes Backed Up: 4,033,529,742
Current Physical File (bytes): 149,343

9/10/2010 3:36:18 AM Bytes Backed Up: 4,033,679,085
Current Physical File (bytes): 3,621,428

9/10/2010 3:53:53 AM Bytes Backed Up: 4,037,300,513
Current Physical File (bytes): 5,702,164

9/10/2010 4:11:31 AM Bytes Backed Up: 4,043,002,677
Current Physical File (bytes): 8,036,550

9/10/2010 4:28:10 AM Bytes Backed Up: 4,051,039,227
Current Physical File (bytes): 7,390,350

9/10/2010 4:45:53 AM Bytes Backed Up: 4,058,429,577
Current Physical File (bytes): 8,244,582

9/10/2010 5:02:39 AM Bytes Backed Up: 4,066,674,159
Current Physical File (bytes): 7,980,708

9/10/2010 5:20:30 AM Bytes Backed Up: 4,074,654,867
Current Physical File (bytes): 7,640,984

9/10/2010 5:38:22 AM Bytes Backed Up: 4,082,295,851
Current Physical File (bytes): 8,131,041

9/10/2010 5:55:10 AM Bytes Backed Up: 4,090,426,892
Current Physical File (bytes): 8,036,843

9/10/2010 6:13:01 AM Bytes Backed Up: 4,098,463,735
Current Physical File (bytes): 7,796,117

9/10/2010 6:29:49 AM Bytes Backed Up: 4,106,259,852
Current Physical File (bytes): 8,025,377

9/10/2010 6:46:37 AM Bytes Backed Up: 4,114,285,229
Current Physical File (bytes): 8,153,302

9/10/2010 7:04:28 AM Bytes Backed Up: 4,122,438,531
Current Physical File (bytes): 7,793,537

9/10/2010 7:21:16 AM Bytes Backed Up: 4,130,232,068
Current Physical File (bytes): 7,982,631

9/10/2010 7:39:07 AM Bytes Backed Up: 4,138,214,699
Current Physical File (bytes): 7,562,742

9/10/2010 7:55:55 AM Bytes Backed Up: 4,145,777,441
Current Physical File (bytes): 7,968,394

9/10/2010 8:12:44 AM Bytes Backed Up: 4,153,745,835
Current Physical File (bytes): 7,161,597

9/10/2010 8:30:35 AM Bytes Backed Up: 4,160,907,432
Current Physical File (bytes): 7,445,699

9/10/2010 8:48:28 AM Bytes Backed Up: 4,168,353,131
Current Physical File (bytes): 7,262,117

9/10/2010 9:05:16 AM Bytes Backed Up: 4,175,615,248
Current Physical File (bytes): 7,095,454

9/10/2010 9:22:05 AM Bytes Backed Up: 4,182,710,702
Current Physical File (bytes): 8,219,820

9/10/2010 9:38:58 AM Bytes Backed Up: 4,190,930,522
Current Physical File (bytes): 7,245,711

 

[NateDJ]

I have now tried with a completely new backup set, new Diskpool, file pool, and LTO Copy pool, no de-dupe and backing up to a different LTO tape system of the same type. My results are exactly the same as before.

 

[rszkolni]

I have done some testing with dedup on/off my backup storage pool. Export/importing a few nodes to generate some new backup space in the pool. Total size is about 20GB. With dedup enabled the storage pool backup is more than a couple hours. 20GB in a few hours. Not good. With dedup disabled, the 20GB storage pool backup is 5 minutes.

I don't think this helps you out NateDJ. You might want to try a copy storage pool to another disk pool just to take LTO out of the equation. Or try migrating data to tape to see how long it takes.

 

[egtegt]

Frankly, I don't recommand using dedupe on TSM. It's not very efficient and it will give you more problems than anything. Buy some new disks, it will be worth the price