Veeam seems to stop VM

[BernhardBergmann]

Hello Veeam-Friends,

we have a situation here at one of our small customers. There is only one single host (ESXi 5.5) with 2 Windows Server 2008 R2 - VM. One of the VM (VM2) has Veeam 7 R2 installed and a Tandberg RDX-Drive (USB) is given through ESXi. The normal Veeam-Backup is written to NAS and then copied to Tandberg RDX by script with robocopy. Now the problem is that sometimes the other VM (VM1) stops responding and cannot be switched off, reset or anything else via vSphere Client anymore. The host must be completely restarted to regain reboot VM1. Sometimes the Veeam-snapshot is already removed, sometimes it is stuck at removal and sometimes the snapshot is not removed and removal process is not even started.
The reboot of the host is initated always by remote session to VM2 (seems to work nearly as normal).

I do not have any further ideas what is happening here and even whether Veeam has to do with this problem....

[emachabert]

Any relevant information in Windows events of the stale VM ?

[veremin]

You mean the VM in question experiences the said behaviour during backup activity, right? Have you tried to take a snapshot manually, keep long it enough (the time similar to the one backup job takes), delete it and see whether the issue is reproduced or not?

Thanks.

[foggy]

Also, how about the actual backup jobs? Am I understanding right that the described behavior is observed while the backup job of the VM1 is running? Does the job fail or stuck or what is its final status?

[cby]

It's not clear from what you say whether the tape backup starts after the Veeam backup completes. If it kicks in during the backup job there can be unpredictable results, and of course a less than useful tape backup. Also using USB via the ESX host may be causing an issue.

[Vitaliy S.]

I would also suggest reviewing VMware VM logs to get more insight on what's going on.

[BernhardBergmann]

Sorry for late answer.

Did not have any further "stuck situation" since then. The backup seems to work as intended, last time the following backup (in the evening after the situation had a warning on VM1 (Cannot use CBT. Soap fault. ...., endpoint).

Windows Logs on both VM does not show anything interesting, at VM1 it actually does not show anything between the successed backup (exactly the time this VM should have been backed up) and the restart.

The Copy to Tape (RDX) is initiated by post-backup-script (Robocopy since RDX is just an external hard-drive).

The VMware-Log shows a lot of warnings while backing up VM1, afterwards VM1 is being backup up with no interesting log messages and after that the log is quiet like a log is if there is nothing happening while nobody is working and the VMs are just idling around.

Snip a part of the Log ---->

Code: Select all

2014-01-20T19:11:20.928Z cpu11:35142)CBT: 1540: Disconnecting the cbt device 2615f5f-cbt with filehandle 39935839
2014-01-20T19:11:20.934Z cpu11:35142)CBT: 2214: Created device 1d29f62-cbt for cbt driver with filehandle 30580578
2014-01-20T19:11:20.934Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 60
2014-01-20T19:11:20.934Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 59
2014-01-20T19:11:20.936Z cpu11:35142)CBT: 1540: Disconnecting the cbt device 1d29f62-cbt with filehandle 30580578
2014-01-20T19:11:20.967Z cpu11:35142)CBT: 1540: Disconnecting the cbt device 326df57-cbt with filehandle 52879191
2014-01-20T19:11:20.972Z cpu11:35142)CBT: 2214: Created device 3275f57-cbt for cbt driver with filehandle 52911959
2014-01-20T19:11:20.972Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 60
2014-01-20T19:11:20.972Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 59
2014-01-20T19:11:20.974Z cpu11:35142)CBT: 2214: Created device 1ee1f5b-cbt for cbt driver with filehandle 32382811
2014-01-20T19:11:20.974Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 60
2014-01-20T19:11:20.974Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 59
2014-01-20T19:11:20.975Z cpu11:35142)CBT: 1540: Disconnecting the cbt device 1ee1f5b-cbt with filehandle 32382811
2014-01-20T19:11:20.977Z cpu11:35142)CBT: 1540: Disconnecting the cbt device 3275f57-cbt with filehandle 52911959
2014-01-20T19:11:20.982Z cpu11:35142)CBT: 2214: Created device 1ee9f5b-cbt for cbt driver with filehandle 32415579
2014-01-20T19:11:20.982Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 60
2014-01-20T19:11:20.982Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 59
2014-01-20T19:11:21.052Z cpu11:35142)CBT: 1540: Disconnecting the cbt device 1ee9f5b-cbt with filehandle 32415579
2014-01-20T19:11:21.090Z cpu11:35142)CBT: 2214: Created device 3299f57-cbt for cbt driver with filehandle 53059415
2014-01-20T19:11:21.090Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 60
2014-01-20T19:11:21.090Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 59
2014-01-20T19:11:21.090Z cpu11:35142)WARNING: CBT: 2039: Unsupported ioctl 43

<-----
The Veeam-job-log ----->

Code: Select all

VMware Backup job: KOMPLETT
Created by SRV02\Administrator at 18.11.2013 14:20:09.
	Success
2 of 2 VMs processed
Montag, 20. Januar 2014 20:00:22
Success 	2 	Start time 	20:00:22 	Total size 	140,0 GB 	Backup size 	57,2 GB 	
Warning 	0 	End time 	20:26:50 	Data read 	43,9 GB 	Dedupe 	1,3x
Error 	0 	Duration 	0:26:27 	Transferred 	4,0 GB 	Compression 	1,9x
Details
Name 	Status 	Start time 	End time 	Size 	Read 	Transferred 	Duration 	Details
SRV01 	Success 	20:02:06 	20:12:08 	90,0 GB 	1,9 GB 	1,9 GB 	0:10:01 	
SRV02 	Success 	20:12:11 	20:26:26 	50,0 GB 	42,0 GB 	2,2 GB 	0:14:14 	

<-This was the job-Log.

First of all i also thought the use of USB could be the problem, but like you see:
SRV02 (VM2) is backup up both VM and has the USB-RDX connected through ESXi
SRV01 (VM1) is backup up first and is experiencing the "situation" from time to time
After completing the job, a post-script is initiated by veeam to copy the repo to RDX

Why should VM1 get a problem with a USB device connected to VM2?

About the time-Values:
Time on SRV02 is 11:02 right now
Time on ESX is 10:02 right not, so the esxi-log and the veeam-log should match in time. The last log message in VM1 is from about 20:03 on that day (VSS success in application-log and VSS started in system-log). So i would say the job ran successfully, but the VM did not "survive" the completion of that job.

[foggy]

Looks like the issue has gone by itself, probably due to its environmental nature. I recommend you to keep an eye on how it is going and contact VMware in case you see similar behavior in future. As to the warning messages in VMware log, seems that they won't cause any issues and can be ignored.