Veeam Backup of VMware VM with Domino (and auto-recovery snapshot working) failing - possibly due to some timeout

[tjirka-dcit]

I am following on #29

creating new issue, as that is already closed

in Veeam Backup view of status of backup jobs I see errors - text copy of those errors:
18.02.2025 22:01:26 :: Failed to create VM snapshot. Error: CreateSnapshot failed, vmRef vm-5335, timeout 1800000, snName VEEAM BACKUP TEMPORARY SNAPSHOT, snDescription Please do not delete this snapshot. It is being used by Veeam Backup., memory False, quiesce True

18.02.2025 22:12:17 :: Processing ld Error: Failed to prepare VM for processing: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details. (An error occurred while saving the snapshot: Failed to quiesce the virtual machine., An error occurred while taking a snapshot: Failed to quiesce the virtual machine.)

18.02.2025 22:12:20 :: Error: Failed to prepare VM for processing: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details. (An error occurred while saving the snapshot: Failed to quiesce the virtual machine., An error occurred while taking a snapshot: Failed to quiesce the virtual machine.)

18.02.2025 22:12:24 :: Processing finished with errors at 18.02.2025 22:12:24

18.02.2025 22:01:47 :: Failed to create VM snapshot. Error: CreateSnapshot failed, vmRef vm-225379, timeout 1800000, snName VEEAM BACKUP TEMPORARY SNAPSHOT, snDescription Please do not delete this snapshot. It is being used by Veeam Backup., memory False, quiesce True

18.02.2025 22:12:17 :: Processing traveler Error: Failed to prepare VM for processing: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details. (An error occurred while saving the snapshot: Failed to quiesce the virtual machine., An error occurred while taking a snapshot: Failed to quiesce the virtual machine.)

18.02.2025 22:12:21 :: Error: Failed to prepare VM for processing: An error occurred while quiescing the virtual machine. See the virtual machine's event log for details. (An error occurred while saving the snapshot: Failed to quiesce the virtual machine., An error occurred while taking a snapshot: Failed to quiesce the virtual machine.)

18.02.2025 22:12:24 :: Processing finished with errors at 18.02.2025 22:12:24

from messages from Domino Backup in Domino logs it seems to me, that it fails when it is more than 60 seconds in this type of message:
[24C0:0004-1EE0] 18.02.2025 22:29:22 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 62 seconds!

I am wondering if there is some timeout set up in Domino Backup, or Windows vss, or in VMware Tools quiescence, or in Veeam Backup that it fails after 60 seconds.

It seems that the new style of Domino server backups, which is now an auto-recovery snapshot, I set up on the evening of February 11, 2025. So, it has been running since the regular backups on the night of February 11 to 12.

In one of console.log archived files I have found:
[1B88:0004-1AF0] 05.02.2025 22:04:36 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 103 seconds!

Interesting, before 11.2.2025, vss snapshot inside was done by Veeam app-aware processing, not by VMware Tools quiescence (which allows Domino Backup to create auto-recovery snapshot), and 5.2.2025 OnFreeze message is with 103 seconds, which is more than 60 seconds, and in Veeam Backup I see that backup was successful on first try.

I will send details by email to Daniel Nashed as I believe he will be looking at this issue (I have prepared Word document with inserted screenshots, messages from logs, and other details).

[tjirka-dcit]

And I am getting during test recovery message "...Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)" such as:
[03B0:0002-1274] 19.02.2025 17:52:13 Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)

Always only one db needed recovery.

Is it possible that Domino Backup is having trouble to get names.nsf to application consistent state during vss style backup as it is special database?

[tjirka-dcit]

I would like to add that it is not obvious which database was being recovered. I am not sure how to find it. It seems to me that name of db being translog recovered is not written to any of those logs: console.log and log.nsf.

[Daniel-Nashed]

Thanks for making this as new issue.

The default timeout should be 400 seconds on The Domino side.
But backup applications or VSS might expect the VSS snapshot to be ready within 60 seconds.

