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.26k stars 242 forks source link

[BUG] [Fedora40][OKD] OpenShift cluster becomes Unreachable #4234

Open souovan opened 5 months ago

souovan commented 5 months ago

General information

CRC version

CRC version: 2.37.1+36d451
OpenShift version: 4.15.14

CRC status

CRC VM:          Running
OpenShift:       Unreachable (v4.15.0-0.okd-2024-02-23-163410)
RAM Usage:       647MB of 10.95GB
Disk Usage:      21.48GB of 32.68GB (Inside the CRC VM)
Cache Usage:     27.69GB
Cache Directory: /home/van/.crc/cache

CRC config

- consent-telemetry                     : yes
- preset                                : okd

Host Operating System

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

Steps to reproduce

  1. Run crc setup
  2. Run crc start
  3. Get Error running post start: Executing systemctl action failed: ssh command error: command : sudo systemctl enable dnsmasq.service err : Process exited with status 1 : Failed to enable unit: Unit file /etc/systemd/system/dnsmasq.service is masked.
  4. Run systemctl unmask dnsmasq.service
  5. Run crc start again
  6. Get 
    
INFO A CRC VM for OKD 4.15.0-0.okd-2024-02-23-163410 is already running 
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: PHX79-zmtbm-9PPmT-I9JMB

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

NOTE: This cluster was built from OKD - The Community Distribution of Kubernetes that powers Red Hat OpenShift. If you find an issue, please report it at https://github.com/openshift/okd

  7. Run `eval $(crc oc-env)`

### Expected
Access the oc CLI and the OKD Web Console

### Actual
When i run `oc login -u developer https://api.crc.testing:6443` i get:

error: dial tcp 192.168.130.11:6443: connect: connection refused - verify you have provided the correct host and port and that the server is currently running.


And aren't able to access the OKD Web Console

