issues with bhyve VMs on 11.2-U2

proto

Patron
Joined
Sep 28, 2015
Messages
269
I tried to import some VMs on a new FreeNAS 11.2-U2 system. The virtual machines were created on the same system previously updated by 11.1-U7, but with horrible results.

What have I done...

1. Installed from scratch on new FreeNAS 11.2-U2 disk
2. imported the VM pool
3. created a new VM by connecting the disk (zvol) previously created
4. started the VM

The WEB UI gives me back the "com port" /dev/nmdm0B (it's the first vm).
The problem is that there is no "nmdm" device on the system! And trying to connect from the WEB UI (VM -> Serial) which in turn tries to connect on a non-existent device: /dev/nmdm1B.
Screenshot 2019-02-25 08.48.06.png


The middlewared.log says:
Code:
[2019/02/25 11:30:27] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm1A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap0,mac=00:a0:98:3b:5e:ab -s 29,fbuf,vncserver,tcp=10.10.10.10:6287,w=1024,h=768,,wait -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/ns0 1_ns0
[2019/02/25 11:30:27] (DEBUG) VMService.run():278 - ==> Start WEBVNC at port 6187 with pid number 12271
[2019/02/25 11:30:27] (DEBUG) VMService.run():287 - ns0: 25/02/2019 11:30:27 Listening for VNC connections on TCP port 6287
[2019/02/25 11:30:27] (DEBUG) VMService.run():287 - ns0: 25/02/2019 11:30:27 Listening for VNC connections on TCP6 port 6287


The strange thing is that 5 (five!) Minutes after the serial device is created.

In any case, the VM remains hanging and irresponsive, is STARTED on the WEB UI but:

Code:
[root @ beast ~] # ps auxww | grep bhyve
root 12270 2.6 0.1 1096396 25948 - I 11:30 0: 28.88 bhyve -A -
H -w -c 1 -m 1024 -s 0: 0, hostbridge -s 31, lpc -l com1, / dev / nmdm1A -l bootrom, / us
r / local / share / uefi-firmware / BHYVE_UEFI.fd -s 4, virtio-net, tap0, mac = 00: a0: 98: 3b: 5
e: ab -s 29, fbuf, vncserver, tcp = 10.10.10.10: 6287, w = 1024, h = 768,, wait -s 30, xhci, tab
let -s 3: 0, ahci, hd: / dev / zvol / VMStore / ns0 1_ns0


I tried to restart the VM with these results:
Code:
[2019/02/25 11:42:15] (WARNING) aiohttp.websocket._send_frame():533 - websocket connection is closing.
[2019/02/25 11:42:58] (DEBUG) VMService.stop():422 - ===> Force Stop VM: ns0 ID: 1 BHYVE_CODE: None
[2019/02/25 11:42:58] (INFO) VMService.run():312 - ===> Error VM: ns0 ID: 1 BHYVE_CODE: -15
[2019/02/25 11:42:58] (ERROR) VMService.running():438 - ===> VMM ns0 is running without bhyve process.
[2019/02/25 11:42:58] (ERROR) VMService.running():438 - ===> VMM ns0 is running without bhyve process.
[2019/02/25 11:42:58] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/25 11:42:58] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: ns0 ID: 1 BHYVE_CODE: -15
[2019/02/25 11:42:58] (DEBUG) VMService.kill_bhyve_web():406 - ==> Killing WEBVNC: 12271
[2019/02/25 11:42:58] (ERROR) asyncio.default_exception_handler():1266 - Task exception was never retrieved
future: <Task finished coro=<VMSupervisor.run() done, defined at /usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py:107> exception=CallError('VM ns0 failed to start: 25/02/2019 11:30:27 Listening for VNC connections on TCP port 6287\n25/02/2019 11:30:27 Listening for VNC connections on TCP6 port 6287',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py", line 316, in run
    raise CallError(f'VM {self.vm["name"]} failed to start: {output}')
middlewared.service_exception.CallError: [EFAULT] VM ns0 failed to start: 25/02/2019 11:30:27 Listening for VNC connections on TCP port 6287
25/02/2019 11:30:27 Listening for VNC connections on TCP6 port 6287


I just managed to get the VM starting from LEGACY:

Code:
root @ beast [~] # ps auxww | grep bhyve
root 15697 2.3 0.3 1110860 108332 - SC 11:57 0: 15.98 bhyve: 2_ns0 (bhyve)


Code:
root @ beast [~] # ls -l / dev / nmdm2 *
crw ------- 1 root wheel 0xef Feb 25 11:58 /dev/nmdm2A
crw ------- 1 root wheel 0xf0 Feb 25 11:57 /dev/nmdm2B


OK!

Finally I can connect via shell / WEB UI
:
Code:
root @ beast [~] # cu -s 9600 -l / dev / nmdm2B
Connected


FreeBSD / amd64 (ns0) (ttyu0)

login:
 

KrisBee

Wizard
Joined
Mar 20, 2017
Messages
1,288
It wasn't until I got to the end of your post that I realised your VM was running FreeBSD. What you didn't show was the middlewared.log output when the VM did start using the legacy UI. In my experience whether you can connect to a console or not when bhyve is using UEFI firmware seems to depend on what slots are in use for the various devices. Was there a differences in slots used when starting the VM via the new and then the old UI?

The first output of ps auxww you listed is a sure sign of a VM not starting properly. I've never seen the full bhyve command listed for a clean VM start, only for failed starts. I've resorted to using bhyvectl at the CLI to destroy hanging VMs in the past, but with the new memory management in FN11 I don't know if that returns VM memory to the ARC now.

If your expectation was that a new VM re-using an existing install on a zvol should just start normally, then whether this a bug or a feature request depends on what is supposed to happen in FreeNAS. As an end user knowing what is supposed to happen is a often a guessing game.

This looks like a bug to me if something works via the legacy UI but not via the new UI.
 

proto

Patron
Joined
Sep 28, 2015
Messages
269
Thanks for your reply KrisBee.

Was there a differences in slots used when starting the VM via the new and then the old UI?
Yes! Here is the difference in serial consoles slots between the two UIs. VMs "useless" and "bananae" were created under the current system, but the COM PORTS in the NEW UI seem serially generated without pointing to the device... I don't know how to explain better, sorry!

Screenshot 2019-02-26 15.02.28.png


Screenshot 2019-02-26 15.03.11.png


It's a buggy NEW UI. Amen!

And what about this one... why should I choose a new NIC between tapX devices??

Screenshot 2019-02-26 14.58.00.png


I'm attaching a full report using another "old" VM (with full middlewared.log that I missed ;-P )

I did 3 test using NEW UI, LEGACY UI and mixing the two.

# TEST1 - NEW UI
0. from NEW UI
1. create a VM importing the old zvol (created under 11.1-U7)
Code:
VM Settings for VM "testdb00":
VM Summary
Guest Operating System : FreeBSD
Number of CPUs : 1
Memory : 1024 MiB
Name : testdb00
Hard Disk : VMStore/db00
Installation Media : /mnt/Edge0/Software/OS_iso/FreeBSD-12.0-RELEASE-amd64-bootonly.iso


On VM listings:
VM is STOPPED and "Com Port" is /dev/nmdm2B.

2. From Devices I removed CDROM.

3. START VM

middlewared.log:
Code:
[2019/02/26 13:05:29] (INFO) VMService.__set_guest_vmemory():901 - ===> Setting ARC FROM: 31258464256 TO: 30184722432
[2019/02/26 13:05:29] (DEBUG) VMService.run():179 - ====> NIC_ATTACH: vlan10
[2019/02/26 13:05:29] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm5A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap1,mac=00:a0:98:31:cf:32 -s 29,fbuf,vncserver,tcp=10.10.10.10:6315,w=1024,h=768,,wait -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 5_testdb00
[2019/02/26 13:05:29] (DEBUG) VMService.run():278 - ==> Start WEBVNC at port 6215 with pid number 30362
[2019/02/26 13:05:29] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:05:29 Listening for VNC connections on TCP port 6315
[2019/02/26 13:05:29] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:05:29 Listening for VNC connections on TCP6 port 6315


VM Status from NEW UI: RUNNING

Code:
root@bestia[~]# ps auxww | grep bhyve
root       15697   4.5  1.2 1110860 405100  -  SC   Mon11      73:29.54 bhyve: 2_ns0 (bhyve)
root       30359   4.1  0.1 1096396  25996  -  I    13:05       0:08.35 bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm5A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap1,mac=00:a0:98:31:cf:32 -s 29,fbuf,vncserver,tcp=10.10.10.10:6315,w=1024,h=768,,wait -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 5_testdb00


Serial Console should be /dev/nmdm5B, but

Code:
root@bestia[~]# ls -l /dev/nmdm*
crw-------  1 root  wheel  0xef Feb 26 13:08 /dev/nmdm2A
crw-------  1 root  wheel  0xf0 Feb 26 13:08 /dev/nmdm2B


WARNING! /dev/nmdm2B is assigned to "2_ns0" (see first line of ps output)

4. POWEROFF VM "testdb00"
Since it's broken STOP this VM.

middlewared.log
Code:
[2019/02/26 13:12:55] (DEBUG) VMService.stop():426 - ===> Soft Stop VM: testdb00 ID: 5
[2019/02/26 13:12:55] (INFO) VMService.run():312 - ===> Error VM: testdb00 ID: 5 BHYVE_CODE: -15
[2019/02/26 13:12:55] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/26 13:12:55] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/26 13:12:55] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 5 BHYVE_CODE: -15
[2019/02/26 13:12:55] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/26 13:12:55] (DEBUG) VMService.kill_bhyve_web():406 - ==> Killing WEBVNC: 30362
[2019/02/26 13:12:55] (ERROR) asyncio.default_exception_handler():1266 - Task exception was never retrieved
future: <Task finished coro=<VMSupervisor.run() done, defined at /usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py:107> exception=CallError('VM testdb00 failed to start: 26/02/2019 13:05:29 Listening for VNC connections on TCP port 6315\n26/02/2019 13:05:29 Listening for VNC connections on TCP6 port 6315',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py", line 316, in run
    raise CallError(f'VM {self.vm["name"]} failed to start: {output}')
middlewared.service_exception.CallError: [EFAULT] VM testdb00 failed to start: 26/02/2019 13:05:29 Listening for VNC connections on TCP port 6315
26/02/2019 13:05:29 Listening for VNC connections on TCP6 port 6315


# END


# TEST 2 - LEGACY UI
0. Login to LEGACY UI
1. Check VM listings
VM "testdb00" is listed and STOPPED

2. START VM

VM is STARTED and "Com Port" is /dev/nmdb5B

middlewared.log
Code:
[2019/02/26 13:19:15] (INFO) VMService.__set_guest_vmemory():901 - ===> Setting ARC FROM: 31258464256 TO: 30184722432
[2019/02/26 13:19:15] (DEBUG) VMService.run():179 - ====> NIC_ATTACH: vlan10
[2019/02/26 13:19:15] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm5A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap1,mac=00:a0:98:31:cf:32 -s 29,fbuf,vncserver,tcp=10.10.10.10:6315,w=1024,h=768,,wait -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 5_testdb00
[2019/02/26 13:19:15] (DEBUG) VMService.run():278 - ==> Start WEBVNC at port 6215 with pid number 31937
[2019/02/26 13:19:15] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:19:15 Listening for VNC connections on TCP port 6315
[2019/02/26 13:19:15] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:19:15 Listening for VNC connections on TCP6 port 6315


SAME issue here. Still no serial console / VM is stil broken as in NEW UI.

Code:
root@bestia[~]# ps auxww | grep bhyve
root       15697   4.7  1.2 1110860 409232  -  SC   Mon11      74:07.75 bhyve: 2_ns0 (bhyve)
root       31934   4.6  0.1 1096396  25996  -  I    13:19       0:06.91 bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm5A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap1,mac=00:a0:98:31:cf:32 -s 29,fbuf,vncserver,tcp=10.10.10.10:6315,w=1024,h=768,,wait -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 5_testdb00


Code:
root@bestia[~]# ls -l /dev/nmdm*
crw-------  1 root  wheel  0xef Feb 26 13:08 /dev/nmdm2A
crw-------  1 root  wheel  0xf0 Feb 26 13:08 /dev/nmdm2B


3. STOP VM
middlewared.log
Code:
[2019/02/26 13:23:06] (DEBUG) VMService.stop():426 - ===> Soft Stop VM: testdb00 ID: 5
[2019/02/26 13:23:06] (INFO) VMService.run():312 - ===> Error VM: testdb00 ID: 5 BHYVE_CODE: -15
[2019/02/26 13:23:06] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/26 13:23:06] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/26 13:23:06] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 5 BHYVE_CODE: -15
[2019/02/26 13:23:06] (DEBUG) VMService.kill_bhyve_web():406 - ==> Killing WEBVNC: 31937
[2019/02/26 13:23:06] (ERROR) asyncio.default_exception_handler():1266 - Task exception was never retrieved
future: <Task finished coro=<VMSupervisor.run() done, defined at /usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py:107> exception=CallError('VM testdb00 failed to start: 26/02/2019 13:19:15 Listening for VNC connections on TCP port 6315\n26/02/2019 13:19:15 Listening for VNC connections on TCP6 port 6315',)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py", line 316, in run
    raise CallError(f'VM {self.vm["name"]} failed to start: {output}')