Normal cases it took just 2 seconds to bring your databases into backup mode.
Bringing a database into backup mode should always work and is not depending on a database in use like names.nsf.
The API is designed to bring databases into backup mode.

We need to find the root cause why this is sometimes taking 2 seconds and sometime much longer.
I have seen other cases where an admin got it working with a longer time than 60 seconds.
But for your number of databases it should not take longer than a couple of seconds.

The call to bring a database into backup mode is the standard call all backup vendors use NSFBackupStart().
There is currently no timing check around this call and we never had any problem reports.

Please provide console.log output not log.nsf output. We might still miss relevant information to find out about why it takes longer.

Also you might want to check on the VMware and Veeam side about why it fails after 62 seconds.
There might be settings. Not sure if this would be VMware or Veeam where settings could be maybe tuned.

@hanneskasp do you have an idea what could cause a timeout with Veeam triggered snapshot using VMware after 62 seconds?
Are you aware of any settings or limitations?

[Daniel-Nashed]

I would like to add that it is not obvious which database was being recovered. I am not sure how to find it. It seems to me that name of db being translog recovered is not written to any of those logs: console.log and log.nsf.

Recovery is a restore topic. The database you request is being recovered.
You can recover single databases or on multi restore multiple databases are copied back and are recovered together -- applying the logs for the list of databases.

I don't understand what is missing here. An admin selects the database and restores it.
Please provide exact information was is missing and in which context you see a recovery. is this restore or some other situation?

[tjirka-dcit]

I would like to add that it is not obvious which database was being recovered. I am not sure how to find it. It seems to me that name of db being translog recovered is not written to any of those logs: console.log and log.nsf.

Recovery is a restore topic. The database you request is being recovered. You can recover single databases or on multi restore multiple databases are copied back and are recovered together -- applying the logs for the list of databases.

I don't understand what is missing here. An admin selects the database and restores it. Please provide exact information was is missing and in which context you see a recovery. is this restore or some other situation?

I do not meant recovery of single database from backup; it is test restore of whole VM from backup - if backup was only crash consistent I would see in console.log something like:
[1618:0002-161C] 20.02.2025 15:38:38 Recovery Manager: Restart Recovery complete. (400/400 databases needed full/partial recovery)

(all databases being recovered from translog)

But I see only one db recovered from translog:
[1618:0002-161C] 20.02.2025 15:38:38 Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)

So it seems backup is mostly application consistently done - for all dbs except of one.

I am wondering which one it is. When server starts it seems it does not log to console.log which specific database(s) needed recovery using translog. Or may be it does but I am not able to see it due to it being very spammy and confusing.

If there were not multiple "Recovery Manager: Recovery being performed for DB " lines for different dbs, and only for one, it would be clear. When this is mentioned for more than one db, how can I find from that which one db was really recovered using translog (because getting it to consistent status during backup failed)

Example of that confusion:
[1618:0002-161C] Recovery Manager: Recovery being performed for DB d:\notes-data\names.nsf
[1618:0002-161C] refreshing dbdirman.nsf, database d:\notes-data\log.nsf not found - 20.02.2025 15:38:34
[1618:0002-161C] finished refresh - 20.02.2025 15:38:34
[1618:0002-161C] Recovery Manager: Recovery being performed for DB d:\notes-data\log.nsf
[1618:0002-161C] refreshing dbdirman.nsf, database d:\notes-data\certstore.nsf not found - 20.02.2025 15:38:34
[1618:0002-161C] finished refresh - 20.02.2025 15:38:34
[1618:0002-161C] Recovery Manager: Recovery being performed for DB d:\notes-data\certstore.nsf

Or may be there is error in the summary report "Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)". I am guessing may be code of it does support reporting zero (0/0), when auto-recovery snapshot is in play.

I will send you by email console.log from first start of Domino in test restore of VM.

[Daniel-Nashed]

