Tape job ends with "Success" but actually fails to complete

[skrause]

Case# 01923979

So this is a fun one, it happened to me in September when trying to send the full from a large file server (1.9TB) located on a remote repository to tape to send to cold storage per our retention policy. Because of how tape jobs cannot use the most recent restore point from a backup copy job, I had to resort to pulling the entire full backup "over the wire" to tape for this server due to the very high daily change rate on this server of ~15% (it is where our DBA backs up all of our production SQL servers due to some quirks with our setup and SQL Always On) we can't run the copy every day due to bandwidth and storage limitations in the target location.

When the job ran, the job showed that it was a success on the server in question, but when you look at the tape properties there is no files listed at all for this server and when you look at the details on the backup in question it says "0 folders and 0 files backed up". No warnings or errors show up in the console.

Code: Select all

10/5/2016 8:58:37 AM :: Building source backup files list started at 10/5/2016 8:58 AM 
10/5/2016 8:58:37 AM :: New SERVER01.vm-98142016-10-01T233102.vbk restore point will be placed to media set  
10/5/2016 8:58:37 AM :: Source backup files detected. VBK: 1, VBK map: 0, VIB: 0 
10/5/2016 8:58:37 AM :: Queued for processing at 10/5/2016 8:58:38 AM 
10/5/2016 8:58:38 AM :: Processing full backups started at 10/05/2016 08:56:43 
10/5/2016 8:58:42 AM :: [SERVER01] Drive 2 (Server: VR01, Library: IBM 3573-TL C.50, Drive ID: Tape0) locked successfully 
10/5/2016 8:58:55 AM :: [SERVER01] Current tape is UIF352L5 
10/5/2016 8:59:11 AM :: New tape backup session started, encryption: hardware 
10/5/2016 8:59:22 AM :: [SERVER01] Processing SERVER01.vm-98142016-10-01T233102.vbk 
10/5/2016 3:23:20 PM :: 0 directories and 0 files backed up 
10/5/2016 3:23:20 PM :: Busy: Source 0% > Proxy 29% > Network 0% > Target 35% 
10/5/2016 3:23:20 PM :: Primary bottleneck: Target 
10/5/2016 3:23:20 PM :: Network traffic verification detected no corrupted blocks 
10/5/2016 3:23:20 PM :: Processing finished at 10/5/2016 3:23:20 PM 

I have developed a new workaround with our DBA which will make it so we don't have to send this server's backup to tape (copying the full backup files of production systems weekly to a server in the "target" location which we can back up locally and send to tape.) so this exact issue probably won't crop up for us again but I wanted to get the dev team a heads up as the job is definitely dying for some reason but is not showing any error. If I had not caught it last month when I only had 2 tapes for 4TB worth of backups I would never have noticed.

[rreed]

I'd also like to see this as a warning (0 files/folders backed up) rather than success please. I get that the job ran successfully and no *errors* occurred, but I need to know if when I'm expecting files to get picked up, and they didn't, I need to go do some investigating.

[skrause]

So it looks like the reason the job actually failed is that tape agents don't re-connect sessions if there is a network blip like backup or replication agents do. Which is annoying but /shrug. Would be nice if the tape agent could buffer a bit of the data stream ahead of the writes in case there is a blip (any network blip in our case would have been maybe 50-100 milliseconds during a firewall rule refresh at worst).

The "success" message even though it obviously didn't copy all the files looks to be a bug that is being sent up the support tiers.