Bug 1240900 - [sysprep] Sysprep floppy payload attached to normal VM regardless of its settings enabling
Summary: [sysprep] Sysprep floppy payload attached to normal VM regardless of its sett...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 3.5.0
Hardware: Unspecified
OS: Unspecified
medium
high
Target Milestone: ovirt-3.5.7
: 3.5.7
Assignee: Shahar Havivi
QA Contact: Nisim Simsolo
URL:
Whiteboard: virt
Depends On: 1190663
Blocks: 1242426 1242428 1292086
TreeView+ depends on / blocked
 
Reported: 2015-07-08 05:41 UTC by rhev-integ
Modified: 2019-10-10 09:58 UTC (History)
17 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of: 1190663
: 1242426 1242428 1292086 (view as bug list)
Environment:
Last Closed: 2015-12-16 12:43:35 UTC
oVirt Team: Virt
Target Upstream Version:
mgoldboi: Triaged+


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2015:1938 0 normal SHIPPED_LIVE Red Hat Enterprise Virtualization Manager 3.5.5 update 2015-10-26 22:31:23 UTC
oVirt gerrit 40987 0 'None' 'MERGED' 'engine: Sysprep attached by default on new Windows VMs' 2019-11-26 08:38:28 UTC
oVirt gerrit 43100 0 'None' 'MERGED' 'restapi: add use_sysprep and use_cloud_init for Vm creation' 2019-11-26 08:38:28 UTC
oVirt gerrit 43384 0 'None' 'MERGED' 'engine: Sysprep attached by default on new Windows VMs' 2019-11-26 08:38:28 UTC
oVirt gerrit 43385 0 'None' 'MERGED' 'restapi: add use_sysprep and use_cloud_init for Vm creation' 2019-11-26 08:38:28 UTC
oVirt gerrit 48283 0 'None' 'MERGED' 'UI: sysprep attached by default in run once dialog.' 2019-11-26 08:38:28 UTC
oVirt gerrit 48321 0 'None' 'MERGED' 'UI: sysprep attached by default in run once dialog.' 2019-11-26 08:38:28 UTC
oVirt gerrit 48327 0 'None' 'ABANDONED' 'UI: sysprep attached by default in run once dialog.' 2019-11-26 08:38:29 UTC
oVirt gerrit 48403 0 'None' 'MERGED' 'UI: sysprep attached by default in run once dialog.' 2019-11-26 08:38:29 UTC

Comment 2 Nisim Simsolo 2015-10-14 09:43:32 UTC
Verified: 
rhevm-3.5.5-0.1.el6ev
sanlock-3.2.2-2.el7.x86_64
vdsm-4.16.27-1.el7ev.x86_64
qemu-kvm-rhev-2.1.2-23.el7_1.3.x86_64
libvirt-client-1.2.8-16.el7_1.4.x86_64

Scenario: 
1. Run new windows VM (first run) with sysprep checkbox unchecked.
2. Verify no sysprep payload attached.
3. Power off VM, check sysprep, add payload, run VM from run once with attached floppy = sysprep.
4. Verify payload attached.
5. Power off VM and uncheck sysprep again. run VM.
6. Verify no payload attached to VM.

Comment 4 errata-xmlrpc 2015-10-26 18:32:45 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-1938.html

Comment 5 Greg Scott 2015-10-29 15:41:34 UTC
Closing may be premature.  I'm not sure if we're dealing with this bug or BZ number 1190696, but a customer just updated to 3.5.5 and found it tried to mount the sysprep virtual floppy read/write on the second boot.  When the VM failed to start, it put the host into an error state for 30 minutes.  And with every host the VM tried to start on, RHEV put that host into an error state for 30 minutes.  Before long, every host in the cluster was prohibited from starting or migrating anything until that 30 minute clock passed.  This pretty much shut down a test lab.

When the VM firstbooted, it was started normally.  It was not started with "Run Once."

Annotated event entries below, with names munged.

2015-10-28 10:20:24,025 INFO
VM pooledVM-3 creation was initiated by user@corp.customer.com@CORP.

2015-10-28 10:20:38,331 INFO
VM pooledVM-3 creation has been completed.

## pooledVM-3: VM created

## pooledVM-3: Wayne started VM for first time, VM will sysprep
## pooledVM-3: RHEVM attaches floppy to VM in readonly mode

2015-10-28 10:26:09,395 INFO
device=floppy, type=disk, readonly=true, deviceId=1ed95c69-2966-417d-98f1-e24034fabd75