You are still in the case recovering the full machine in an unsupported way not explaining exactly what you are doing...
So this is the recovery of the machine into a separate machine with Veeam tools?
This is translog kicking in and the transaction log you have in that moment is not 100% matching. Because the translog is a different story.

Domino backup is intended to recover NSF files by restoring them and using translog iff needed to roll them forward.

[tjirka-dcit]

We need to find the root cause why this is sometimes taking 2 seconds and sometime much longer. I have seen other cases where an admin got it working with a longer time than 60 seconds. But for your number of databases it should not take longer than a couple of seconds.

I think that root cause is this:

at 22:00 starts Veeam backup of almost all of our VMs (something like 100+ VMs) at the same time

(I prefer to have the backup taken at the same moment, so in case of restoring multiple virtual machines, the data restored from backup would be from the same time, ensuring consistency)

at start of backup it is doing quiescence in all VMs (in some using Veeam app-aware processing - Veeam logging inside of VM and running some Veeam code, in some using VMware Tools), then creating VMware snapshots for all these VMs, then creating snapshots of LUNs on disk array, then deleting VMware snapshots, then doing backup from storage snapshots (backup server is connected to our disk array Dell SCv3020 using fibrechannel and has right to mount snapshots from storage (and create snapshots, ...)), after that storage snapshots are deleted

it has probably very hard performance hit on our VMware infrastructure and our disk array

I was thinking about scheduling backup job of our two VMs with Domino servers (and only two other servers, so that first two phases of backup should not take more than few minutes) to 21:55

important is start of backup - when backup is being done from disk array storage snapshot it is transparent for VMs, and there should not be some serious penalty as disk array snapshots are being accelerated, I think almost the same performance as without snapshot

what I suspect has the most performance hit is doing quiescence in all VMs and creating VMware snapshots (as VMware snapshots are much less effective than disk array snapshots - I have heard that it would be better if we were using VMware vSAN, but that is not the case)

[tjirka-dcit]

You are still in the case recovering the full machine in an unsupported way not explaining exactly what you are doing... So this is the recovery of the machine into a separate machine with Veeam tools? This is translog kicking in and the transaction log you have in that moment is not 100% matching. Because the translog is a different story.

Domino backup is intended to recover NSF files by restoring them and using translog iff needed to roll them forward.

it is test restore of backup using Veeam SureBackup - I would like to know how it will behave then doing restore of whole VM - but doing real restore of backup to new VM would take much time as the VM has almost 1 TB - so I prefer SureBackup which runs new VM from backup in isolated network and disk changes written to selected LUN

And now it occurred to me that the problem might be that we have the transaction log on a different disk than the data.

So, although a Domino Backup VSS auto-recovery is created from the data disk, it's quite possible that the VSS snapshot of the disk with the transaction logs does not occur at the same moment - or rather, the state of the transaction logs may not be entirely consistent with the state of the databases in the auto-recovery VSS snapshot of the data disk.

It might become consistent if I moved the transaction log to the disk with the data.

Or may be I can try to stop myself hunting perfect score and force myself to think that this is enough.

Nevertherless it frustrates me that I do not know which one database is being recovered by transaction log, or even if it is still the same db.

[Daniel-Nashed]

Again you are in a complete server recovery mode.
And as you say translog on a different disk can make a difference.
I can't say which database needs recovery. The translog system does not report it.
But that's not a problem. it's doing it's work.

Having translog in the same volume would work eventually better if this is your primary restore scenario.

But this is not our primary restore scenario.

In at least 95% of the cases you need to restore single databases or a couple of databases to recover data.

• User is missing documents
• Database is corrupted

For corrupted databases there might be even easier ways if you are running in a cluster.
Domino provides database repair which just got improved with repairing DAOS NLOs separately.

The normal use case is to let Domino restore mount the right backup, restore a database to the original location or to another location for the user to look at documents and copy them back.

There is even an option to restore deleted documents and folders to the original database.

Having said that, what you are doing should still work but is not the standard restore case.