![image](https://github.com/crc-org/crc/assets/42985246/0079d26d-86e7-4866-b59e-c1a25a49e40a)

### Logs when i ssh to the running crc VM

van@fedora:~$ crc ip 192.168.130.11 van@fedora:~$ ssh -i ~/.crc/machines/crc/id_ecdsa -o StrictHostKeyChecking=no core@192.168.130.11


i get:

Fedora CoreOS 39.20240128.3.0 Tracker: https://github.com/coreos/fedora-coreos-tracker Discuss: https://discussion.fedoraproject.org/tag/coreos

Last login: Fri Jun 14 18:49:51 2024 from 192.168.130.1 [systemd] Failed Units: 1 qemu-guest-agent.service


Then `root@crc:~# systemctl status qemu-guest-agent.service`

× qemu-guest-agent.service - QEMU Guest Agent Loaded: loaded (/etc/systemd/system/qemu-guest-agent.service; enabled; preset: enabled) Drop-In: /usr/lib/systemd/system/service.d └─10-timeout-abort.conf Active: failed (Result: exit-code) since Fri 2024-06-14 18:41:41 UTC; 9min ago Duration: 3ms Process: 1159 ExecStart=/usr/bin/qemu-ga --method=vsock-listen --path=3:1234 --blacklist=${BLACKLIST_RPC} -F${FSFREEZE_HOOK_PATHNAME} (code=exited, status=1/FAILURE) Main PID: 1159 (code=exited, status=1/FAILURE) CPU: 2ms

Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Scheduled restart job, restart counter is at 5. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Start request repeated too quickly. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: Failed to start qemu-guest-agent.service - QEMU Guest Agent.


Then `journalctl -u qemu-guest-agent.service --since 18:38:30`

Jun 14 18:41:41 crc systemd[1]: Started qemu-guest-agent.service - QEMU Guest Agent. Jun 14 18:41:41 crc (qemu-ga)[1015]: qemu-guest-agent.service: Referenced but unset environment variable evaluates to an empty string: BLACKLIST_RPC Jun 14 18:41:41 crc qemu-ga[1015]: 1718390501.650499: critical: Failed to create socket: Address family not supported by protocol Jun 14 18:41:41 crc qemu-ga[1015]: 1718390501.650536: critical: failed to create guest agent channel Jun 14 18:41:41 crc qemu-ga[1015]: 1718390501.650538: critical: failed to initialize guest agent channel Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Main process exited, code=exited, status=1/FAILURE Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Scheduled restart job, restart counter is at 1. Jun 14 18:41:41 crc systemd[1]: Started qemu-guest-agent.service - QEMU Guest Agent. Jun 14 18:41:41 crc (qemu-ga)[1071]: qemu-guest-agent.service: Referenced but unset environment variable evaluates to an empty string: BLACKLIST_RPC Jun 14 18:41:41 crc qemu-ga[1071]: 1718390501.753307: critical: Failed to create socket: Address family not supported by protocol Jun 14 18:41:41 crc qemu-ga[1071]: 1718390501.754795: critical: failed to create guest agent channel Jun 14 18:41:41 crc qemu-ga[1071]: 1718390501.754799: critical: failed to initialize guest agent channel Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Main process exited, code=exited, status=1/FAILURE Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Scheduled restart job, restart counter is at 2. Jun 14 18:41:41 crc systemd[1]: Started qemu-guest-agent.service - QEMU Guest Agent. Jun 14 18:41:41 crc (qemu-ga)[1115]: qemu-guest-agent.service: Referenced but unset environment variable evaluates to an empty string: BLACKLIST_RPC Jun 14 18:41:41 crc qemu-ga[1115]: 1718390501.814844: critical: Failed to create socket: Address family not supported by protocol Jun 14 18:41:41 crc qemu-ga[1115]: 1718390501.815354: critical: failed to create guest agent channel Jun 14 18:41:41 crc qemu-ga[1115]: 1718390501.815373: critical: failed to initialize guest agent channel Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Main process exited, code=exited, status=1/FAILURE Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Scheduled restart job, restart counter is at 3. Jun 14 18:41:41 crc systemd[1]: Started qemu-guest-agent.service - QEMU Guest Agent. Jun 14 18:41:41 crc (qemu-ga)[1145]: qemu-guest-agent.service: Referenced but unset environment variable evaluates to an empty string: BLACKLIST_RPC Jun 14 18:41:41 crc qemu-ga[1145]: 1718390501.840374: critical: Failed to create socket: Address family not supported by protocol Jun 14 18:41:41 crc qemu-ga[1145]: 1718390501.840388: critical: failed to create guest agent channel Jun 14 18:41:41 crc qemu-ga[1145]: 1718390501.840390: critical: failed to initialize guest agent channel Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Main process exited, code=exited, status=1/FAILURE Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Scheduled restart job, restart counter is at 4. Jun 14 18:41:41 crc systemd[1]: Started qemu-guest-agent.service - QEMU Guest Agent. Jun 14 18:41:41 crc (qemu-ga)[1159]: qemu-guest-agent.service: Referenced but unset environment variable evaluates to an empty string: BLACKLIST_RPC Jun 14 18:41:41 crc qemu-ga[1159]: 1718390501.866131: critical: Failed to create socket: Address family not supported by protocol Jun 14 18:41:41 crc qemu-ga[1159]: 1718390501.866145: critical: failed to create guest agent channel Jun 14 18:41:41 crc qemu-ga[1159]: 1718390501.866147: critical: failed to initialize guest agent channel Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Main process exited, code=exited, status=1/FAILURE Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Scheduled restart job, restart counter is at 5. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Start request repeated too quickly. Jun 14 18:41:41 crc systemd[1]: qemu-guest-agent.service: Failed with result 'exit-code'. Jun 14 18:41:41 crc systemd[1]: Failed to start qemu-guest-agent.service - QEMU Guest Agent. lines 16-43/43 (END)


Then i run:

root@crc:~# podman ps CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 74e5ad82fc3e quay.io/crcont/gvisor-tap-vsock:latest 3 months ago Up 14 minutes gvisor-tap-vsock root@crc:~# podman logs 74e5ad82fc3e


And get:

... ERRO[0889] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0890] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0891] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0892] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0893] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0894] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0895] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0896] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0897] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0898] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0899] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0900] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0901] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0902] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0903] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0904] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer ERRO[0905] cannot connect to host: dial vsock host(2):1024: connect: connection reset by peer



