Log output seems to be relavant:
2018-08-11T06:15:53.879281+00:00 INFO minijail0[12303]: libminijail[12303]: mount / -> / type ''
2018-08-11T06:15:53.879374+00:00 INFO minijail0[12303]: libminijail[12303]: mount proc -> /proc type 'proc'
2018-08-11T06:15:53.879391+00:00 INFO minijail0[12303]: libminijail[12303]: mount /sys -> /sys type ''
2018-08-11T06:15:53.879408+00:00 INFO minijail0[12303]: libminijail[12303]: mount /dev/chromeos-low-mem -> /dev/chromeos-low-mem type ''
2018-08-11T06:15:53.879424+00:00 INFO minijail0[12303]: libminijail[12303]: mount /dev/log -> /dev/log type ''
2018-08-11T06:15:53.879447+00:00 INFO minijail0[12303]: libminijail[12303]: mount /dev/kvm -> /dev/kvm type ''
2018-08-11T06:15:53.879464+00:00 INFO minijail0[12303]: libminijail[12303]: mount /dev/net -> /dev/net type ''
2018-08-11T06:15:53.879480+00:00 INFO minijail0[12303]: libminijail[12303]: mount /dev/vhost-vsock -> /dev/vhost-vsock type ''
2018-08-11T06:15:53.879496+00:00 INFO minijail0[12303]: libminijail[12303]: mount /dev/dri -> /dev/dri type ''
2018-08-11T06:15:53.879561+00:00 INFO minijail0[12303]: libminijail[12303]: mount run -> /run type 'tmpfs'
2018-08-11T06:15:53.879583+00:00 INFO minijail0[12303]: libminijail[12303]: mount /run/chrome -> /run/chrome type ''
2018-08-11T06:15:53.879600+00:00 INFO minijail0[12303]: libminijail[12303]: mount /run/dbus -> /run/dbus type ''
2018-08-11T06:15:53.879616+00:00 INFO minijail0[12303]: libminijail[12303]: mount /run/vm -> /run/vm type ''
2018-08-11T06:15:53.881334+00:00 DEBUG kernel: [  969.415836] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-08-11T06:15:53.879710+00:00 INFO minijail0[12303]: libminijail[12303]: mount var -> /var type 'tmpfs'
2018-08-11T06:15:53.879769+00:00 INFO minijail0[12303]: libminijail[12303]: mount empty -> /var/empty type 'tmpfs'
2018-08-11T06:15:53.879827+00:00 INFO minijail0[12303]: libminijail[12303]: mount /run/imageloader -> /run/imageloader type 'none'
2018-08-11T06:15:53.879885+00:00 INFO minijail0[12303]: libminijail[12303]: mount /home -> /home type 'none'
2018-08-11T06:15:53.882109+00:00 INFO minijail0[12303]: libminijail[12303]: not running init loop, exiting immediately
2018-08-11T06:15:53.902339+00:00 INFO vm_concierge[12304]: libminijail[1]: mount / -> / type ''
2018-08-11T06:15:53.902371+00:00 INFO vm_concierge[12304]: libminijail[1]: mount proc -> /proc type 'proc'
2018-08-11T06:15:53.902387+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /sys -> /sys type ''
2018-08-11T06:15:53.902403+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /dev/chromeos-low-mem -> /dev/chromeos-low-mem type ''
2018-08-11T06:15:53.902418+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /dev/log -> /dev/log type ''
2018-08-11T06:15:53.902434+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /dev/kvm -> /dev/kvm type ''
2018-08-11T06:15:53.902449+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /dev/net -> /dev/net type ''
2018-08-11T06:15:53.902465+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /dev/vhost-vsock -> /dev/vhost-vsock type ''
2018-08-11T06:15:53.902481+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /dev/dri -> /dev/dri type ''
2018-08-11T06:15:53.902496+00:00 INFO vm_concierge[12304]: libminijail[1]: mount run -> /run type 'tmpfs'
2018-08-11T06:15:53.902511+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /run/chrome -> /run/chrome type ''
2018-08-11T06:15:53.902526+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /run/dbus -> /run/dbus type ''
2018-08-11T06:15:53.902540+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /run/vm -> /run/vm type ''
2018-08-11T06:15:53.902555+00:00 INFO vm_concierge[12304]: libminijail[1]: mount var -> /var type 'tmpfs'
2018-08-11T06:15:53.902570+00:00 INFO vm_concierge[12304]: libminijail[1]: mount empty -> /var/empty type 'tmpfs'
2018-08-11T06:15:53.902585+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /run/imageloader -> /run/imageloader type 'none'
2018-08-11T06:15:53.902600+00:00 INFO vm_concierge[12304]: libminijail[1]: mount /home -> /home type 'none'
2018-08-11T06:15:53.903308+00:00 WARNING vm_concierge[12304]: libminijail[1]: stat(/dev/kvm) failed: No such file or directory
2018-08-11T06:15:53.903329+00:00 WARNING vm_concierge[12304]: libminijail[1]: creating mount target '/tmp/minijail.dev.8ToM5G/kvm' failed
2018-08-11T06:15:53.903848+00:00 DEBUG kernel: [  969.438220] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-08-11T06:15:53.915256+00:00 ERR vm_concierge[12304]: libminijail[1]: mount_one failed: No such file or directory
2018-08-11T06:15:53.928754+00:00 INFO crash_reporter[12305]: libminijail[12305]: mount /dev/log -> /dev/log type ''
2018-08-11T06:15:54.209817+00:00 DEBUG kernel: [  969.744882] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-08-11T06:15:54.220705+00:00 DEBUG kernel: [  969.755332] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-08-11T06:15:54.229524+00:00 WARNING crash_reporter[12305]: [user] Received crash notification for vm_concierge[12304] sig 11, user 0 (handling)
2018-08-11T06:15:54.232035+00:00 INFO crash_reporter[12305]: State of crashed process [12304]: S (sleeping)
2018-08-11T06:15:54.232748+00:00 INFO crash_reporter[12305]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/6'
2018-08-11T06:15:54.232997+00:00 WARNING crash_reporter[12305]: Crash directory /var/spool/crash already full with 32 pending reports
2018-08-11T06:15:54.233045+00:00 ERR crash_reporter[12305]: Could not create crash directory
2018-08-11T06:15:54.233085+00:00 ERR crash_reporter[12305]: Unable to find/create process-specific crash path
2018-08-11T06:15:54.233649+00:00 WARNING crash_reporter[12305]: [ARC] Received crash notification for vm_concierge[12304] sig 11, user 0 (ignoring - crash origin is not ARC)
2018-08-11T06:15:54.244290+00:00 WARNING kernel: [  969.777789] init: vm_concierge main process (12304) killed by SEGV signal
2018-08-11T06:15:54.244322+00:00 WARNING kernel: [  969.777844] init: vm_concierge main process ended, respawning