middlewared.service_exception.CallError: [EFAULT] VM testdb00 failed to start: 26/02/2019 13:19:15 Listening for VNC connections on TCP port 6315
26/02/2019 13:19:15 Listening for VNC connections on TCP6 port 6315


4. DELETE VM from LEGACY UI
Cannot use this VM, so I have to destroy/delete it.

# END


# TEST 3 - "IMPORT/CREATE" VM on LEGACY and USE on BOTH UIs

0. Freom LEGACY UI
1. create a VM importing the old zvol (created under 11.1-U7)
VM Settings are the same as TEST1

2. START VM

STATUS is STARTED and "com port" is /dev/nmdm6B. CORRECT!

middlewared.log
Code:
[2019/02/26 13:30:43] (INFO) VMService.__set_guest_vmemory():901 - ===> Setting ARC FROM: 31258464256 TO: 30184722432
[2019/02/26 13:30:43] (DEBUG) VMService.run():179 - ====> NIC_ATTACH: vlan10
[2019/02/26 13:30:43] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm6A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap1,mac=00:a0:98:66:31:fc -s 29,fbuf,vncserver,tcp=0.0.0.0:5906,w=1024,h=768,, -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 6_testdb00
[2019/02/26 13:30:43] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:30:43 Listening for VNC connections on TCP port 5906
[2019/02/26 13:30:43] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:30:43 Listening for VNC connections on TCP6 port 5906
[2019/02/26 13:30:58] (DEBUG) VMService.run():287 - testdb00: Unhandled ps2 mouse command 0xe1