Apreciate help and any hint where to continue debbuging this issue
cfergeau commented 5 months ago

You could try a crc stop before retrying crc start, but not sure it will be enough. When there's an error during initial startup, crc is not very good at recovering :-/ You could try adding the needed unmask in pkg/crc/services/dns/dns.go before it tries to start dnsmasq, and see if this helps.

praveenkumar commented 5 months ago

@souovan when using the system mode networking then qemu-guest-agent.service can be ignored because it use vsock-listen method which is only part of user mode networking. I would be more interested in the start/status logs. Can you try following and share the details?

$ crc delete
$ crc setup --log-level debug
$ crc start --log-level debug
$ crc status --log-level debug
cfergeau commented 5 months ago

it uses vsock-listen method which is only part of user mode networking.

For what it's worth, it should relatively easy to add vsock support to the VM on linux https://libvirt.org/formatdomain.html#vsock Or we could at least add ConditionVirtualization=apple to qemu-guest-agent unit file since we only need it on macOS.

cfergeau commented 5 months ago

Or we could at least add ConditionVirtualization=apple to qemu-guest-agent unit file since we only need it on macOS.

I tried this in https://github.com/crc-org/snc/pull/914

SGT911 commented 3 months ago

Hi @souovan, a temporal fix to use OKD ~4.15 is unmasking the dnsmasq after first crc start error and restart the VM with crc stop and crc start.

crc setup
crc start
# Wait for the dnsmasq error

ssh -i ~/.crc/machines/crc/id_ecdsa -o StrictHostKeyChecking=no core@$(crc ip)
# In the ssh connection run the following commands
sudo systemctl unmask dnsmasq.service
sudo systemctl stop qemu-guest-agent.service
sudo systemctl disable qemu-guest-agent.service
exit # Exit from the ssh connection

crc stop
crc start
praveenkumar commented 3 months ago

Inside the VM dnsmasq service is not masked so I am not sure why it need to unmask.

AlexStorm1313 commented 3 weeks ago

@souovan when using the system mode networking then qemu-guest-agent.service can be ignored because it use vsock-listen method which is only part of user mode networking. I would be more interested in the start/status logs. Can you try following and share the details?

$ crc delete
$ crc setup --log-level debug
$ crc start --log-level debug
$ crc status --log-level debug

I'm running into the same issue on fedora. Here are some logs I can provide. I also tried unmasking, enabling and starting dnsmasq.service myself which works without errors.

crc setup --log-level debug