2015-10-28 10:26:09,484 INFO
VM pooledVM-3 was started by user@corp.customer.com@CORP (Host: hostA.customer.com).

2015-10-28 10:26:15,741 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from WaitForLaunch --> PoweringUp

2015-10-28 10:27:11,413 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from PoweringUp --> Up

2015-10-28 10:27:11,430 INFO
VM pooledVM-3 started on Host hostA.customer.com

## pooledVM-3: VM has sysprep floppy image assigned to it

## pooledVM-3: sysprep finished, rebooting VM first time

2015-10-28 10:31:23,374 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from Up --> RebootInProgress

2015-10-28 10:32:56,200 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from RebootInProgress --> Up

2015-10-28 12:18:45,788 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from Up --> PoweringDown

2015-10-28 12:18:49,014 INFO
VM pooledVM-3 is down. Exit message: User shut down from within the guest

## pooledVM-3: Wayne logged in to VM and manually shut it down via Windows GUI

2015-10-28 12:18:49,015 INFO
VM pooledVM-3 (812f02b2-6e25-4bd8-9294-ba4da6e12727) is running in db and not running in VDS hostA.customer.com

2015-10-28 12:18:49,059 WARN
Couldnt update VM pooledVM-3 (812f02b2-6e25-4bd8-9294-ba4da6e12727) version from its template, continue with restoring stateless snapshot.

2015-10-28 12:26:34,584 INFO
VM pooledVM-3 was started by user@corp.customer.com@CORP (Host: hostB.customer.com).

## pooledVM-3: VM was started by Wayne in normal 'run' mode (run once was not used)
## pooledVM-3: VM has sysprep floppy image assigned to it
## pooledVM-3: RHEVM attaches floppy to VM in readwrite mode
## pooledVM-3: RHEVM attaches the sysprep floppy again, even though the sysprep floppy is not needed at this stage