Serial console is UP:
Code:
root@bestia[~]# ls -l /dev/nmdm*
crw-------  1 root  wheel  0xef Feb 26 13:08 /dev/nmdm2A
crw-------  1 root  wheel  0xf0 Feb 26 13:08 /dev/nmdm2B
crw-------  1 root  wheel  0xf9 Feb 26 13:31 /dev/nmdm6A
crw-------  1 root  wheel  0xfa Feb 26 13:30 /dev/nmdm6B


VM is UP:
Code:
root@bestia[~]# ps auxww | grep bhyve
root       15697   4.7  1.2 1110860 409232  -  SC   Mon11      74:37.70 bhyve: 2_ns0 (bhyve)
root       34204   2.5  0.2 1110860  52768  -  SC   13:30       0:11.71 bhyve: 6_testdb00 (bhyve)


3. CONNECT to Serial Console via shell
OK! It works.

4. CONNECT via NEW UI
Disconncet from LEGACY UI
Connect to NEW UI

VM listing:

VM "testdb00" is RUNNING, but "Com Port" is set to /dev/nmdm2B while it should be /dev/nmdm6B!

5. STOP form NEW UI
Used Serial Console to shutdown properly. OK

middlewared.log
Code:
[2019/02/26 13:42:08] (DEBUG) VMService.run():287 - testdb00: fbuf frame buffer base: 0x842e00000 [sz 16777216]
[2019/02/26 13:42:08] (INFO) VMService.run():304 - ===> Powered off VM: testdb00 ID: 6 BHYVE_CODE: 1
[2019/02/26 13:42:08] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/26 13:42:08] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/26 13:42:08] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 6 BHYVE_CODE: 1