DEBU OpenShift version: 4.17.1                    
DEBU MicroShift version: 4.17.1                   
DEBU Running 'crc setup'                          
INFO Using bundle path /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64.crcbundle 
DEBU resolv.conf file path: /run/systemd/resolve/stub-resolv.conf 
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/my_username/.crc/bin/crc-admin-helper-linux-amd64 --version' 
DEBU Found crc-admin-helper-linux-amd64 version 0.5.4 
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 if crc executable symlink exists    
INFO Checking minimum RAM requirements            
DEBU Total memory of system is 63179808768 bytes  
INFO Check if Podman binary exists in: /home/my_username/.crc/bin/oc 
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 >=8.0.0       
DEBU Running 'virsh -v'                           
INFO Checking if crc-driver-libvirt is installed  
DEBU Checking if crc-driver-libvirt-amd64 is installed 
DEBU Running '/home/my_username/.crc/bin/crc-driver-libvirt-amd64 version' 
DEBU Found crc-driver-libvirt-amd64 version 0.13.9 
DEBU crc-driver-libvirt-amd64 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 crc-daemon.service is running                
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 running                   
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 running                  
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)
    Drop-In: /usr/lib/systemd/system/service.d
             `-10-timeout-abort.conf
     Active: inactive (dead)
TriggeredBy: * systemd-networkd.socket
       Docs: man:systemd-networkd.service(8)
             man:org.freedesktop.network1(5)
   FD Store: 0 (limit: 512) 
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 resolv.conf file path: /run/systemd/resolve/stub-resolv.conf 
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/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64.crcbundle exists 
DEBU /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64.crcbundle exists 
Your system is correctly setup for using CRC. Use 'crc start' to start the instance

crc start --log-level debug

DEBU OpenShift version: 4.17.1                    
DEBU MicroShift version: 4.17.1                   
DEBU Running 'crc start'                          
DEBU Total memory of system is 63179808768 bytes  
DEBU No new version available. The latest version is 2.43.0 
DEBU Checking file: /home/my_username/.crc/machines/crc/.crc-exist 
INFO Using bundle path /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64.crcbundle 
DEBU resolv.conf file path: /run/systemd/resolve/stub-resolv.conf 
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/my_username/.crc/bin/crc-admin-helper-linux-amd64 --version' 
DEBU Found crc-admin-helper-linux-amd64 version 0.5.4 
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 if crc executable symlink exists    
INFO Checking minimum RAM requirements            
DEBU Total memory of system is 63179808768 bytes  
INFO Check if Podman binary exists in: /home/my_username/.crc/bin/oc 
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 >=8.0.0       
DEBU Running 'virsh -v'                           
INFO Checking if crc-driver-libvirt is installed  
DEBU Checking if crc-driver-libvirt-amd64 is installed 
DEBU Running '/home/my_username/.crc/bin/crc-driver-libvirt-amd64 version' 
DEBU Found crc-driver-libvirt-amd64 version 0.13.9 
DEBU crc-driver-libvirt-amd64 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 running                   
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 running                  
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)
    Drop-In: /usr/lib/systemd/system/service.d
             `-10-timeout-abort.conf
     Active: inactive (dead)
TriggeredBy: * systemd-networkd.socket
       Docs: man:systemd-networkd.service(8)
             man:org.freedesktop.network1(5)
   FD Store: 0 (limit: 512) 
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 resolv.conf file path: /run/systemd/resolve/stub-resolv.conf 
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/my_username/.crc/machines/crc/.crc-exist 
INFO Loading bundle: crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64... 
INFO Creating CRC VM for OKD 4.15.0-0.okd-2024-02-23-163410... 
DEBU Found binary path at /home/my_username/.crc/bin/crc-driver-libvirt-amd64 
DEBU Launching plugin server for driver libvirt   
DEBU Plugin server listening at address 127.0.0.1:36107 
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="2024-10-31T08:53:01+01:00" level=debug msg="About to check libvirt version" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Validating storage pool" 
DEBU (crc) Calling .GetConfigRaw                  
DEBU Creating machine...                          
DEBU (crc) Calling .Create                        
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Preparing /home/my_username/.crc/machines/crc/crc.qcow2 for machine use" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="image creation took 25.367509ms" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Verifying executable bit set on /home/my_username/.crc/machines/crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Setting executable bit set on /home/my_username/.crc/machines/crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Verifying executable bit set on /home/my_username/.crc/machines" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Verifying executable bit set on /home/my_username/.crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Verifying executable bit set on /home/my_username" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Verifying executable bit set on /home" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Defining VM..." 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Found x86_64 hypervisor with 'hvm' capabilities" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Found q35 machine type" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Found x86_64 hypervisor with 'hvm' capabilities" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Found q35 machine type" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01: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/my_username/.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 Checking file: /home/my_username/.crc/machines/crc/.crc-exist 
DEBU Found binary path at /home/my_username/.crc/bin/crc-driver-libvirt-amd64 
DEBU Launching plugin server for driver libvirt   
DEBU Plugin server listening at address 127.0.0.1:45195 
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="2024-10-31T08:53:01+01:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Fetching VM..." 
INFO Starting CRC VM for okd 4.15.0-0.okd-2024-02-23-163410... 
DEBU Updating CRC VM configuration                
DEBU (crc) Calling .GetConfigRaw                  
DEBU (crc) Calling .Start                         
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Starting VM crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Validating network" 
DEBU (crc) DBG | time="2024-10-31T08:53:01+01:00" level=debug msg="Validating storage pool" 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="GetIP called for crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="IP address: 192.168.130.11" 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01: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 minutes... 
DEBU retry loop: attempt 0                        
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="Getting current state..." 
DEBU Machine is up and running!                   
DEBU (crc) Calling .GetState                      
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="Getting current state..." 
DEBU (crc) Calling .GetIP                         
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="GetIP called for crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="IP address: 192.168.130.11" 
INFO CRC instance is running with IP 192.168.130.11 
DEBU (crc) Calling .GetIP                         
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="GetIP called for crc" 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="Getting current state..." 
DEBU (crc) DBG | time="2024-10-31T08:53:06+01:00" level=debug msg="IP address: 192.168.130.11" 
DEBU Waiting until ssh is available               
DEBU retry loop: attempt 0                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: dial tcp 192.168.130.11:22: connect: no route to host, output:  
DEBU error: Temporary error: ssh command error:
command : exit 0
err     : dial tcp 192.168.130.11:22: connect: no route to host
 - sleeping 1s 