Kicking off many backups at the same time on different VMs isn't a good idea in general and could cause impact not only on snapshots but at server performance.

You should schedule your backups to not cause too much load on the virtual environment.

Adding debug to track each call to bring databases into backup mode could help to find out.
I can see if we can add more diagnostics to the upcoming Domino 14.5.

We could also report a warning if a database would take longer than let's say 5 seconds to be in backup mode.
This would capture hang situations for a database.

Thanks for your console.logs I will have a look if I can spot something.

[Daniel-Nashed]

You have translog replayed because the databases and translog is different.

It looks like log.nsf is the database getting recovery performed.
Which is not really a problem. you just get the latest changes applied.
Looks like your translog is newer than the NSF snapshot from what I see.

I was also expecting backup console.log but your logs have been from the recovery step only.

Looks also like you still have dbdirman.nsf on your server - which is not needed any more.

[1618:0002-161C] Recovery Manager: Recovery being performed for DB d:\notes-data\mailbox.ntf
[1618:0002-161C] Restart Replay (54 MB): 10% 20% 30% 40% 50% 60% 70% 80% 90% 100% 
[1618:0002-161C] Clearing DBIID CAD4E3F7 for DB d:\notes-data\log.nsf
[1618:0002-161C] 20.02.2025 15:38:38   Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)

[tjirka-dcit]

I was also expecting backup console.log but your logs have been from the recovery step only.

I have additionally sent you by email console.log logs regarding backup

Kicking off many backups at the same time on different VMs isn't a good idea in general and could cause impact not only on snapshots but at server performance.
You should schedule your backups to not cause too much load on the virtual environment.

in today's backup job it have failed again for our primary Domino server (success on first retry)

so I have changed schedule time for that backup job zalohy-3-streda from 22:00 to 21:55, that should make it better

still I am wondering why threshold for that OnFreeze time seems to be only 60 seconds

Looks also like you still have dbdirman.nsf on your server - which is not needed any more.

I have already deleted it. I do understand why it is still being mentioned in console.log. May be some "bug" - copy&paste error in Domino server code - not replacing "dbdirman.nsf" in code responsible for writing to console.log in code inherited from dbdirman.nsf (if I understand correctly some functionality equivalent to dbdirman.nsf was moved directly to Domino).

And as you say translog on a different disk can make a difference.

I was trying to move translog do data disk in test restore of our main Domino server (that Veeam SureBackup, as I already mentioned in that other issue it is great for testing planned changes), I was thinking that best way would be to temporary disable transaction logging, then restart server, then move that directory to data disk, then enable translog again with setting new path, then restart server

but I was surprised that after first restart of server it has crashed, it seems like our server cannot run with translog disabled

so I would probably need to choose some other method

[Daniel-Nashed]

Don't remove translog! Why are you doing things on your own making it worse.
I can't spend more time if you don't do what I ask for.

Don't work on assumptions and try things on your own please.

I can't tell you why Veeam or VMware is not giving you more time than 60 seconds.
And would need to check with Veeam. I mentioned a contract from Veeam. But he can't reply until next week as he mentioned to me this afternoon.

I can't research everything for you in technology outside Domino.
Maybe you could do some research on your end and as someone to support you on the VMware/Veeam side.

I have worked with customers who had a longer timeout. I could try to simulate a longer time to bring databases into backup mode in my lab. But this would take additional time on my side.

Just because HCL is having a VSS implementation this does not make us responsible for everything happening on your Windows machine and with 3rd party backup applications.

I am trying to help. But I need you to also look on your end. The timeout is out of Domino's control.

Here is what I found so far --> https://www.veeam.com/kb1680

This looks like a VSS limit. I have not found anything to increase the limit.

[hanneskasp]

Hello,
our timeout is 1800 seconds (1800000ms)

mRef vm-5335, timeout 1800000

This should be investigated by Veeam support. From the log excerpt, it's hard to say whether it's a VMware thing or something else