Serial console device /dev/nmdm6B is destroyed


6. START end STOP from LEGACY UI

middlewared.log @ START
Code:
[2019/02/26 13:46:06] (INFO) VMService.__set_guest_vmemory():901 - ===> Setting ARC FROM: 31258464256 TO: 30184722432
[2019/02/26 13:46:06] (DEBUG) VMService.run():179 - ====> NIC_ATTACH: vlan10
[2019/02/26 13:46:06] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm6A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap1,mac=00:a0:98:74:36:b1 -s 29,fbuf,vncserver,tcp=0.0.0.0:5906,w=1024,h=768,, -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 6_testdb00
[2019/02/26 13:46:06] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:46:06 Listening for VNC connections on TCP port 5906
[2019/02/26 13:46:06] (DEBUG) VMService.run():287 - testdb00: 26/02/2019 13:46:06 Listening for VNC connections on TCP6
port 5906
[2019/02/26 13:46:21] (DEBUG) VMService.run():287 - testdb00: Unhandled ps2 mouse command 0xe1


middlewared.log @ POWEROFF (via VM)
Code:
[2019/02/26 13:47:57] (DEBUG) VMService.run():287 - testdb00: fbuf frame buffer base: 0x842e00000 [sz 16777216]
[2019/02/26 13:47:57] (INFO) VMService.run():304 - ===> Powered off VM: testdb00 ID: 6 BHYVE_CODE: 1
[2019/02/26 13:47:57] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/26 13:47:57] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/26 13:47:57] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 6 BHYVE_CODE: 1