2015-10-28 12:26:34,494 INFO
deviceId=63d86473-f4b0-4d56-8328-4ba799a3fbb8, device=floppy, type=DISK, bootOrder=0, specParams={vmPayload={file={sysprep.inf=
device=floppy, type=disk, readonly=false, deviceId=63d86473-f4b0-4d56-8328-4ba799a3fbb8

## pooledVM-3: VM had error with sysprep floppy trying to be opened in readwrite mode (file is read only permissions for vdsm).
## pooledVM-3: VM should not be mounting sysprep floppy, this is post first-boot of VM

2015-10-28 12:26:42,803 ERROR
VM pooledVM-3 is down with error. Exit message: internal error process exited while connecting to monitor: 2015-10-28T16:26:38.393502Z qemu-kvm: -drive file=/var/run/vdsm/payload/812f02b2-6e25-4bd8-9294-ba4da6e12727.84fd76683961251bb9f8fd206e58bcb4.img,if=none,id=drive-fdc0-0-0,format=raw,serial=: could not open disk image /var/run/vdsm/payload/812f02b2-6e25-4bd8-9294-ba4da6e12727.84fd76683961251bb9f8fd206e58bcb4.img: Permission denied

## pooledVM-3: VM was shutdown/not started due to ERROR: the floppy .img file opened in readwrite (RW), file perms only allow readonly (RO)

2015-10-28 12:26:44,972 INFO
VM pooledVM-3 (812f02b2-6e25-4bd8-9294-ba4da6e12727) is running in db and not running in VDS hostB.customer.com

2015-10-28 12:26:45,114 WARN
Failed to run VM pooledVM-3 on Host hostB.customer.com.

## pooledVM-3: RHEVM automatically attempted to start VM on a different hypervisor due to error running error starting on hostB.customer.com

2015-10-28 12:26:45,666 INFO
VM pooledVM-3 was started by user@corp.customer.com@CORP (Host: hostA.customer.com).

## pooledVM-3: VM has a floppy sysprep file assigned to it

2015-10-28 12:26:45,572 INFO
deviceId=63d86473-f4b0-4d56-8328-4ba799a3fbb8, device=floppy, type=DISK, bootOrder=0, specParams={vmPayload={file={sysprep.inf=

2015-10-28 12:26:46,214 INFO
deviceId=63d86473-f4b0-4d56-8328-4ba799a3fbb8, device=floppy, type=DISK, bootOrder=0, specParams={vmPayload={file={sysprep.inf=

2015-10-28 12:26:49,383 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from WaitForLaunch --> PoweringUp

2015-10-28 12:26:49,443 INFO
deviceId=63d86473-f4b0-4d56-8328-4ba799a3fbb8, device=floppy, type=DISK, bootOrder=0, specParams={vmPayload={file={sysprep.inf=

2015-10-28 12:27:20,712 INFO
VM pooledVM-3 812f02b2-6e25-4bd8-9294-ba4da6e12727 moved from PoweringUp --> Up

2015-10-28 12:27:20,719 INFO
deviceId=63d86473-f4b0-4d56-8328-4ba799a3fbb8, device=floppy, type=DISK, bootOrder=0, specParams={vmPayload={file={sysprep.inf=

2015-10-28 12:27:20,759 INFO
VM pooledVM-3 started on Host hostA.customer.com



## pooledVM-3: VM post-sysprep startup completed

Comment 6 Greg Scott 2015-11-05 17:39:20 UTC
With 3.5.5, that VM is still trying to connect to its sysprep floppy on second boot.  See the comment above with details.  Wasn't that what this bug was supposed to fix?  There's another similar BZ, number 1274708.  Are these issues related?

thanks

- Greg Scott

Comment 7 Shahar Havivi 2015-11-08 07:09:46 UTC
(In reply to Greg Scott from comment #6)
If the vm failed to run it means that the VM was not initialized so the second boot is the first boot (since the vm is not marked as initialized in the DB)

Comment 8 Shahar Havivi 2015-11-09 08:30:44 UTC
Greg please tell me if  the following is the problem:

1. You are creating a VM via the user portal
2. adding disk
3. run the vm (not runonce)

The VM fail to run?
What kind of OS did you put in new VM dialog?
Did you configure anything else in new VM dialog beside the VM name?

Comment 9 Shahar Havivi 2015-11-09 11:32:04 UTC
Greg I found the problem and you right - 
We are attaching sysprep on run-once dialog by default.
I will send a patch soon but please confirm if this problem is only in run-once dialog.

Comment 10 Greg Scott 2015-11-09 14:17:11 UTC
Thanks Shahar.  Also see comment 9 from BZ number 1274708.  And support case number 01518293.  I'll paste the relevant comment in below.  The report from the customer is, after the hotfix applied to 3.5.5 from that other BZ, the 2nd boot after normal run works as expected.  But the second boot after run-once still behaves badly as you found above.

Details in the comment from that other BZ:

****

The problem is only partially fixed.  Apparently, when the VM is first started with "run once", it still tries (incorrectly) to attach the floppy on the next power up after the sysprep mini-setup run finishes.  When the VM is first started with the normal "run", things now behave as expected on second powerup.

The problem also has unpleasant consequences.  When 3 VMs fail to start on a host, RHEV-M declares that host to be in an error state for the next 30 minutes. So in a scenario with lots of pooled VMs, all doing a second powerup and failing because of the floppy error, before too long, every host in the cluster will fail to start a VM 3 times, which pushes every RHEV-H host in the cluster into an error state for 30 minutes.  With all the hosts in this error state, no VMs can start or migrate and the cluster is pretty much out of commission.  

Here is some customer feedback on the hotfix for 3.5.5 based on this patch from support case number 01518293.

After hotfix was applied:
Systems no longer cause boot error for readwrite sysprep floppy on the first powerup after the initial sysprep and then VM shutdown. The sysprep floppy is not presented at all the to VM on the first powerup post sysprep then shutdown (this is the VMs 2nd powerup), which is the correct and expected behavior.
This ONLY affects systems if started with the "Run" option.

Systems started with "Run Once" option still have the problem where, on the next powerup of the VM post the sysprep then shutdown (the VMs 2nd powerup), the VMs are told to again attach to the sysprep floppy (error), and also in the process told to attach this floppy in readwrite state (file presented is with readonly permmissions).

*****

- Greg

Comment 11 Shahar Havivi 2015-11-09 14:35:10 UTC
(In reply to Greg Scott from comment #10)
Thanks Greg,
The patch will fix the automatic attaching sysprep in the first run only when when the user didn't define sysprep on add vm dialog (which is your case).

As for the second boot I can only assume that the system treat it as first boot since it fail to run.

You are more then welcome to test it on my environment if you want to test some scenario, just mail me and I will set it up.

Comment 12 Michal Skrivanek 2015-12-16 12:43:35 UTC
closing again (status as of comment #4)


Note You need to log in before you can comment on or make changes to this bug.