Deleted: debug-logs_20180810-231645.tgz 1.2 MB

debug-logs_20180810-231645.tgz 1.2 MB Download

2018-08-11T06:15:53.903308+00:00 WARNING vm_concierge[12304]: libminijail[1]: stat(/dev/kvm) failed: No such file or directory

This happens if you haven't done a cold reset since VM extensions were enabled. You can do this by shutting down completely, then holding refresh and pressing power.

+dgreid did we have a mechanism to force a cold reset when VMX is locked out? cyan didn't have a firmware update to trigger this.

I held refresh and pressed power and it didn't do anything. Still does the same bug.

After doing the cold reset, /dev/kvm exist but now i have this issue:
[1378:1378:0811/123500.470828:ERROR:object_proxy.cc(616)] Failed to call method: org.chromium.debugd.StartVmConcierge: object_path= /org/chromium/debugd: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.

New log:

Deleted: debug-logs_20180811-124908.tgz 1.3 MB

debug-logs_20180811-124908.tgz 1.3 MB Download

Confirmed not isolated and is reproducable by /u/Abalado on reddit. https://www.reddit.com/r/Crostini/comments/96im27/do_i_understand_the_version_process_correctly/

seems like vm_concierge service keeps stopping right after it starts, but couldn't find anything in the logs.

chirantan, was there an issue with per-user permissions on dbus messages?

The last few lines from the log in #5 still show that /dev/kvm is missing:

2018-08-11T12:46:07.349843-07:00 WARNING vm_concierge[8235]: libminijail[1]: stat(/dev/kvm) failed: No such file or directory
2018-08-11T12:46:07.349863-07:00 WARNING vm_concierge[8235]: libminijail[1]: creating mount target '/tmp/minijail.dev.WKAfnR/kvm' failed
2018-08-11T12:46:07.356374-07:00 ERR vm_concierge[8235]: libminijail[1]: mount_one failed: No such file or directory
'

cirantan, is there special instructions for devmode cold reset?

It's the same no matter what mode you are in: press the refresh and power buttons together.  The screen should immediately turn off and the device should reboot.

It's not doing that, it just keeps booting normally.

the power button is on the side of the chrome book, the normal pwr button is lock

Update: I'm an idiot. I had to do it with the computer still on. That being said, the bug still seems to happen. I'll upload the log in a second

/dev/kvm still doesnt exist, even after the hard reset.

I'm assuming at this point I haven't done a hard reset, but i have pressed, held, held for slightly less, pressed and immediately released the power and reset button and nothing has happened while the computer is off. So I have no idea whats going on, but the power reset combo *isn't working*.

I've seen 4 instances of the bug now.

two confirmed instances of cold reset not working now

Not working here after a cold reset.

Recovery, updated to canary, cold reset, setup termina and got logs, and /dev/kvm still doesn't exist.

Confirming same issue on Acer Chromebook R11 (CB5-132T/C738T)

Also, using Settings -> Delete Linux (Beta) does not work either, producing message "Error uninstalling Linux. Please try again".
 

I have another R11 that is showing all the symptoms described here for crostini terminal failing to open. 
Firmware Google_Cyan.7287.57.180
Version 70.0.3519.3 (canary)

I have the same issue, but note that when I enable linux from settings, I get "Error installing Linux - error mounting linux files, please try again'.   Trying again gives the same error.

