search

hashicorp / packer

Packer is a tool for creating identical machine images for multiple platforms from a single source configuration.
http://www.packer.io
Other
15.09k stars 3.33k forks source link

virtualbox-iso and virtualbox-vm leaving floppy device and temporary floppy image mounted #9269

Open Roxyrob opened 4 years ago

Roxyrob commented 4 years ago

Overview of the Issue

virtualbox-iso and virtualbox-vm do not remove floppy drive and/or temporary floppy image on the keep_registered

This mostly is an issue using these vm/snapshot as starting point (e.g. attach_snapshot) for subsequent templates.

Below an example of VirtualBox Storage definition for a vm after packer keep_registered in virtualbox-iso or virtualbox-vm

Storage Controller: IDE Controller IDE Primary Master: packer-....vdi (Normal, 30.00 GB) Controller: Floppy Controller Floppy Device 0: floppy.vfd (Inaccessible)

Reproduction Steps

  1. Run template like Below "Simplified Packer Builfile"
  2. Open VirtualBox to see vm or snapshot Storage configuration (in properties).

Packer version

Packer v1.5.6

Simplified Packer Buildfile

### virtualbox-iso

{
  "variables":{
    "env_type": "",
    ...
  },
  "sensitive-variables": ["..."],
  "builders":[
    {
      "type": "virtualbox-iso",
      ...
      "keep_registered": "true",
      "shutdown_timeout": "40m",
      "shutdown_command": "...",
      "post_shutdown_delay": "3m",
      "floppy_files": [
        "./scripts/..."
      ],
      "skip_export": "true"
    }
  ]
}

### virtualbox-vm

{
  "variables":{
    "env_type": "",
    ...
  },
  "sensitive-variables": ["..."],
  "builders":[
    {
      "type": "virtualbox-vm",
      "attach_snapshot": "base",
      "target_snapshot": "snapshot-stage-prov",
      "keep_registered": "true",
      "shutdown_timeout": "40m",
      "shutdown_command": "...",
      "post_shutdown_delay": "2m",

      "floppy_files": [
        "./scripts/..."
        ...
      ],
      "skip_export": "true"
    }
  ],
  "provisioners": [
    {
      "type": "windows-shell",
      "scripts": [ "scripts/...",
                   "scripts/..."
      ]
    }
  ]
}

Operating system and Environment details

Linux CentOS7 kernel 3.10.0-1062.12.1.el7 arch x86_64

Log Fragments and crash.log files

No issue visible in the log since the build works well (apart from VirtualBox vm/snapshot Storage having Floppy Drive and attached inaccessible image).

SwampDragons commented 4 years ago

Hi again! This is odd -- we do have code to clean up the floppies, and if you set the env var PACKER_LOG=1 I would expect you to see the logline "Error unregistering floppy:" followed by the error message being bubbled up from Virtualbox.

Roxyrob commented 4 years ago

Hi @SwampDragons, you're right for virtualbox-iso, I'm wrong as in a new build keep_registered indeed removed iso and floppy:

