SOLVED VMs Not Starting in WebGUI

[m1ked123]

Hi everyone,

First post, so bear with me. I've been having an issue starting virtual machines that I had created in the FreeNAS 11.0-RELEASE WebGUI. They are VMs with Ubuntu Server installed (16.04) and they've been running for months already. I've restarted them before for basic maintenance tasks (installing security updates). This said, it had been a while since I've updated FreeNAS, so I decided to update to U2 last night.

When the system rebooted, the VMs had not started (autostart turned on) and refuse to start. When I say start: I press the "Start" button on a VM, a green dialog displays saying that it was started, but the system's status still shows as "STOPPED". I attempted to boot the system into FreeNAS 11.0-RELEASE, but even that didn't change anything.

Did I just royally screw up? New VMs created in U2 start and stop fine, but the ones I created in RELEASE will not start. Nothing on these VMs is vital; I can always recreate them, but I'd prefer not to (been there, done that several times with Corral). If this is my only option, is there an easy way to migrate the existing ZVOLs from the old VMs to the new ones and assign them the same IP Addresses that were previously used?

Thanks for any help you can provide!

 

[dlavigne]

Were you able to resolve this? If not, anything in /var/log/messages when you attempt to start the VM?

 

[m1ked123]

Were you able to resolve this? If not, anything in /var/log/messages when you attempt to start the VM?

Thanks for your response!

I hadn't thought to look there. The results are interesting, but I can't think of what the entries could mean. My next task will be to improve the verbosity of log entries and see if that doesn't get me more information.

Entries when starting an existing VM (which does not start) are of the form:
Sep 7 22:44:59 freenas tap1: ethernet address: blah
Sep 7 22:44:59 freenas kernel: tap1: promiscuous mode enabled
Sep 7 22:44:59 freenas kernel: tap1: link state changed to UP
Sep 7 22:44:59 freenas kernel: tap1: link state changed to UP
Sep 7 22:44:59 freenas kernel: tap1: link state changed to DOWN
Sep 7 22:44:59 freenas kernel: tap1: link state changed to DOWN

Entries after starting a newly created VM (which actually starts) are of the form:
Sep 7 22:47:12 freenas tap1: ethernet address: blah
Sep 7 22:47:12 freenas kernel: tap1: promiscuous mode enabled
Sep 7 22:47:12 freenas kernel: tap1: link state changed to UP
Sep 7 22:47:12 freenas kernel: tap1: link state changed to UP

 

[Stux]

Have you got the VM waiting for a VNC connection ?

 

[m1ked123]

Have you got the VM waiting for a VNC connection ?

I've tried turning off that option, but it had no noticeable affect. Even if I attempt to connect to the machine using VNC, it doesn't end up turning on (maybe I'm not properly understanding the function). I was thinking that maybe I'd delete the VNC device altogether since all of my management is through SSH, but I'm not sure what the potential consequences would be if I did that.

 

[Stux]

I've tried turning off that option, but it had no noticeable affect. Even if I attempt to connect to the machine using VNC, it doesn't end up turning on (maybe I'm not properly understanding the function). I was thinking that maybe I'd delete the VNC device altogether since all of my management is through SSH, but I'm not sure what the potential consequences would be if I did that.

I think that'd remove the vga console from the VM.

 

[birt]

I had a similar problem. A VM would just fail to start after it was working properly for a while.

Inspecting /var/log/middlewared.log I saw:

Code:

[2017/09/12 11:18:23] (WARNING) ServiceBase.destroy_vm():149 - ===> DESTROYING VM: Backup ID: 3 BHYVE_CODE: 1
[2017/09/12 11:29:29] (DEBUG) ServiceBase.run():125 - Starting bhyve: bhyve -A -P -H -c 4 -m 4096 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm3A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 3,virtio-net,tap1 -s 29,fbuf,tcp=0.0.0.0:5903,w=1024,h=768,wait -s 30,xhci,tablet -s 4,ahci-cd,/mnt/d1.5tb1/share/test.iso -s 5,ahci-cd,/mnt/d1.5tb1/share/virtio-win-0.1.141.iso -s 6,ahci-hd,/dev/zvol/backup_vm/backup_vm Backup
[2017/09/12 11:29:29] (DEBUG) ServiceBase.run():128 - Backup: bhyve: Could not open backing file: /mnt/d1.5tb1/share/virtio-win-0.1.141.iso: No such file or directory
[2017/09/12 11:29:29] (INFO) ServiceBase.run():142 - ===> STOPPING VM: Backup ID: 3 BHYVE_CODE: 1

Turns out it wasn't starting because I had deleted one of the ISO files that were mounted as CDROMs.

I would recommend inspecting your /var/log/middlewared.log, perhaps you can get more information about the problem there. Inspecting /var/log/messages I could see the same messages you mentioned and in /var/log/debug.log I had some info that was not a lot of help.

 

[m1ked123]

I had a similar problem. A VM would just fail to start after it was working properly for a while.

Inspecting /var/log/middlewared.log I saw:

Code:

[2017/09/12 11:18:23] (WARNING) ServiceBase.destroy_vm():149 - ===> DESTROYING VM: Backup ID: 3 BHYVE_CODE: 1
[2017/09/12 11:29:29] (DEBUG) ServiceBase.run():125 - Starting bhyve: bhyve -A -P -H -c 4 -m 4096 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm3A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 3,virtio-net,tap1 -s 29,fbuf,tcp=0.0.0.0:5903,w=1024,h=768,wait -s 30,xhci,tablet -s 4,ahci-cd,/mnt/d1.5tb1/share/test.iso -s 5,ahci-cd,/mnt/d1.5tb1/share/virtio-win-0.1.141.iso -s 6,ahci-hd,/dev/zvol/backup_vm/backup_vm Backup
[2017/09/12 11:29:29] (DEBUG) ServiceBase.run():128 - Backup: bhyve: Could not open backing file: /mnt/d1.5tb1/share/virtio-win-0.1.141.iso: No such file or directory
[2017/09/12 11:29:29] (INFO) ServiceBase.run():142 - ===> STOPPING VM: Backup ID: 3 BHYVE_CODE: 1

Turns out it wasn't starting because I had deleted one of the ISO files that were mounted as CDROMs.

I would recommend inspecting your /var/log/middlewared.log, perhaps you can get more information about the problem there. Inspecting /var/log/messages I could see the same messages you mentioned and in /var/log/debug.log I had some info that was not a lot of help.

Thank you. I don't know how to set this as the "Answer" or something, but this fixed the problem. I'll keep middlewared.log in mind as a place to check next time when/if things go south.

 

[birt]

Good to hear you were able to sort it out. I don't think you can mark something as an answer but you can mark the thread as solved somehow.

As a more generic recommendation, I run a:

Code:

ls -alt /var/log/ | head

right after a booboo happens in order to find the log files that had output recently (it sorts by the last modification time descending).