API Changes in 12.2?

[HansMeiser]

Hello,

some days ago i wrote in the tape-section about strange behaviour of tape-management in 12.2.
tape-f29/ndmp-salience-after-update-to-12-2-t95753.html

We did further investigation of the problem and this post represents last level of information.

back story: For different jobs we have different mediapools containing a bunch of tapes. Last written tapes are transported to our safe in the basement and offline tapes are replaced with other ones. For changing tapes by hand in the libary it is very helpful if tapes are used by veeam in ascending sequence by their tapenumber. So last written tapes can be found as sequence in same position and you dont have effort to search all library-boxes. In last years veeam was not very helpful to achieve this goal, veeam was taken random numbers of free tape so our notice. For this reason we use a powershell script which is manageing tapes for us. We created an additional mediapool called "reserve" to keep all free/expired tapes. Our script is watching progress of backup and moves next free tape in ascending number to mediapool if last free tape is in use. So we ensure that always one free tape is available for backupprocess representing an ascending sequence. This works for many years but it seems there are changes in 12.2

notice:
It seems that informations about tapes delivered by API are not up-to-date in every case. So our script was moving a allegedly free tape to Mediapool "Reserve", but in reality this tape was already used and written. We noticed this behaviour, but failed to reason at this time.
So we had a written tape in Mediapool "Reserve", this tape was taken to safe in basement and is currently offline but was the start for the problem i posted in the tape-section.
For some reason veeam absolutely wanted to use exactly this tape on the next backupprocess. In logs we found hundreds of messages: Tape 123 expected but Tape 456 locked and veem did not found a solution for this problem and looped for some hours.
Why veeam absolutely needed tape 123 is incomprehensible. The tape was at this time a) in the wrong mediapool, b) offline and c) a newer mediaset was already existing on other tapes.
So this all is only a follow-up problem. It seem that origin of error is that infos about tapes/mediapools are not always up-to-date when working with API. I dont know if this is a problem of Veeam 12.2 or the newly used PostgreSQL as a replacement for MS SQL Express.

So what do you think? Something known on this side? 12.2 Changelog confirms updates on tapemanagement. Please tell me your opinion.

Thank you,
Hans

[david.domask]

Hi Hans,

Thank you for the detailed explanation and sorry to hear that there are challenges. For understanding why Veeam was intending to use Tape 123, I would ask that you please open a Support Case and let Veeam Support review the behavior. Be sure to include logs for the affected job for Support to review. (use the 1st radio option to select from jobs, and select the affected job)

A few comments/questions about your scenario though:

1. For your Powershell script, it's simply using Get-VBRTapeMedium and then passing it to Move-VBRTapeMedium?
2. How are you checking in the script that a tape is free and not currently used? Can you share the code block?

At first blush, can't quite say how the script and the Tape job decided that Tape 123 was needed, and this will require a review of the logs; there are no changes specifically to the tape Powershell endpoints that would result in this, so Veeam Support will need to check the behavior in the logs.

Please open a case and share the case number here once you have it.

Thanks!

[HansMeiser]

Hello,

i did some litte bit more research in this case. i tried to follow the path of the tape which seems to be the root of the problem.
Yes, we use Move-VBRTapeMedium to move tapes to mediapools. moving tapes mark them as free and the tape can be used in backupjob. we move the tape to "reserve" and back again to the media pool where it is needed. so the tape should end up in right mediapool and status is free. this happens with tape 123 on 22.09.2024 at 16:01 (endtime of script)
almost the same time i found a veeam logline which is new to me:
22.09.2024 15:59:28 :: Add tape to media pool my_media_poola (Scalar_i3 (ip.ip.ip.ip)). Oldest retained tape: 123. Last written tape: 122