DEBU retry loop: attempt 1                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: dial tcp 192.168.130.11:22: connect: no route to host, output:  
DEBU error: Temporary error: ssh command error:
command : exit 0
err     : dial tcp 192.168.130.11:22: connect: no route to host
 - sleeping 1s 
DEBU retry loop: attempt 2                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: dial tcp 192.168.130.11:22: connect: no route to host, output:  
DEBU error: Temporary error: ssh command error:
command : exit 0
err     : dial tcp 192.168.130.11:22: connect: no route to host
 - sleeping 1s 
DEBU retry loop: attempt 3                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: dial tcp 192.168.130.11:22: connect: no route to host, output:  
DEBU error: Temporary error: ssh command error:
command : exit 0
err     : dial tcp 192.168.130.11:22: connect: no route to host
 - sleeping 1s 
DEBU retry loop: attempt 4                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: dial tcp 192.168.130.11:22: connect: no route to host, output:  
DEBU error: Temporary error: ssh command error:
command : exit 0
err     : dial tcp 192.168.130.11:22: connect: no route to host
 - sleeping 1s 
DEBU retry loop: attempt 5                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: dial tcp 192.168.130.11:22: connect: no route to host, output:  
DEBU error: Temporary error: ssh command error:
command : exit 0
err     : dial tcp 192.168.130.11:22: connect: no route to host
 - sleeping 1s 
