search

crc-org / crc

CRC is a tool to help you run containers. It manages a local OpenShift 4.x cluster, Microshift or a Podman VM optimized for testing and development purposes
https://crc.dev
Apache License 2.0
1.25k stars 236 forks source link

[BUG] Running on a self-compiled (vanilla) kernel might result in a seccomp_init() failed error #3577

Closed eskuai closed 1 year ago

eskuai commented 1 year ago

General information

CRC version

# Put `crc version` output here
$ crc version
CRC version: 2.15.0+cc05160
OpenShift version: 4.12.5
Podman version: 4.3.1

CRC status

# Put `crc status --log-level debug` output here
crc status --log-level debug
DEBU CRC version: 2.15.0+cc05160                  
DEBU OpenShift version: 4.12.5                    
DEBU Podman version: 4.3.1                        
DEBU Running 'crc status'                         
CRC VM:          Stopped
OpenShift:       Stopped (v4.12.0-0.okd-2023-02-18-033438)
RAM Usage:       0B of 0B
Disk Usage:      0B of 0B (Inside the CRC VM)
Cache Usage:     32.48GB
Cache Directory: /home/jj/.crc/cache

CRC config

# Put `crc config view` output here
crc config view
- consent-telemetry                     : no
- preset                                : okd

Host Operating System

# Put the output of `cat /etc/os-release` in case of Linux
# put the output of `sw_vers` in case of Mac
# Put the output of `systeminfo` in case of Windows

cat /etc/os-release
NAME="Fedora Linux"
VERSION="37 (Workstation Edition)"
ID=fedora
VERSION_ID=37
VERSION_CODENAME=""
PLATFORM_ID="platform:f37"
PRETTY_NAME="Fedora Linux 37 (Workstation Edition)"
ANSI_COLOR="0;38;2;60;110;180"
LOGO=fedora-logo-icon
CPE_NAME="cpe:/o:fedoraproject:fedora:37"
DEFAULT_HOSTNAME="fedora"
HOME_URL="https://fedoraproject.org/"
DOCUMENTATION_URL="https://docs.fedoraproject.org/en-US/fedora/f37/system-administrators-guide/"
SUPPORT_URL="https://ask.fedoraproject.org/"
BUG_REPORT_URL="https://bugzilla.redhat.com/"
REDHAT_BUGZILLA_PRODUCT="Fedora"
REDHAT_BUGZILLA_PRODUCT_VERSION=37
REDHAT_SUPPORT_PRODUCT="Fedora"
REDHAT_SUPPORT_PRODUCT_VERSION=37
SUPPORT_END=2023-11-14
VARIANT="Workstation Edition"
VARIANT_ID=workstation

Steps to reproduce

  1. crc delete
  2. crc setup
  3. crc start

Expected

A running okd instance -

Actual

An error install

Logs

# tail -f crc.log 
-device '{"driver":"isa-serial","chardev":"charserial0","id":"serial0","index":0}' \
-audiodev '{"id":"audio1","driver":"none"}' \
-vnc 127.0.0.1:0,audiodev=audio1 \
-device '{"driver":"cirrus-vga","id":"video0","bus":"pcie.0","addr":"0x1"}' \
-object '{"qom-type":"rng-random","id":"objrng0","filename":"/dev/urandom"}' \
-device '{"driver":"virtio-rng-pci","rng":"objrng0","id":"rng0","bus":"pci.5","addr":"0x0"}' \
-msg timestamp=on
2023-04-04T14:08:33.267526Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: Failed to write msg. Wrote -1 instead of 12.
2023-04-04T14:08:33.267547Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: vhost_backend_init failed: Protocol error
2023-04-04 14:08:33.333+0000: shutting down, reason=failed
---
[root@darkstar qemu]# tail -f crc-fs0-virtiofsd.log
seccomp_init() failed
virtio_session_mount: Waiting for vhost-user socket connection...
virtio_session_mount: Received vhost-user socket connection
seccomp_init() failed
virtio_session_mount: Waiting for vhost-user socket connection...
virtio_session_mount: Received vhost-user socket connection
seccomp_init() failed
virtio_session_mount: Waiting for vhost-user socket connection...
virtio_session_mount: Received vhost-user socket connection
seccomp_init() failed

Before gather the logs try following if that fix your issue

$ crc delete -f
$ crc cleanup
$ crc setup
$ crc start --log-level debug

Please consider posting the output of crc start --log-level debug on http://gist.github.com/ and post the link in the issue.

praveenkumar commented 1 year ago

can you post the output of $ crc setup --log-level debug to understand which step is actually failing?

eskuai commented 1 year ago

Sure.