# END
 

KrisBee

Wizard
Joined
Mar 20, 2017
Messages
1,288
I thought the devices in that appear in that drop down VM NIC list had been fixed, but that perhaps it's still an outstanding issue at https://redmine.ixsystems.com/issues

Otherwise it looks like you have a bug to report. I was actually thinking of the slot number that the zvol device was attached to, in your case slot 3 as in -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 6_testdb00, but that seems to have been used in all cases you've tested.
 

proto

Patron
Joined
Sep 28, 2015
Messages
269
Ah! I had misunderstood about the slot, I was a little too focused on the console issue.
I can confirm that at least for the disks there is no problem: the slots in this case are correctly populated with the values entered in the UI during the disk configuration.

Now, I think it's better to file a bug report. I'll report here later.

While, for the NIC issue I could not find the reference bug and in any case there is too much difference in the list generated by the LEGACY UI and the NEW one: the first one gives me the listing of the igbX belonging to the lagg interface, the vlanX (correct!), but fortunately no device tapX; the second one gives me back lagg if, vlanX and the whole series of opened tapX ... Uhm!
 

KrisBee

Wizard
Joined
Mar 20, 2017
Messages
1,288
Seeing as you appear to want to use a console connection rather than VNC, have you tried selecting "UEFI-CSM" as the boot method? For this variant of bhyve UEFI firmware, I found the actual slot allocated to the disk device can make a difference to whether the VM boots or not.
 

proto

Patron
Joined
Sep 28, 2015
Messages
269
I can't use VNC, due to firewall restrictions.
Umm... tried to boot testdb00 in UEFI-CSM, but serial console seems unresponsive. While I see no differences between allocated slot