So it seems that some seconds before the script was working veeam itself moved a tape to mediapool "my_media_poola" which should not happen. i read about registry keys TapeMarkExpiredMediaFree or TapeGfsExpiredMediumSharing which should allow this, but we dont have any of them active under HKEY_LOCAL_MACHINE\SOFTWARE\Veeam\Veeam Backup and Replication\ . So from my side veeam is not allowed to do this unless some defaults are changed in 12.2
result was that tape 123 ended up in mediapool "reserve" and was written too. this is a paradox situation because veeam should not use a tape from wrong mediapool and otherwise the tape would be free if the script moved it to "reserve" after writing.
may be the two move-commands worked for the same time and are not completely isolated/blocked to each other.

next time the job was running we had the problem that tape 123 was expected. also unexplainable for us because the tape was at this time a) in the wrong mediapool, b) offline and c) a newer mediaset was already existing on other tapes. this seems to be a follow up problem. we think about opening a ticket for this part of the problem, but we do not open the ticket by our selfs, this will be done by our servicepartner.

So what do you think about the competition of the to move processes and why veem is adding tapes to mediapools without explicit permission.

Thansk,
Hans

[HansMeiser]

Hello,

So we have this:
22.09.2024 15:59:28 :: Add tape to media pool my_media_poola (Scalar_i3 (ip.ip.ip.ip)). Oldest retained tape: 123. Last written tape: 122

this implies that tape 123 was moved to a mediapool. i tried to confirm this lines by corresponding lines in txt files and found some interesting lines in performer_1.log
reading this lines then it seems that veeam was not automatically moving tapes.

[22.09.2024 15:59:28.918] <67> Info (3) [TapeMedium] Capturing tape medium from media pool 'Free' to media pool 'my_media_poola'
[22.09.2024 15:59:28.933] <67> Info (3) [TapeMedium] No tape medium has been captured

and some lines later it seems that our script was working succesfully and delivered the tape:
[22.09.2024 16:02:30.295] <67> Info (3) [CTapeMediumForWriteFindAlg] Free tape medium found in current media pool: [TapeMedia 000123/46aedb1a-beff-43db-b616-ab45491e40bd, 5999999057920b/5999999057920b (Protected: False, IsActive: False, Retired: False, IsFree: True, IsFull: False, IsOnline: True, IsWriteProtected: False, IsWorm: False), MediaSetId: , MediaSetType: Simple, Location: library (Id: 98d138ce-e6b7-40ba-b04e-92f3a938cc30) in Slot69]

So according to the logs the procedure went ok so far.

some hours later at the end of writing data to tape we have this:

[22.09.2024 19:28:50.272] <15> Info (3) [Tape 000123] Updating, Capacity 5999999057920, Remaining 2726218956800, PartitionCount 0, IsWriteProtected False, IsWorm False, UsageStatistic {LifetimeRead: 22598MB, LifetimeWritten: 97503102MB, LoadCount: 56, CleaningCyclesLeft: 0}
[22.09.2024 19:28:50.334] <15> Info (3) Media pool Reserve is not changed, current tape is 000123

So in last line we read about "Reserve". This may be the time when tapeinfo is saved and contained a wrong mediapool. I have no idea why it is talking about "Reserve" at this point.
this is the only time i found the word Reserve in this log.

when comparing with lines of other tapes then it did not tell about "Reserve" but the real mediapool.
[22.09.2024 15:23:33.193] <67> Info (3) Media pool my_media_poola is not changed, current tape is 000122

So at some point veeam cheated and replaced "my_media_poola "with "Reserve" and used this as real name mediapool and saved this data to database.

Thanks,
Hans

[david.domask]

Hi Hans,

While I appreciate the detailed write up, may I ask if there is already a Support case opened?

If the Tape job is really taking a tape from the incorrect media pool, the behavior is not expected, but we really will need a Support Case so Veeam Support can check the logs more carefully, we will not be able to troubleshoot this over the forums.

Please open a Support case and share the case number here as per the forum rules; while I do agree there is unexpected behavior, a deeper review of the logs will be required to explain it in full.

[HansMeiser]

Hello,

still not opened, i will discuss with my mate and our service partner.

Thank you,
Hans