DEBU retry loop: attempt 6                        
DEBU Running SSH command: exit 0                  
DEBU Using ssh private keys: [/home/my_username/.crc/machines/crc/id_ed25519 /home/my_username/.crc/cache/crc_okd_libvirt_4.15.0-0.okd-2024-02-23-163410_amd64/id_ecdsa_crc] 
DEBU SSH command results: err: <nil>, output:     
INFO CRC VM is running                            
DEBU Using root access: disable core user password 
DEBU Running SSH command: sudo passwd --lock core 
DEBU SSH command results: err: <nil>, output: Locking password for user core.
passwd: Success 
DEBU Running SSH command: cat /home/core/.ssh/authorized_keys 
DEBU SSH command results: err: Process exited with status 1, output:  
INFO Updating authorized keys...                  
DEBU Creating /home/core/.ssh/authorized_keys with permissions 0644 in the CRC VM 
DEBU Running SSH command: <hidden>                
DEBU SSH command succeeded                        
DEBU Running SSH command: rm /home/core/.ssh/authorized_keys.d/ignition 
DEBU SSH command results: err: <nil>, output:     
DEBU Using root access: Get device id             
DEBU Running SSH command: sudo /usr/sbin/blkid -t TYPE=xfs -o device 
DEBU SSH command results: err: <nil>, output: /dev/vda4 
DEBU Using root access: Growing /dev/vda4 partition 
DEBU Running SSH command: sudo /usr/bin/growpart /dev/vda 4 
DEBU SSH command results: err: Process exited with status 1, output: NOCHANGE: partition 4 is size 63961055. it cannot be grown 
DEBU No free space after /dev/vda4, nothing to do 
DEBU Configuring shared directories               
DEBU (crc) Calling .GetSharedDirs                 
DEBU (crc) DBG | time="2024-10-31T08:53:34+01:00" level=debug msg="Found x86_64 hypervisor with 'hvm' capabilities" 
DEBU (crc) DBG | time="2024-10-31T08:53:34+01:00" level=debug msg="Found q35 machine type" 
INFO Configuring shared directories               
DEBU Using root access: Creating /home/my_username 
DEBU Running SSH command: sudo mkdir -p /home/my_username 
DEBU SSH command results: err: <nil>, output:     
DEBU Mounting tag dir0 at /home/my_username       
DEBU Using root access: Mounting /home/my_username 
DEBU Running SSH command: sudo mount -o context="system_u:object_r:container_file_t:s0" -t virtiofs dir0 /home/my_username 
DEBU SSH command results: err: <nil>, output:     
DEBU Using root access: make root Podman socket accessible 
DEBU Running SSH command: sudo chmod 777 /run/podman/ /run/podman/podman.sock 
DEBU SSH command results: err: <nil>, output:     
DEBU Creating /etc/dnsmasq.d/crc-dnsmasq.conf with permissions 0644 in the CRC VM 
DEBU Running SSH command: <hidden>                
DEBU SSH command succeeded                        
DEBU Running SSH command: systemctl status dnsmasq.service 
DEBU SSH command results: err: Process exited with status 3, output: ○ dnsmasq.service
     Loaded: masked (Reason: Unit dnsmasq.service is masked.)
    Drop-In: /usr/lib/systemd/system/service.d
             └─10-timeout-abort.conf
     Active: inactive (dead) 
DEBU Using root access: Executing systemctl enable dnsmasq.service 
DEBU Running SSH command: sudo systemctl enable dnsmasq.service 
DEBU SSH command results: err: Process exited with status 1, output:  
DEBU Making call to close driver server           
DEBU (crc) Calling .Close                         
DEBU (crc) DBG | time="2024-10-31T08:53:34+01: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 running post start: Executing systemctl action failed:  ssh command error:
command : sudo systemctl enable dnsmasq.service
err     : Process exited with status 1
: Failed to enable unit: Unit file /etc/systemd/system/dnsmasq.service is masked.

crc status --log-level debug

DEBU OpenShift version: 4.17.1                    
DEBU MicroShift version: 4.17.1                   
DEBU Running 'crc status'                         
CRC VM:          Running
OpenShift:       Unreachable (v4.15.0-0.okd-2024-02-23-163410)
RAM Usage:       626.8MB of 10.95GB
Disk Usage:      21.48GB of 32.68GB (Inside the CRC VM)
Cache Usage:     27.69GB
Cache Directory: /home/my_username/.crc/cache
AlexStorm1313 commented 3 weeks ago

Hi @souovan, a temporal fix to use OKD ~4.15 is unmasking the dnsmasq after first crc start error and restart the VM with crc stop and crc start.


crc start
# Wait for the dnsmasq error

ssh -i ~/.crc/machines/crc/id_ecdsa -o StrictHostKeyChecking=no core@$(crc ip)
# In the ssh connection run the following commands
sudo systemctl unmask dnsmasq.service
sudo systemctl stop qemu-guest-agent.service
sudo systemctl disable qemu-guest-agent.service
exit # Exit from the ssh connection

crc stop
crc start```

This seems to work. Not sure if disabling the qemu-guest agent has any impact. for some reason the dnsmasq.service is masked inside the VM

praveenkumar commented 2 weeks ago

@AlexStorm1313 Are you using crc with OKD bundle?

AlexStorm1313 commented 2 weeks ago

@praveenkumar Yes that's correct.