crc setup --log-level debug
DEBU CRC version: 2.15.0+cc05160                  
DEBU OpenShift version: 4.12.5                    
DEBU Podman version: 4.3.1                        
DEBU Running 'crc setup'                          
INFO Using bundle path /home/jj/.crc/cache/crc_okd_libvirt_4.12.0-0.okd-2023-02-18-033438_amd64.crcbundle 
DEBU Checking if systemd-resolved.service is running 
DEBU Running 'systemctl status systemd-resolved.service' 
DEBU systemd-resolved.service is already running  
INFO Checking if running as non-root              
INFO Checking if running inside WSL2              
INFO Checking if crc-admin-helper executable is cached 
DEBU Running '/home/jj/.crc/bin/crc-admin-helper-linux --version' 
DEBU Found crc-admin-helper-linux version 0.0.12  
DEBU crc-admin-helper executable already cached   
INFO Checking if running on a supported CPU architecture 
DEBU GOARCH is amd64 GOOS is linux                
INFO Checking minimum RAM requirements            
DEBU Total memory of system is 67345199104 bytes  
INFO Checking if crc executable symlink exists    
INFO Checking if Virtualization is enabled        
DEBU Checking if the vmx/svm flags are present in /proc/cpuinfo 
DEBU CPU virtualization flags are good            
INFO Checking if KVM is enabled                   
DEBU Checking if /dev/kvm exists                  
DEBU /dev/kvm was found                           
INFO Checking if libvirt is installed             
DEBU Checking if 'virsh' is available             
DEBU 'virsh' was found in /usr/bin/virsh          
DEBU Checking 'virsh capabilities' for libvirtd/qemu availability 
DEBU Running 'virsh --readonly --connect qemu:///system capabilities' 
DEBU Found x86_64 hypervisor with 'hvm' capabilities 
INFO Checking if user is part of libvirt group    
DEBU Checking if current user is part of the libvirt group 
DEBU Current user is already in the libvirt group 
INFO Checking if active user/process is currently part of the libvirt group 
INFO Checking if libvirt daemon is running        
DEBU Checking if libvirtd service is running      
DEBU Running 'systemctl status virtqemud.socket'  
DEBU virtqemud.socket is running                  
INFO Checking if a supported libvirt version is installed 
DEBU Checking if libvirt version is >=3.4.0       
DEBU Running 'virsh -v'                           
INFO Checking if crc-driver-libvirt is installed  
DEBU Checking if crc-driver-libvirt is installed  
DEBU Running '/home/jj/.crc/bin/crc-driver-libvirt version' 
DEBU Found crc-driver-libvirt version 0.13.5      
DEBU crc-driver-libvirt is already installed      
INFO Checking crc daemon systemd service          
DEBU Checking crc daemon systemd service          
DEBU Checking if crc-daemon.service is running    
DEBU Running 'systemctl --user status crc-daemon.service' 
DEBU Command failed: exit status 3                
DEBU stdout: * crc-daemon.service - CRC daemon
     Loaded: loaded (/home/jj/.config/systemd/user/crc-daemon.service; static)
     Active: inactive (dead) since Tue 2023-04-04 17:07:57 CEST; 1min 28s ago
   Duration: 8min 30.404s
TriggeredBy: * crc-vsock.socket
             * crc-http.socket
    Process: 30286 ExecStart=/home/jj/.crc/bin/crc daemon (code=exited, status=0/SUCCESS)
   Main PID: 30286 (code=exited, status=0/SUCCESS)
        CPU: 145ms