An error occurred while quiescing the virtual machine

From Veeam side (I work for Veeam), I can only recommend to open a case to investigate the "An error occurred while quiescing the virtual machine" error.

Best regards
Hannes

[Daniel-Nashed]

there is a smaller change we could add on our side.
currently prune operations are executed before the backup.
this isn't a helpful for a VSS snapshot.

for a snapshot we should make sure prune operations are performed after the backup.
but because no database files need to be deleted and no other actions beside cleaning up the inventory, it should not have a huge impact. still if you have a larger number of databases, this might take time.
It's arguable if this is an enhancement request or a bug fix.
But it can impact VSS snapshots.

SPR # DNADDE8JT6 Domino VSS Snapshot backup retention can impact VSS snapshot freeze time needed

This would not be a complete solution but could improve freeze time needed in some case.

[tjirka-dcit]

Don't remove translog! Why are you doing things on your own making it worse. I can't spend more time if you don't do what I ask for.
Don't work on assumptions and try things on your own please.

I have only tried it in test copy of production environment (Veeam SureBackup of disk storage snapshot backup), because I was not at first sure how to correctly move the translog (I did not wanted to make experiments on production). I have thought that may be temporary disabling it would be the right way. I have even found one result during googling it that confirmed that (I am having trouble to find it again, may be I just misinpretted something; btw I remember that it lead to some HCL web and that I did not have permissions to view that page, I have only saw part of content in what google cached and displayed with found URL)

Btw I have tried to move translog to data directory (it seems correct way is to change path in server document using Domino Administrator, then shutdown Domino server, then move directory with translog, then start Domino server) - and as it behaves the same ("Recovery Manager: Restart Recovery complete. (1/1 databases needed full/partial recovery)" when doing test restore of whole VM) I have moved it back. It will leave it as it is, important is that dbs are in consistent state in backup. That backup of whole VM includes backup of a little bit newer state of translog and it applies when doing (test) restore of whole VM is I believe OK.

And regarding long time during "vss magic time" it seems that it is backuping on first try after I have changed schedule of that job five minutes before other backup jobs.

Last fail 20.2.2025 22:00, after that that backup jobs starts on 21:55 and always green on first try.

in logs of our main Domino server:
[2870:0004-17E0] 22.02.2025 21:57:34 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 35 seconds!
[2870:0004-17E0] 23.02.2025 04:17:19 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 27 seconds!
[2870:0004-17E0] 23.02.2025 21:56:48 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 4 seconds!
[2870:0004-17E0] 24.02.2025 04:17:02 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 21 seconds!
[2870:0004-17E0] 24.02.2025 21:57:00 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 21 seconds!
[2870:0004-17E0] 25.02.2025 04:18:30 BackupVSS: DominoVSSWriter::OnFreeze Domino in Freeze Mode after 33 seconds!

btw 4:xx is about replicating that VM to disaster recovery ESXi

As it is working now fine it is probably time to thinking about this case as solved (until it stops doing backup on first time or some other issue).

Here is what I found so far --> https://www.veeam.com/kb1680
This looks like a VSS limit. I have not found anything to increase the limit.

The issue described at https://www.veeam.com/kb1680 is exactly our case, thanks for finding it.
...
Microsoft VSS will only hold a freeze on the writers for up to 60 seconds (20 for Exchange) and will automatically unfreeze (thaw) the writers once that timeout is met.
...

This corresponds to the 60-second threshold that I identified.

So probably we just need to make our system making it done without that time frame.

SPR # DNADDE8JT6 Domino VSS Snapshot backup retention can impact VSS snapshot freeze time needed

Thanks, anything that help evens a little could be fine, as it seems we have freeze time about half a minute most time even in time when it doest not compete for performance with other backup jobs.

I am not sure what factors are contributing to that long time, may be indexing of db(s), some agents running, or event something other. Or of course can be other VMs consuming more resources in that time too - can be complicated to find exactly.