Code:
### START in UEFI-CSM ###
[2019/02/27 12:58:01] (DEBUG) VMService.run():287 - testdb00: fbuf frame buffer base: 0x842e00000 [sz 16777216]
[2019/02/27 12:58:01] (INFO) VMService.run():304 - ===> Powered off VM: testdb00 ID: 6 BHYVE_CODE: 1
[2019/02/27 12:58:01] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/27 12:58:01] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/27 12:58:01] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 6 BHYVE_CODE: 1
[2019/02/27 12:58:56] (INFO) VMService.__set_guest_vmemory():901 - ===> Setting ARC FROM: 30721593344 TO: 29647851520
[2019/02/27 12:58:56] (DEBUG) VMService.run():179 - ====> NIC_ATTACH: vlan10
[2019/02/27 12:58:56] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm6A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI_CSM.fd -s 4,virtio-net,tap2,mac=00:a0:98:6d:2d:3f -s 29,fbuf,vncserver,tcp=0.0.0.0:5906,w=1024,h=768,, -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 6_testdb00
[2019/02/27 12:58:56] (DEBUG) VMService.run():287 - testdb00: 27/02/2019 12:58:56 Listening for VNC connections on TCP port 5906
[2019/02/27 12:58:56] (DEBUG) VMService.run():287 - testdb00: 27/02/2019 12:58:56 Listening for VNC connections on TCP6 port 5906
[2019/02/27 13:07:15] (DEBUG) VMService.run():287 - testdb00: vm_run error -1, errno 25
[2019/02/27 13:07:15] (DEBUG) VMService.run():287 - testdb00: fbuf frame buffer base: 0x842e00000 [sz 16777216]
### DESTROY with bhyvectl ###
[2019/02/27 13:07:15] (INFO) VMService.run():304 - ===> Powered off VM: testdb00 ID: 6 BHYVE_CODE: 1
[2019/02/27 13:07:15] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/27 13:07:15] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 6 BHYVE_CODE: 1
### START in UEFI ###
[2019/02/27 13:08:02] (INFO) VMService.__set_guest_vmemory():901 - ===> Setting ARC FROM: 30721593344 TO: 29647851520
[2019/02/27 13:08:02] (DEBUG) VMService.run():179 - ====> NIC_ATTACH: vlan10
[2019/02/27 13:08:02] (DEBUG) VMService.run():265 - Starting bhyve: bhyve -A -H -w -c 1 -m 1024 -s 0:0,hostbridge -s 31,lpc -l com1,/dev/nmdm6A -l bootrom,/usr/local/share/uefi-firmware/BHYVE_UEFI.fd -s 4,virtio-net,tap2,mac=00:a0:98:3f:db:dc -s 29,fbuf,vncserver,tcp=0.0.0.0:5906,w=1024,h=768,, -s 30,xhci,tablet -s 3:0,ahci,hd:/dev/zvol/VMStore/db00 6_testdb00
[2019/02/27 13:08:02] (DEBUG) VMService.run():287 - testdb00: 27/02/2019 13:08:02 Listening for VNC connections on TCP port 5906
[2019/02/27 13:08:02] (DEBUG) VMService.run():287 - testdb00: 27/02/2019 13:08:02 Listening for VNC connections on TCP6 port 5906
### Running! :-) ###
[2019/02/27 13:08:18] (DEBUG) VMService.run():287 - testdb00: Unhandled ps2 mouse command 0xe1
[2019/02/27 13:10:55] (DEBUG) VMService.run():287 - testdb00: fbuf frame buffer base: 0x842e00000 [sz 16777216]
[2019/02/27 13:10:55] (INFO) VMService.run():304 - ===> Powered off VM: testdb00 ID: 6 BHYVE_CODE: 1
[2019/02/27 13:10:55] (ERROR) VMService.running():438 - ===> VMM testdb00 is running without bhyve process.
[2019/02/27 13:10:55] (DEBUG) VMService.__teardown_guest_vmemory():339 - ===> Give back guest memory to ARC: 1073741824
[2019/02/27 13:10:55] (WARNING) VMService.destroy_vm():319 - ===> Destroying VM: testdb00 ID: 6 BHYVE_CODE: 1


I can't boot any FreeBSD VMs in UEFI-CSM, even the ones created in 11.2-U2.
Quite strange... all VMs are FreeBSD 12-RELEASE based.
 

KrisBee

Wizard
Joined
Mar 20, 2017
Messages
1,288
Well that seems to be another possible bug as your middlewared.log output shows the firmware in use is still BHYVE_UEFI.fd It should be BHYVE_UEFI_CSM.fd
 

proto

Patron
Joined
Sep 28, 2015
Messages
269
I tried to boot some old FreeBSD 5/6/9 release in CSM. No way... Serial console is unresponsive and I cannot install, but I can't test further because my bhyve knowledge is minimal. So I don't know what to expect from CSM. I'm coming from FreeNAS 9 - nas only mode - with no jails/plugins/vms :)

So, to sum up: NEW UI gives unreliable serial ports and suggests tapX nics in dropdown list, but they are not blocking issues (maybe aesthetic? :p).

I opened these bugs:
#77773 --> serial ports messing / which seems related to 77764 opened while editing mine.
#77781 --> tapx nics issue
 
Top