Termina is shown in the apps list, but fails to start.   Running vmc start termina generates the error message quoted by the original poster.   This persists after a hard restart.

Acer R11 CB5-132, ChromeOS 70.0.3519.3 

Can you provide the contents of /proc/cmdline ?  We're looking for a string of the form "disablevmx=off" in there.



I didn't see that parameter in the logs from #5 and it shows that the kernel is disabling VMX:

2018-08-11T12:34:09.438076-07:00 INFO kernel: [    0.000000] Disabling VMX on cpu 0
2018-08-11T12:34:09.438327-07:00 INFO kernel: [    0.081801] Disabling VMX on cpu 1
2018-08-11T12:34:09.438342-07:00 INFO kernel: [    0.106331] Disabling VMX on cpu 2
2018-08-11T12:34:09.438345-07:00 WARNING kernel: [    0.119810]  #3<6>[    0.130844] Disabling VMX on cpu 3

contents of /proc/cmdline from my R11:

cros_secure console= loglevel=7 init=/sbin/init cros_secure oops=panic panic=-1 root=/dev/dm-0 rootwait ro dm_verity.error_behavior=3 dm_verity.max_bios=-1 dm_verity.dev_wait=1 dm="1 vroot none ro 1,0 3584000 verity payload=PARTUUID=c4d567c3-ddce-f84a-a0f5-6fa1d924f24b/PARTNROFF=1 hashtree=PARTUUID=c4d567c3-ddce-f84a-a0f5-6fa1d924f24b/PARTNROFF=1 hashstart=3584000 alg=sha1 root_hexdigest=dd25c054a37775d269fc5283cf5116459aa48db1 salt=8f844ce1f65d73b382c01a78deb8643ca018bd996d8e0184e6890e88c817d5f2" noinitrd vt.global_cursor_default=0 kern_guid=c4d567c3-ddce-f84a-a0f5-6fa1d924f24b add_efi_memmap boot=local noresume noswap i915.modeset=1 tpm_tis.force=1 tpm_tis.interrupts=0 nmi_watchdog=panic,lapic iwlwifi.remove_when_gone=1
                                                                            

Looks like it's a build side bug, seems like it isn't building the kernel with disablevmx=off.

if a board defines a modify_kernel_command_line function in its overlay, then it overrides instead of adds to the parent baseboard definition, that's why some braswells work but cyan doesn't. We need to add a disablevmx=off to its scripts/build_kernel_image.sh.

+dgreid, when should we expect this to be fixed?

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/board-overlays/+/da3bec69e5a625000ea8a7871f954d826ee2fd48

commit da3bec69e5a625000ea8a7871f954d826ee2fd48
Author: Dylan Reid <dgreid@chromium.org>
Date: Tue Aug 14 04:58:46 2018

cyan: Enable VMs on the command line

Because cyan defines different kernel command line than the other strago
boards, make sure VMs are enabled.

BUG= 873437 
TEST=none, I'm on vacation:)

Change-Id: I9757c85d796242692983c4b4baf020dbee80f469
Signed-off-by: Dylan Reid <dgreid@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/1173311
Reviewed-by: Stephen Barber <smbarber@chromium.org>
Reviewed-by: Chirantan Ekbote <chirantan@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>

[modify] https://crrev.com/da3bec69e5a625000ea8a7871f954d826ee2fd48/overlay-cyan/scripts/build_kernel_image.sh

What steps needed to test this fix? I updated canary build through settings, but vmc list command still produces

crosh> vmc list
Error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
Unable to start concierge service

You'll need a canary with the fix in it. Tomorrow's should have it, not sure it made the cut last night.

Then logout, press refresh+power at the same time to rest the system, then log back in and vmc should work, as should the UI integration.

Okay, I'll wait till tomorrow and re-try. I'm on canary. Thanks!

It should be in today, there was no update last night so if there was one then it should have the fix

Can confirm it *is* in the latest build. Try doing a hard reset?

It works for me in the latest Canary build now, but it did take some extra work to have it up and running. Before a hard reset (Reset + Power) I still had no /dev/kvm, so neither the Terminal icon nor "vmc start termina" would work.

After the reset (Reset + Power) I could confirm that /dev/kvm existed.

"vmc start termina" worked, and afterwards the Terminal icon brought in the complete Crostini container while displaying a loading anymation for a while. I've been able to install several GUI applications from the repositories now.

Machine: Acer R11 CB5-132T

After hard reset I chose "Turn On" on Linux and after few minutes of wait got the terminal up and running. Installed nano and mc. Kudos! Great job, guys, and thanks for all the hard work you put into this project.

That's a few reports that it works, marking verified.

Thanks for the debugging help.

This still doesn't work for me even after hard reset..

I got a new issue a few Canary updates later which was resolved by this: https://gist.github.com/bzub/65aabace4a60874c61ece4838b6219f3

Perhaps someone could open a new ticket for that if that hasn't been done already?

this bug is simply about cyan & kvm not working.  if they're working now, this bug is resolved.  if you have a new issue, please file a new bug rather than commenting here.  if you're able to start a container, then it's def unrelated to this bug.