Apr 04 16:59:27 darkstar systemd[1059]: Starting crc-daemon.service - CRC daemon...
Apr 04 16:59:27 darkstar crc[30286]: level=info msg="using socket provided by crc-vsock.socket"
Apr 04 16:59:27 darkstar crc[30286]: level=info msg="using socket provided by crc-http.socket"
Apr 04 16:59:27 darkstar systemd[1059]: Started crc-daemon.service - CRC daemon.
Apr 04 16:59:27 darkstar crc[30286]: @ - - [04/Apr/2023:16:59:27 +0200] "GET /api/status HTTP/1.1" 200 172
Apr 04 17:07:57 darkstar systemd[1059]: Stopping crc-daemon.service - CRC daemon...
Apr 04 17:07:57 darkstar systemd[1059]: Stopped crc-daemon.service - CRC daemon. 
DEBU stderr:                                      
DEBU crc-daemon.service is neither running nor listening 
DEBU Checking if crc-daemon.service has the expected content 
INFO Checking crc daemon systemd socket units     
DEBU Checking crc daemon systemd socket units     
DEBU Checking if crc-http.socket is running       
DEBU Running 'systemctl --user status crc-http.socket' 
DEBU crc-http.socket is listening                 
DEBU Checking if crc-http.socket has the expected content 
DEBU Checking if crc-vsock.socket is running      
DEBU Running 'systemctl --user status crc-vsock.socket' 
DEBU crc-vsock.socket is listening                
DEBU Checking if crc-vsock.socket has the expected content 
INFO Checking if systemd-networkd is running      
DEBU Checking if systemd-networkd.service is running 
DEBU Running 'systemctl status systemd-networkd.service' 
DEBU Command failed: exit status 3                
DEBU stdout: * systemd-networkd.service - Network Configuration
     Loaded: loaded (/usr/lib/systemd/system/systemd-networkd.service; disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: * systemd-networkd.socket
       Docs: man:systemd-networkd.service(8) 
DEBU stderr:                                      
DEBU systemd-networkd.service is not running      
INFO Checking if NetworkManager is installed      
DEBU Checking if 'nmcli' is available             
DEBU 'nmcli' was found in /usr/bin/nmcli          
INFO Checking if NetworkManager service is running 
DEBU Checking if NetworkManager.service is running 
DEBU Running 'systemctl status NetworkManager.service' 
DEBU NetworkManager.service is already running    
INFO Checking if dnsmasq configurations file exist for NetworkManager 
INFO Checking if the systemd-resolved service is running 
DEBU Checking if systemd-resolved.service is running 
DEBU Running 'systemctl status systemd-resolved.service' 
DEBU systemd-resolved.service is already running  
INFO Checking if /etc/NetworkManager/dispatcher.d/99-crc.sh exists 
DEBU Checking NetworkManager dispatcher file for crc network 
DEBU Dispatcher file has the expected content     
INFO Checking if libvirt 'crc' network is available 
DEBU Checking if libvirt 'crc' network exists     
DEBU Running 'virsh --connect qemu:///system net-info crc' 
DEBU Checking if libvirt 'crc' definition is up to date 
DEBU Running 'virsh --connect qemu:///system net-dumpxml --inactive crc' 
DEBU libvirt 'crc' network has the expected value 
INFO Checking if libvirt 'crc' network is active  
DEBU Checking if libvirt 'crc' network is active  
DEBU Running 'virsh --connect qemu:///system net-info crc' 
DEBU libvirt 'crc' network is already active      
INFO Checking if CRC bundle is extracted in '$HOME/.crc' 
INFO Checking if /home/jj/.crc/cache/crc_okd_libvirt_4.12.0-0.okd-2023-02-18-033438_amd64.crcbundle exists 
DEBU /home/jj/.crc/cache/crc_okd_libvirt_4.12.0-0.okd-2023-02-18-033438_amd64.crcbundle exists 
Your system is correctly setup for using CRC. Use 'crc start' to start the instance
eskuai commented 1 year ago 
crc start  --log-level debug
DEBU CRC version: 2.15.0+cc05160                  
DEBU OpenShift version: 4.12.5                    
DEBU Podman version: 4.3.1                        
DEBU Running 'crc start'                          
DEBU Total memory of system is 67345199104 bytes  
DEBU No new version available. The latest version is 2.15.0 
DEBU Checking file: /home/jj/.crc/machines/crc/.crc-exist 
DEBU Found binary path at /home/jj/.crc/bin/crc-driver-libvirt 
DEBU Launching plugin server for driver libvirt   
DEBU Plugin server listening at address 127.0.0.1:39589 
DEBU () Calling .GetVersion                       
DEBU Using API Version 1                          
DEBU () Calling .SetConfigRaw                     
DEBU () Calling .GetMachineName                   
DEBU (crc) Calling .GetBundleName                 
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2023-04-04T17:12:07+02:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2023-04-04T17:12:07+02:00" level=debug msg="Fetching VM..." 
DEBU Making call to close driver server           
DEBU (crc) Calling .Close                         
DEBU Successfully made call to close driver server 
DEBU Making call to close connection to plugin binary 
DEBU (crc) DBG | time="2023-04-04T17:12:07+02:00" level=debug msg="Closing plugin on server side" 
DEBU Checking if systemd-resolved.service is running 
DEBU Running 'systemctl status systemd-resolved.service' 
DEBU systemd-resolved.service is already running  
INFO Checking if running as non-root              
INFO Checking if running inside WSL2              
INFO Checking if crc-admin-helper executable is cached 
DEBU Running '/home/jj/.crc/bin/crc-admin-helper-linux --version' 
DEBU Found crc-admin-helper-linux version 0.0.12  
DEBU crc-admin-helper executable already cached   
INFO Checking if running on a supported CPU architecture 
DEBU GOARCH is amd64 GOOS is linux                
INFO Checking minimum RAM requirements            
DEBU Total memory of system is 67345199104 bytes  
INFO Checking if crc executable symlink exists    
INFO Checking if Virtualization is enabled        
DEBU Checking if the vmx/svm flags are present in /proc/cpuinfo 
DEBU CPU virtualization flags are good            
INFO Checking if KVM is enabled                   
DEBU Checking if /dev/kvm exists                  
DEBU /dev/kvm was found                           
INFO Checking if libvirt is installed             
DEBU Checking if 'virsh' is available             
DEBU 'virsh' was found in /usr/bin/virsh          
DEBU Checking 'virsh capabilities' for libvirtd/qemu availability 
DEBU Running 'virsh --readonly --connect qemu:///system capabilities' 

DEBU Found x86_64 hypervisor with 'hvm' capabilities 
INFO Checking if user is part of libvirt group    
DEBU Checking if current user is part of the libvirt group 
DEBU Current user is already in the libvirt group 
INFO Checking if active user/process is currently part of the libvirt group 
INFO Checking if libvirt daemon is running        
DEBU Checking if libvirtd service is running      
DEBU Running 'systemctl status virtqemud.socket'  
DEBU virtqemud.socket is running                  
INFO Checking if a supported libvirt version is installed 
DEBU Checking if libvirt version is >=3.4.0       
DEBU Running 'virsh -v'                           
INFO Checking if crc-driver-libvirt is installed  
DEBU Checking if crc-driver-libvirt is installed  
DEBU Running '/home/jj/.crc/bin/crc-driver-libvirt version' 
DEBU Found crc-driver-libvirt version 0.13.5      
DEBU crc-driver-libvirt is already installed      
INFO Checking crc daemon systemd socket units     
DEBU Checking crc daemon systemd socket units     
DEBU Checking if crc-http.socket is running       
DEBU Running 'systemctl --user status crc-http.socket' 
DEBU crc-http.socket is listening                 
DEBU Checking if crc-http.socket has the expected content 
DEBU Checking if crc-vsock.socket is running      
DEBU Running 'systemctl --user status crc-vsock.socket' 
DEBU crc-vsock.socket is listening                
DEBU Checking if crc-vsock.socket has the expected content 
INFO Checking if systemd-networkd is running      
DEBU Checking if systemd-networkd.service is running 
DEBU Running 'systemctl status systemd-networkd.service' 
DEBU Command failed: exit status 3                
DEBU stdout: * systemd-networkd.service - Network Configuration
     Loaded: loaded (/usr/lib/systemd/system/systemd-networkd.service; disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: * systemd-networkd.socket
       Docs: man:systemd-networkd.service(8) 
DEBU stderr:                                      
DEBU systemd-networkd.service is not running      
INFO Checking if NetworkManager is installed      
DEBU Checking if 'nmcli' is available             
DEBU 'nmcli' was found in /usr/bin/nmcli          
INFO Checking if NetworkManager service is running 
DEBU Checking if NetworkManager.service is running 
DEBU Running 'systemctl status NetworkManager.service' 
DEBU NetworkManager.service is already running    
INFO Checking if dnsmasq configurations file exist for NetworkManager 
INFO Checking if the systemd-resolved service is running 
DEBU Checking if systemd-resolved.service is running 
DEBU Running 'systemctl status systemd-resolved.service' 
DEBU systemd-resolved.service is already running  
INFO Checking if /etc/NetworkManager/dispatcher.d/99-crc.sh exists 
DEBU Checking NetworkManager dispatcher file for crc network 
DEBU Dispatcher file has the expected content     
INFO Checking if libvirt 'crc' network is available 
DEBU Checking if libvirt 'crc' network exists     
DEBU Running 'virsh --connect qemu:///system net-info crc' 
DEBU Checking if libvirt 'crc' definition is up to date 
DEBU Running 'virsh --connect qemu:///system net-dumpxml --inactive crc' 
DEBU libvirt 'crc' network has the expected value 
INFO Checking if libvirt 'crc' network is active  
DEBU Checking if libvirt 'crc' network is active  
DEBU Running 'virsh --connect qemu:///system net-info crc' 
DEBU libvirt 'crc' network is already active      
DEBU Checking file: /home/jj/.crc/machines/crc/.crc-exist 
INFO Loading bundle: crc_okd_libvirt_4.12.0-0.okd-2023-02-18-033438_amd64... 
DEBU Checking file: /home/jj/.crc/machines/crc/.crc-exist 
DEBU Found binary path at /home/jj/.crc/bin/crc-driver-libvirt 
DEBU Launching plugin server for driver libvirt   
DEBU Plugin server listening at address 127.0.0.1:44399 
DEBU () Calling .GetVersion                       
DEBU Using API Version 1                          
DEBU () Calling .SetConfigRaw                     
DEBU () Calling .GetMachineName                   
DEBU (crc) Calling .GetBundleName                 
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=debug msg="Fetching VM..." 
INFO Starting CRC VM for okd 4.12.0-0.okd-2023-02-18-033438... 
DEBU Updating CRC VM configuration                
DEBU (crc) Calling .GetConfigRaw                  
DEBU (crc) Calling .Start                         
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=debug msg="Starting VM crc" 
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=debug msg="Validating storage pool" 
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=warning msg="Failed to start: virError(Code=1, Domain=10, Message='internal error: qemu unexpectedly closed the monitor: 2023-04-04T15:12:15.085467Z qemu-system-x86_64: -device {\"driver\":\"vhost-user-fs-pci\",\"id\":\"fs0\",\"chardev\":\"chr-vu-fs0\",\"tag\":\"dir0\",\"bus\":\"pci.1\",\"addr\":\"0x0\"}: Failed to write msg. Wrote -1 instead of 12.\n2023-04-04T15:12:15.085488Z qemu-system-x86_64: -device {\"driver\":\"vhost-user-fs-pci\",\"id\":\"fs0\",\"chardev\":\"chr-vu-fs0\",\"tag\":\"dir0\",\"bus\":\"pci.1\",\"addr\":\"0x0\"}: vhost_backend_init failed: Protocol error')" 
DEBU Making call to close driver server           
DEBU (crc) Calling .Close                         
DEBU Successfully made call to close driver server 
DEBU Making call to close connection to plugin binary 
DEBU (crc) DBG | time="2023-04-04T17:12:15+02:00" level=debug msg="Closing plugin on server side" 
Error starting machine: Error in driver during machine start: virError(Code=1, Domain=10, Message='internal error: qemu unexpectedly closed the monitor: 2023-04-04T15:12:15.085467Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: Failed to write msg. Wrote -1 instead of 12.
2023-04-04T15:12:15.085488Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: vhost_backend_init failed: Protocol error')
gbraad commented 1 year ago
  • preset : okd

We do not provide support for the OKD bundle. Issues using this preset have to be filed at: https://github.com/okd-project/okd/issues

If you can try to run the openshift preset and see if you also experience these issues, we might be able to help you.

gbraad commented 1 year ago

@jsliacan Can you try to run on a fully updated Fedora 37 machine, without any additional installs, and see if you get the same results? Note: I have not seen them on my system(s). @praveenkumar @cfergeau WDYT?

gbraad commented 1 year ago

@praveenkumar. This starts virtiofsd, but something in the protocol fails; seccomp initialization does not pass.

Error starting machine: Error in driver during machine start: virError(Code=1, Domain=10, Message='internal error: qemu unexpectedly closed the monitor: 2023-04-04T15:12:15.085467Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: Failed to write msg. Wrote -1 instead of 12.
2023-04-04T15:12:15.085488Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: vhost_backend_init failed: Protocol error')

@eskuai are you running with a non-standard kernel? selinux enabled? Anything else installed on the machine that might have changed sysctl, kernel or other parameters?

eskuai commented 1 year ago

I think that podman was before ... or no message ... I'll try to reset all, restart again ...

maybe:

INFO Downloading bundle: /home/jsanz/.crc/cache/crc_libvirt_4.12.5_amd64.crcbundle...

a) Non standard kernel ? ... yes ... 

Linux darkstar 6.2.9 #7 SMP PREEMPT_DYNAMIC Thu Mar 30 13:33:47 CEST 2023 x86_64 x86_64 x86_64 GNU/Linux

b) TO-DO: Check using fedora kernel ... if i got the same problem, restart with fedora kernel ... c) selinux is disabled ... 

sestatus
SELinux status:                 disabled
gbraad commented 1 year ago

Non standard kernel ? ... yes ...

Unsupported in that case. We only test and provide support for the distribution provided kernels.

It is stil interesting to understand what you have done, but I am sure we can not do much for you.

eskuai commented 1 year ago

Right,

INFO Checking if dnsmasq configurations file exist for NetworkManager 
INFO Checking if the systemd-resolved service is running 
INFO Checking if /etc/NetworkManager/dispatcher.d/99-crc.sh exists 
INFO Checking if libvirt 'crc' network is available 
INFO Checking if libvirt 'crc' network is active  
INFO Checking if CRC bundle is extracted in '$HOME/.crc' 
INFO Checking if /home/jj/.crc/cache/crc_libvirt_4.12.5_amd64.crcbundle exists 
INFO Getting bundle for the CRC executable        
INFO Downloading bundle: /home/jj/.crc/cache/crc_libvirt_4.12.5_amd64.crcbundle... 
2.98 GiB / 2.98 GiB [-----------------------------------------------------------------------------------------------------------------------------------------] 100.00% 27.26 MiB p/s
INFO Uncompressing /home/jj/.crc/cache/crc_libvirt_4.12.5_amd64.crcbundle 
crc.qcow2:  11.82 GiB / 11.82 GiB [-----------------------------------------------------------------------------------------------------------------------------------------] 100.00%
oc:  124.65 MiB / 124.65 MiB [----------------------------------------------------------------------------------------------------------------------------------------------] 100.00%
Your system is correctly setup for using CRC. Use 'crc start' to start the instance

And now

 crc config view
- consent-telemetry                     : yes
eskuai commented 1 year ago

Same problem...

[jj@darkstar ~]$ 
[jj@darkstar ~]$ crc start  --log-level debug
DEBU CRC version: 2.15.0+cc05160                  
DEBU OpenShift version: 4.12.5                    
DEBU Podman version: 4.3.1                        
DEBU Running 'crc start'                          
DEBU Total memory of system is 67345199104 bytes  
DEBU No new version available. The latest version is 2.15.0 
DEBU Checking file: /home/jj/.crc/machines/crc/.crc-exist 
DEBU Checking if systemd-resolved.service is running 
DEBU Running 'systemctl status systemd-resolved.service' 
DEBU systemd-resolved.service is already running  
INFO Checking if running as non-root              
INFO Checking if running inside WSL2              
INFO Checking if crc-admin-helper executable is cached 
DEBU Running '/home/jj/.crc/bin/crc-admin-helper-linux --version' 
DEBU Found crc-admin-helper-linux version 0.0.12  
DEBU crc-admin-helper executable already cached   
INFO Checking if running on a supported CPU architecture 
DEBU GOARCH is amd64 GOOS is linux                
INFO Checking minimum RAM requirements            
DEBU Total memory of system is 67345199104 bytes  
INFO Checking if crc executable symlink exists    
INFO Checking if Virtualization is enabled        
DEBU Checking if the vmx/svm flags are present in /proc/cpuinfo 
DEBU CPU virtualization flags are good            
INFO Checking if KVM is enabled                   
DEBU Checking if /dev/kvm exists                  
DEBU /dev/kvm was found                           
INFO Checking if libvirt is installed             
DEBU Checking if 'virsh' is available             
DEBU 'virsh' was found in /usr/bin/virsh          
DEBU Checking 'virsh capabilities' for libvirtd/qemu availability 
DEBU Running 'virsh --readonly --connect qemu:///system capabilities' 
DEBU Found x86_64 hypervisor with 'hvm' capabilities 
INFO Checking if user is part of libvirt group    
DEBU Checking if current user is part of the libvirt group 
DEBU Current user is already in the libvirt group 
INFO Checking if active user/process is currently part of the libvirt group 
INFO Checking if libvirt daemon is running        
DEBU Checking if libvirtd service is running      
DEBU Running 'systemctl status virtqemud.socket'  
DEBU virtqemud.socket is running                  
INFO Checking if a supported libvirt version is installed 
DEBU Checking if libvirt version is >=3.4.0       
DEBU Running 'virsh -v'                           
INFO Checking if crc-driver-libvirt is installed  
DEBU Checking if crc-driver-libvirt is installed  
DEBU Running '/home/jj/.crc/bin/crc-driver-libvirt version' 
DEBU Found crc-driver-libvirt version 0.13.5      
DEBU crc-driver-libvirt is already installed      
INFO Checking crc daemon systemd socket units     
DEBU Checking crc daemon systemd socket units     
DEBU Checking if crc-http.socket is running       
DEBU Running 'systemctl --user status crc-http.socket' 
DEBU crc-http.socket is listening                 
DEBU Checking if crc-http.socket has the expected content 
DEBU Checking if crc-vsock.socket is running      
DEBU Running 'systemctl --user status crc-vsock.socket' 
DEBU crc-vsock.socket is listening                
DEBU Checking if crc-vsock.socket has the expected content 
INFO Checking if systemd-networkd is running      
DEBU Checking if systemd-networkd.service is running 
DEBU Running 'systemctl status systemd-networkd.service' 
DEBU Command failed: exit status 3                
DEBU stdout: * systemd-networkd.service - Network Configuration
     Loaded: loaded (/usr/lib/systemd/system/systemd-networkd.service; disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: * systemd-networkd.socket
       Docs: man:systemd-networkd.service(8) 
DEBU stderr:                                      
DEBU systemd-networkd.service is not running      
INFO Checking if NetworkManager is installed      
DEBU Checking if 'nmcli' is available             
DEBU 'nmcli' was found in /usr/bin/nmcli          
INFO Checking if NetworkManager service is running 
DEBU Checking if NetworkManager.service is running 
DEBU Running 'systemctl status NetworkManager.service' 
DEBU NetworkManager.service is already running    
INFO Checking if dnsmasq configurations file exist for NetworkManager 
INFO Checking if the systemd-resolved service is running 
DEBU Checking if systemd-resolved.service is running 
DEBU Running 'systemctl status systemd-resolved.service' 
DEBU systemd-resolved.service is already running  
INFO Checking if /etc/NetworkManager/dispatcher.d/99-crc.sh exists 
DEBU Checking NetworkManager dispatcher file for crc network 
DEBU Dispatcher file has the expected content     
INFO Checking if libvirt 'crc' network is available 
DEBU Checking if libvirt 'crc' network exists     
DEBU Running 'virsh --connect qemu:///system net-info crc' 
DEBU Checking if libvirt 'crc' definition is up to date 
DEBU Running 'virsh --connect qemu:///system net-dumpxml --inactive crc' 
DEBU libvirt 'crc' network has the expected value 
INFO Checking if libvirt 'crc' network is active  
DEBU Checking if libvirt 'crc' network is active  
DEBU Running 'virsh --connect qemu:///system net-info crc' 
DEBU libvirt 'crc' network is already active      
DEBU Checking file: /home/jj/.crc/machines/crc/.crc-exist 
INFO Loading bundle: crc_libvirt_4.12.5_amd64...  
DEBU Cannot load secret from configuration: empty path 
DEBU Using secret from keyring                    
INFO Creating CRC VM for openshift 4.12.5...      
DEBU Found binary path at /home/jj/.crc/bin/crc-driver-libvirt 
DEBU Launching plugin server for driver libvirt   
DEBU Plugin server listening at address 127.0.0.1:46067 
DEBU () Calling .GetVersion                       
DEBU Using API Version 1                          
DEBU () Calling .SetConfigRaw                     
DEBU () Calling .GetMachineName                   
DEBU (crc) Calling .GetMachineName                
DEBU (crc) Calling .DriverName                    
DEBU Running pre-create checks...                 
DEBU (crc) Calling .PreCreateCheck                
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="About to check libvirt version" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Validating storage pool" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Activating pool 'crc'" 
DEBU (crc) Calling .GetConfigRaw                  
DEBU Creating machine...                          
DEBU (crc) Calling .Create                        
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Preparing /home/jj/.crc/machines/crc/crc.qcow2 for machine use" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="image creation took 6.663459ms" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Verifying executable bit set on /home/jj/.crc/machines/crc" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Verifying executable bit set on /home/jj/.crc/machines" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Verifying executable bit set on /home/jj/.crc" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Setting executable bit set on /home/jj/.crc" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Verifying executable bit set on /home/jj" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Verifying executable bit set on /home" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Defining VM..." 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Found x86_64 hypervisor with 'hvm' capabilities" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Found q35 machine type" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Found x86_64 hypervisor with 'hvm' capabilities" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Found q35 machine type" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="disk image capacity is already 33285996544 bytes" 
INFO Generating new SSH key pair...               
INFO Generating new password for the kubeadmin user 
DEBU Created /home/jj/.crc/machines/crc/.crc-exist 
DEBU Machine successfully created                 
DEBU Making call to close driver server           
DEBU (crc) Calling .Close                         
DEBU Successfully made call to close driver server 
DEBU Making call to close connection to plugin binary 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Closing plugin on server side" 
DEBU Checking file: /home/jj/.crc/machines/crc/.crc-exist 
DEBU Found binary path at /home/jj/.crc/bin/crc-driver-libvirt 
DEBU Launching plugin server for driver libvirt   
DEBU Plugin server listening at address 127.0.0.1:44839 
DEBU () Calling .GetVersion                       
DEBU Using API Version 1                          
DEBU () Calling .SetConfigRaw                     
DEBU () Calling .GetMachineName                   
DEBU (crc) Calling .GetBundleName                 
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Fetching VM..." 
INFO Starting CRC VM for openshift 4.12.5...      
DEBU Updating CRC VM configuration                
DEBU (crc) Calling .GetConfigRaw                  
DEBU (crc) Calling .Start                         
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Starting VM crc" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Validating storage pool" 
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=warning msg="Failed to start: virError(Code=1, Domain=10, Message='internal error: qemu unexpectedly closed the monitor: 2023-04-04T15:31:15.272360Z qemu-system-x86_64: -device {\"driver\":\"vhost-user-fs-pci\",\"id\":\"fs0\",\"chardev\":\"chr-vu-fs0\",\"tag\":\"dir0\",\"bus\":\"pci.1\",\"addr\":\"0x0\"}: Failed to write msg. Wrote -1 instead of 12.\n2023-04-04T15:31:15.272381Z qemu-system-x86_64: -device {\"driver\":\"vhost-user-fs-pci\",\"id\":\"fs0\",\"chardev\":\"chr-vu-fs0\",\"tag\":\"dir0\",\"bus\":\"pci.1\",\"addr\":\"0x0\"}: vhost_backend_init failed: Protocol error')" 
DEBU Making call to close driver server           
DEBU (crc) Calling .Close                         
DEBU (crc) DBG | time="2023-04-04T17:31:15+02:00" level=debug msg="Closing plugin on server side" 
DEBU Successfully made call to close driver server 
DEBU Making call to close connection to plugin binary 
Error starting machine: Error in driver during machine start: virError(Code=1, Domain=10, Message='internal error: qemu unexpectedly closed the monitor: 2023-04-04T15:31:15.272360Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: Failed to write msg. Wrote -1 instead of 12.
2023-04-04T15:31:15.272381Z qemu-system-x86_64: -device {"driver":"vhost-user-fs-pci","id":"fs0","chardev":"chr-vu-fs0","tag":"dir0","bus":"pci.1","addr":"0x0"}: vhost_backend_init failed: Protocol error')
gbraad commented 1 year ago

Which kernel do you run? With standard parameters?

eskuai commented 1 year ago

@gbraad

Be sure, the kernel is a vanilla kernel compiled by me ... fedora 37 and kernel 6.2.9 ... removing most "debug" options from kernel config ... 

cat /etc/default/grub
GRUB_TIMEOUT=8
GRUB_DISTRIBUTOR="$(sed 's, release .*$,,g' /etc/system-release)"
GRUB_DEFAULT=saved
GRUB_DISABLE_SUBMENU=true
GRUB_TERMINAL_OUTPUT="console"
GRUB_CMDLINE_LINUX="resume=UUID=79079bd3-81dd-4163-a14d-e9c122075a87 rhgb quiet delayacct nohugeiomap udev.log_priority=3 audit=0 transparent_hugepage=never systemd.unified_cgroup_hierarchy=1 cgroup_no_v1=all selinux=0 mitigations=off retbleed=off amd_pstate.shared_mem=1 nowatchdog  rd.driver.pre=vfio-pci iommu=pt "
GRUB_DISABLE_RECOVERY="true"
GRUB_ENABLE_BLSCFG=true
GRUB_HIDDEN_TIMEOUT_QUIET=false

Yes, removed the debug options ... in a minute, I'll restart using 6.2.8-200.fc37.x86_64.img

gbraad commented 1 year ago 
$ rpm -qa | grep kernel
kernel-6.1.14-200.fc37.x86_64
$ cat /etc/default/grub
GRUB_CMDLINE_LINUX="resume=/dev/mapper/system-swap00 rd.lvm.lv=system/root00 rd.lvm.lv=system/swap00 rhgb quiet"
$ uname -na
Linux ncentre 6.1.14-200.fc37.x86_64 #1 SMP PREEMPT_DYNAMIC Sun Feb 26 00:13:26 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

This is what I would expect as a standard distro provided kernel. If you compile your own kernel, we can not provide support for this.

eskuai commented 1 year ago 
rpm -qa | grep kernel
kernel-srpm-macros-1.0-15.fc37.noarch
libreport-plugin-kerneloops-2.17.4-1.fc37.x86_64
abrt-addon-kerneloops-2.15.1-6.fc37.x86_64
kernel-core-6.1.18-200.fc37.x86_64
kernel-modules-6.1.18-200.fc37.x86_64
kernel-6.1.18-200.fc37.x86_64
kernel-modules-extra-6.1.18-200.fc37.x86_64
kernel-devel-6.1.18-200.fc37.x86_64
kernel-modules-core-6.2.7-200.fc37.x86_64
kernel-core-6.2.7-200.fc37.x86_64
kernel-modules-6.2.7-200.fc37.x86_64
kernel-tools-libs-6.2.6-200.fc37.x86_64
kernel-tools-6.2.6-200.fc37.x86_64
kernel-6.2.7-200.fc37.x86_64
kernel-modules-extra-6.2.7-200.fc37.x86_64
kernel-headers-6.2.6-200.fc37.x86_64
kernel-devel-6.2.7-200.fc37.x86_64
kernel-modules-core-6.2.8-200.fc37.x86_64
kernel-core-6.2.8-200.fc37.x86_64
kernel-modules-6.2.8-200.fc37.x86_64
kernel-6.2.8-200.fc37.x86_64
kernel-modules-extra-6.2.8-200.fc37.x86_64
kernel-devel-6.2.8-200.fc37.x86_64

<..>

cat /etc/default/grub
GRUB_TIMEOUT=8
GRUB_DISTRIBUTOR="$(sed 's, release .*$,,g' /etc/system-release)"
GRUB_DEFAULT=saved
GRUB_DISABLE_SUBMENU=true
GRUB_TERMINAL_OUTPUT="console"
GRUB_CMDLINE_LINUX="resume=UUID=79079bd3-81dd-4163-a14d-e9c122075a87 rhgb quiet delayacct nohugeiomap udev.log_priority=3 audit=0 transparent_hugepage=never systemd.unified_cgroup_hierarchy=1 cgroup_no_v1=all selinux=0 mitigations=off retbleed=off amd_pstate.shared_mem=1 nowatchdog  rd.driver.pre=vfio-pci iommu=pt "
GRUB_DISABLE_RECOVERY="true"
GRUB_ENABLE_BLSCFG=true
GRUB_HIDDEN_TIMEOUT_QUIET=false

<..>

uname -na
Linux darkstar 6.2.9 #7 SMP PREEMPT_DYNAMIC Thu Mar 30 13:33:47 CEST 2023 x86_64 x86_64 x86_64 GNU/Linux
gbraad commented 1 year ago

mitigations=off retbleed=off

I understand you are about performance, however we are about consistency and a secure environment. We do not test with these kind of changes.

gbraad commented 1 year ago

@jsliacan No need to verify this for now; non-standard setup

eskuai commented 1 year ago

mitigations=off retbleed=off

I understand you are about performance, however we are about consistency and a secure environment. We do not test with these kind of changes.

Just think, that I am java programmer, learning k8s-oc ... That's my own pc... but to-do, remove it from grub ... Ok ... testing fedora standard kernel ...

I got a fedora stardand vagrant image to test ...

gbraad commented 1 year ago

I understand, but supporting custom setups is an unmaintainable situation for us. We have to test against multiple systems, including Windows, MacOS, different versions of them, and several Linux distros. We have settled on the latest version with a standard (OOTB) configuration to confirm our software works.

I got a fedora stardand vagrant image to test ...

Please, do not run a virtual machine on top, as that will result in nested virtualization and this is also not supported due to increased resource usage and possible timing problems for the guest OS.

eskuai commented 1 year ago

@gbraad

Ok, restart using fedora kernel ... you're right, it seems working perfect! [at now]

 crc config view
- consent-telemetry                     : yes
$ crc start 
INFO Checking if running as non-root              
INFO Checking if running inside WSL2              
INFO Checking if crc-admin-helper executable is cached 
INFO Checking if running on a supported CPU architecture 
INFO Checking minimum RAM requirements            
INFO Checking if crc executable symlink exists    
INFO Checking if Virtualization is enabled        
INFO Checking if KVM is enabled                   
INFO Checking if libvirt is installed             
INFO Checking if user is part of libvirt group    
INFO Checking if active user/process is currently part of the libvirt group 
INFO Checking if libvirt daemon is running        
INFO Checking if a supported libvirt version is installed 
INFO Checking if crc-driver-libvirt is installed  
INFO Checking crc daemon systemd socket units     
INFO Checking if systemd-networkd is running      
INFO Checking if NetworkManager is installed      
INFO Checking if NetworkManager service is running 
INFO Checking if dnsmasq configurations file exist for NetworkManager 
INFO Checking if the systemd-resolved service is running 
INFO Checking if /etc/NetworkManager/dispatcher.d/99-crc.sh exists 
INFO Checking if libvirt 'crc' network is available 
INFO Checking if libvirt 'crc' network is active  
INFO Loading bundle: crc_libvirt_4.12.5_amd64...  
INFO Starting CRC VM for openshift 4.12.5...      
INFO CRC instance is running with IP 192.168.130.11 
INFO CRC VM is running                            
INFO Updating authorized keys...                  
INFO Configuring shared directories               
INFO Check internal and public DNS query...       
INFO Check DNS query from host...                 
INFO Verifying validity of the kubelet certificates... 
INFO Starting kubelet service                     
INFO Waiting for kube-apiserver availability... [takes around 2min]

So sorry by my mistake.. I dont think that it could be a kernel config issue ... minishift , minikube ... work ok ..

Next time, try to boot with debug mode, I'll make a diff. .. what is the change?

Tx

gbraad commented 1 year ago

kernel config issue

sorry, but it actually looks like it. Seccomp is a security framework that is part of the kernel, hence my questions directly pointing at this. Virtiofsd might trigger a certain path that does not work correctly, as this is a driver for the filesharing between the VM and the host (which uses the kernel's virtio). This is not something Minishift or minikube uses (we worked on these before).

what is the change?

Since virtio-fs relies on seccomp, as also stated here:

* The ability to invoke syscalls is limited using seccomp(2).
* Linux capabilities(7) are dropped.

check if your kernel config has 'seccomp' included. This might have been turned off due to overzealous performance reasons? ;-)

gbraad commented 1 year ago

Marking as invalid as works with standard F37 configuration.

eskuai commented 1 year ago

FYI,

Something running in :

DEBU (crc) DBG --- msg="GetIP called for crc"

My mistake:

DEBU Updating CRC VM configuration
DEBU (crc) Calling .GetConfigRaw
DEBU (crc) Calling .Start
DEBU (crc) DBG | time="2023-04-04T18:15:46+02:00" level=debug msg="Starting VM crc"
DEBU (crc) DBG | time="2023-04-04T18:15:46+02:00" level=debug msg="Validating network"
DEBU (crc) DBG | time="2023-04-04T18:15:46+02:00" level=debug msg="Validating storage pool"
DEBU (crc) DBG | time="2023-04-04T18:15:46+02:00" level=warning msg="Failed to start: virError(Code=1, Domain=10, Message='internal error: qemu unexpectedly closed the monitor: 2023-04-04T16:15:46.308870Z qemu-system-x86_64: -device {\"driver\":\"vhost-user-fs-pci\",\"id\":\"fs0\",\"chardev\":\"chr-vu-fs0\",\"tag\":\"dir0\",\"bus\":\"pci.1\",\"addr\":\"0x0\"}: Failed to write msg. Wrote -1 instead of 12.\n2023-04-04T16:15:46.308890Z qemu-system-x86_64: -device {\"driver\":\"vhost-user-fs-pci\",\"id\":\"fs0\",\"chardev\":\"chr-vu-fs0\",\"tag\":\"dir0\",\"bus\":\"pci.1\",\"addr\":\"0x0\"}: vhost_backend_init failed: Protocol error')"
DEBU Making call to close driver server

<..>

virtio_session_mount: Waiting for vhost-user socket connection...
virtio_session_mount: Received vhost-user socket connection
seccomp_init() failed

fedora kernel:

INFO Starting CRC VM for openshift 4.12.5...      
DEBU Updating CRC VM configuration                
DEBU (crc) Calling .GetConfigRaw                  
DEBU (crc) Calling .Start                         
DEBU (crc) DBG | time="2023-04-04T18:25:44+02:00" level=debug msg="Starting VM crc" 
DEBU (crc) DBG | time="2023-04-04T18:25:44+02:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2023-04-04T18:25:44+02:00" level=debug msg="Validating storage pool" 
DEBU (crc) DBG | time="2023-04-04T18:25:50+02:00" level=debug msg="GetIP called for crc" 
DEBU (crc) DBG | time="2023-04-04T18:25:50+02:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2023-04-04T18:25:50+02:00" level=debug msg="IP address: 192.168.130.11" 
DEBU (crc) DBG | time="2023-04-04T18:25:50+02:00" level=info msg="Found IP for machine: 192.168.130.11" 
DEBU (crc) Calling .GetConfigRaw

<..>

virtio_session_mount: Waiting for vhost-user socket connection...
virtio_session_mount: Received vhost-user socket connection
virtio_loop: Entry
fv_queue_set_started: qidx=0 started=1
fv_queue_set_started: qidx=1 started=1
fv_queue_thread: Start for queue 0 kick_fd 10
fv_queue_thread: Start for queue 1 kick_fd 13
eskuai commented 1 year ago

@gbraad

And again, you're right, ... Enable seccomp to safely execute untrusted bytecode (SECCOMP) - N - Ok, TO-DO .. enable it , compile and test ...

eskuai commented 1 year ago

FYI @gbraad Ok, ...

uname -a Linux darkstar 6.2.9 #8 SMP PREEMPT_DYNAMIC Tue Apr 4 18:56:10 CEST 2023 x86_64 x86_64 x86_64 GNU/Linux

`Enable seccomp to safely execute untrusted bytecode (SECCOMP) - Y -

And ...

DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2023-04-04T18:59:04+02:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2023-04-04T18:59:04+02:00" level=debug msg="Fetching VM..." 
INFO Starting CRC VM for openshift 4.12.5...      
DEBU Updating CRC VM configuration                
DEBU (crc) Calling .GetConfigRaw                  
DEBU (crc) Calling .Start                         
DEBU (crc) DBG | time="2023-04-04T18:59:04+02:00" level=debug msg="Starting VM crc" 
DEBU (crc) DBG | time="2023-04-04T18:59:04+02:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2023-04-04T18:59:04+02:00" level=debug msg="Validating storage pool" 
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="GetIP called for crc" 
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="IP address: 192.168.130.11" 
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=info msg="Found IP for machine: 192.168.130.11" 
DEBU (crc) Calling .GetConfigRaw                  
DEBU Waiting for machine to be running, this may take a few minute`s... 
DEBU retry loop: attempt 0                        
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="Getting current state..." 
DEBU Machine is up and running!                   
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="Getting current state..." 
DEBU (crc) Calling .GetIP                         
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="GetIP called for crc" 
DEBU (crc) DBG | time="2023-04-04T18:59:09+02:00" level=debug msg="Getting current state..."

OMG!

DEBU Unexpected operator status for ingress: EvaluationConditionsDetected 
DEBU openshift-apiserver operator not available, Reason: APIServices_Error 
INFO Operator openshift-apiserver is not yet available 
DEBU Unexpected operator status for ingress: EvaluationConditionsDetected 
INFO All operators are available. Ensuring stability... 
DEBU Unexpected operator status for ingress: EvaluationConditionsDetected 
INFO Operators are stable (2/3)...                
DEBU Unexpected operator status for ingress: EvaluationConditionsDetected 
INFO Operators are stable (3/3)...                
DEBU Cluster took 6m30.511855245s to stabilize    
INFO Adding crc-admin and crc-developer contexts to kubeconfig... 
DEBU Making call to close driver server           
DEBU (crc) Calling .Close                         
DEBU Successfully made call to close driver server 
DEBU Making call to close connection to plugin binary 
Started the OpenShift cluster.

The server is accessible via web console at:
  https://console-openshift-console.apps-crc.testing

Log in as administrator:
  Username: kubeadmin
  Password: xxxxxx

Log in as user:
  Username: developer
  Password: developer

Use the 'oc' command line interface:
  $ eval $(crc oc-env)
  $ oc login -u developer https://api.crc.testing:6443
gbraad commented 1 year ago

Thank you for the feedback. Glad it works