Protect STGPool constantly mounting and unmounting tape.

[Nudge]

We recently converted to storage pools and when we do a protect to tape on these storage pools, the process is constantly mounting and un-mounting the same tape. Is this normal behavior? It is taking over 6 hours to back up ~4TB to tape. This is still behaving the same at 7:38AM this morning.

05/12/2020 01:30:38 ANR0984I Process 527 for PROTECT STGPOOL (WORKER) started
in the BACKGROUND at 01:30:38. (SESSION: 76245, PROCESS:
527)
05/12/2020 01:31:08 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 523)
05/12/2020 01:35:10 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:35:10 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:36:50 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:36:50 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:38:51 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:38:51 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:40:46 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:40:46 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:42:49 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:42:49 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:44:55 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:44:55 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:46:40 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:46:40 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:48:47 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:48:47 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:50:34 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:50:34 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)
05/12/2020 01:52:20 ANR0515I Process 527 closed volume XX0012. (SESSION:
76245, PROCESS: 527)
05/12/2020 01:52:20 ANR0513I Process 527 opened output volume XX0012.
(SESSION: 76245, PROCESS: 527)

 

[RecoveryOne]

I would say its normal. I see it a lot in my environment.
So 4tb in 6 hours is about 200Mb/sec. What type of tape drives are you using? Are you writing to more than one tape drive? What's your infrastructure like (San speed, disk speed/type, dedicated hba's for driving tape, or sharing them with your storage array, etc)? Last night I wrote 1.49Tb to 6, LTO6 drives (6 workers) in about 2 hours 25 mins. So, once again near 200Mb/sec. And frankly, that is a a massive improvement over what I was achieving previously after some infrastructure work on the SAN side of things to my tape drives. So, I'm pretty happy with it. Some nights I see 2.5Tb protected to tape in 2 hours 5 mins, or around 390Mb/sec or so. Really just depends on how busy my server is.

Also, if you are just running the straight protect process, it will automatically reclaim tapes if they reach the reclamation threshold set in the copy pool. That will add time to your process. What I've done, is every day is run a PROTECT STGPOOL <POOL> type=local reclaim=no, and then once a week issue a PROTECT STGPOOL <pool> type=local reclaim=only.

In the past IBM has stated that I could reduce the number of protect processes and see if I get any better performance. I've not yet done that.

When you were running legacy pools, how long did your backup processes take for roughly same amount of data? How long and how often did space reclamation run for that copy pool?