show virtualbox-iso logs ``` 2020/05/22 19:30:39 ui: ==> vbox_vmx_builder: Gracefully halting virtual machine... 2020/05/22 19:30:39 packerio plugin: Executing shutdown command: shutdown /s /t 0 /f /d p:0:0 /c "Packer Shutdown" 2020/05/22 19:30:39 packerio plugin: [INFO] starting remote command: shutdown /s /t 0 /f /d p:0:0 /c "Packer Shutdown" 2020/05/22 19:30:40 packerio plugin: [INFO] command 'shutdown /s /t 0 /f /d p:0:0 /c "Packer Shutdown"' exited with code: 0 2020/05/22 19:30:40 packerio plugin: Waiting max 40m0s for shutdown to complete 2020/05/22 19:30:51 packerio plugin: Delay for 3m0s after shutdown to allow locks to clear... 2020/05/22 19:33:51 packerio plugin: VM shut down. 2020/05/22 19:33:51 ui: vbox_vmx_builder: Removing floppy drive... 2020/05/22 19:33:51 packerio plugin: Executing VBoxManage: []string{"storageattach", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "--storagectl", "Floppy Controller", "--port", "0", "--device", "0", "--medium", "none"} 2020/05/22 19:33:51 packerio plugin: stdout: 2020/05/22 19:33:51 packerio plugin: stderr: 2020/05/22 19:33:51 packerio plugin: Trying for 10 minutes to remove floppy controller. 2020/05/22 19:33:51 packerio plugin: Executing VBoxManage: []string{"storagectl", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "--name", "Floppy Controller", "--remove"} 2020/05/22 19:33:51 packerio plugin: stdout: 2020/05/22 19:33:51 packerio plugin: stderr: 2020/05/22 19:33:51 packerio plugin: Executing VBoxManage: []string{"storageattach", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "--storagectl", "IDE Controller", "--port", "0", "--device", "1", "--medium", "none"} 2020/05/22 19:33:51 packerio plugin: stdout: 2020/05/22 19:33:51 packerio plugin: stderr: 2020/05/22 19:33:51 ui: ==> vbox_vmx_builder: Skipping export of virtual machine... 2020/05/22 19:33:51 packerio plugin: failed to unlock port lockfile: close tcp 127.0.0.1:3333: use of closed network connection 2020/05/22 19:33:51 packerio plugin: Executing VBoxManage: []string{"storageattach", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "--storagectl", "Floppy Controller", "--port", "0", "--device", "0", "--medium", "none"} 2020/05/22 19:33:51 packerio plugin: stdout: 2020/05/22 19:33:51 packerio plugin: stderr: VBoxManage: error: Could not find a controller named 'Floppy Controller' 2020/05/22 19:33:51 packerio plugin: Error unregistering floppy: VBoxManage error: VBoxManage: error: Could not find a controller named 'Floppy Controller' 2020/05/22 19:33:51 packerio plugin: failed to unlock port lockfile: close tcp 127.0.0.1:5938: use of closed network connection 2020/05/22 19:33:51 packerio plugin: Executing VBoxManage: []string{"storageattach", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "--storagectl", "IDE Controller", "--port", "0", "--device", "1", "--medium", "none"} 2020/05/22 19:33:51 packerio plugin: stdout: 2020/05/22 19:33:51 packerio plugin: stderr: VBoxManage: error: No storage device attached to device slot 1 on port 0 of controller 'IDE Controller' 2020/05/22 19:33:51 packerio plugin: VBoxManage: error: Details: code VBOX_E_OBJECT_NOT_FOUND (0x80bb0001), component SessionMachine, interface IMachine, callee nsISupports 2020/05/22 19:33:51 packerio plugin: VBoxManage: error: Context: "DetachDevice(Bstr(pszCtl).raw(), port, device)" at line 403 of file VBoxManageStorageController.cpp 2020/05/22 19:33:51 ui: ==> vbox_vmx_builder: Keeping virtual machine registered with VirtualBox host (keep_registered = true) 2020/05/22 19:33:51 packerio plugin: Deleting floppy disk: /tmp/packer171892612 2020/05/22 19:33:51 [INFO] (telemetry) ending virtualbox-iso 2020/05/22 19:33:51 ui: Build 'vbox_vmx_builder' finished. 2020/05/22 19:33:51 ui: ==> Builds finished. The artifacts of successful builds are: 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact-count []string{"1"} 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact []string{"0", "builder-id", "mitchellh.virtualbox"} 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact []string{"0", "id", "VM"} 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact []string{"0", "string", "VM files in directory: ../../builds/windows2019min_vbox_vmx_builder"} 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact []string{"0", "files-count", "1"} 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact []string{"0", "file", "0", "../../builds/windows2019min_vbox_vmx_builder/packer-windows2019min-x86_64-vbox_vmx_builder-devel.vdi"} 2020/05/22 19:33:51 machine readable: vbox_vmx_builder,artifact []string{"0", "end"} 2020/05/22 19:33:51 ui: --> vbox_vmx_builder: VM files in directory: ../../builds/windows2019min_vbox_vmx_builder 2020/05/22 19:33:51 [INFO] (telemetry) Finalizing. 2020/05/22 19:33:51 waiting for all plugin processes to complete... 2020/05/22 19:33:51 /usr/local/bin/packerio: plugin process exited ```

but virtualbox-vm, starting from "attach_snapshot": "base", seems to remove floppy in the log, but floppy is here in "target_snapshot", used as base for the next build steps. Also vm in current state was with floppy ejected but has floppy controller:

show virtualbox-vm logs ``` 2020/05/22 19:46:55 packerio plugin: Waiting max 40m0s for shutdown to complete 2020/05/22 19:46:55 packerio plugin: Delay for 2m0s after shutdown to allow locks to clear... 2020/05/22 19:48:55 packerio plugin: VM shut down. 2020/05/22 19:48:56 ui: ==> vbox_vmx_vagrant_prov: Creating snapshot snapshot-stage-prov-vagrant on virtual machine packer-windows2019min-x86_64-vbox_vmx_builder-devel 2020/05/22 19:48:56 packerio plugin: Executing LoadSnapshots: VM: packer-windows2019min-x86_64-vbox_vmx_builder-devel 2020/05/22 19:48:56 packerio plugin: Executing VBoxManage: []string{"snapshot", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "list", "--machinereadable"} 2020/05/22 19:48:56 packerio plugin: stdout: SnapshotName="base" 2020/05/22 19:48:56 packerio plugin: SnapshotUUID="12baf91a-50f4-4b41-b9c9-279f942339d3" 2020/05/22 19:48:56 packerio plugin: CurrentSnapshotName="base" 2020/05/22 19:48:56 packerio plugin: CurrentSnapshotUUID="12baf91a-50f4-4b41-b9c9-279f942339d3" 2020/05/22 19:48:56 packerio plugin: CurrentSnapshotNode="SnapshotName" 2020/05/22 19:48:56 packerio plugin: stderr: 2020/05/22 19:48:56 packerio plugin: Executing CreateSnapshot: VM: packer-windows2019min-x86_64-vbox_vmx_builder-devel, SnapshotName snapshot-stage-prov-vagrant 2020/05/22 19:48:56 packerio plugin: Executing VBoxManage: []string{"snapshot", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "take", "snapshot-stage-prov-vagrant"} 2020/05/22 19:48:56 packerio plugin: stdout: Snapshot taken. UUID: 91e7b244-b1e3-4c62-bf98-d13cfce162ea 2020/05/22 19:48:56 packerio plugin: stderr: 0%...10%...20%...30%...40%...50%...60%...70%...80%...90%...100% 2020/05/22 19:48:56 ui: ==> vbox_vmx_vagrant_prov: Skipping export of virtual machine... 2020/05/22 19:48:56 packerio plugin: failed to unlock port lockfile: close tcp 127.0.0.1:3228: use of closed network connection 2020/05/22 19:48:56 packerio plugin: Executing VBoxManage: []string{"storageattach", "packer-windows2019min-x86_64-vbox_vmx_builder-devel", "--storagectl", "Floppy Controller", "--port", "0", "--device", "0", "--medium", "none"} 2020/05/22 19:48:56 packerio plugin: stdout: 2020/05/22 19:48:56 packerio plugin: stderr: 2020/05/22 19:48:56 packerio plugin: failed to unlock port lockfile: close tcp 127.0.0.1:5902: use of closed network connection 2020/05/22 19:48:56 ui: ==> vbox_vmx_vagrant_prov: Keeping virtual machine state (keep_registered = true) 2020/05/22 19:48:56 packerio plugin: Deleting floppy disk: /tmp/packer885901581 2020/05/22 19:48:56 [INFO] (telemetry) ending virtualbox-vm 2020/05/22 19:48:56 ui: Build 'vbox_vmx_vagrant_prov' finished. 2020/05/22 19:48:56 ui: ==> Builds finished but no artifacts were created. 2020/05/22 19:48:56 [INFO] (telemetry) Finalizing. 2020/05/22 19:48:56 waiting for all plugin processes to complete... 2020/05/22 19:48:56 /usr/local/bin/packerio: plugin process exited 2020/05/22 19:48:56 /usr/local/bin/packerio: plugin process exited ```