finch vm init fails

[timhammond]

Describe the bug
Running finch vm init fails. I have tried to remove the vm and re run init and it persists. It hangs at INFO[0000] Initializing and starting Finch virtual machine... for 10 mins before failing.

Steps to reproduce
finch vm init --debug
finch vm stop
finch vm remove
finch vm init

This recurs through these steps

Expected behavior
VM should be setup through the init process

Screenshots or logs
`bash-5.2$ finch vm remove
INFO[0000] Removing existing Finch virtual machine...

INFO[0000] Finch virtual machine removed successfully

bash-5.2$ finch vm init --debug
DEBU[0000] Creating limactl command: ARGUMENTS: [ls -f {{.Status}} finch], LIMA_HOME: /Applications/Finch/lima/data
DEBU[0000] Status of virtual machine:
DEBU[0000] Creating limactl command: ARGUMENTS: [sudoers], LIMA_HOME: /Applications/Finch/lima/data
DEBU[0000] Creating limactl command: ARGUMENTS: [start --name=finch /Applications/Finch/os/finch.yaml --tty=false],
LIMA_HOME: /Applications/Finch/lima/data
INFO[0000] Initializing and starting Finch virtual machine...
ERRO[0600] Finch virtual machine failed to start, debug logs: time="2022-12-07T13:58:04-05:00" level=info msg="Terminal is not available, proceeding without opening an editor"
time="2022-12-07T13:58:04-05:00" level=info msg="Starting socket_vmnet daemon for "finch-shared" network"
time="2022-12-07T13:58:04-05:00" level=info msg="Attempting to download the image from "/Applications/Finch/os/Fedora-Cloud-Base-37-1.7.aarch64.qcow2"" digest="sha256:cc8b0f49bc60875a16eef65ad13e0e86ba502ba3585cc51146f11f4182a628c0"
time="2022-12-07T13:58:04-05:00" level=info msg="Downloaded the image from "/Applications/Finch/os/Fedora-Cloud-Base-37-1.7.aarch64.qcow2""
time="2022-12-07T13:58:04-05:00" level=info msg="Attempting to download the nerdctl archive from "https://github.com/containerd/nerdctl/releases/download/v1.0.0/nerdctl-full-1.0.0-linux-arm64.tar.gz\"" digest="sha256:e4c9b9434c88847f4d18f8b84c0d073555e4c949546cfa8a21e719de67afdf70"
time="2022-12-07T13:58:04-05:00" level=info msg="Using cache "/Users/hammondt/Library/Caches/lima/download/by-url-sha256/52a7d0c7ca8453dd643a5e0d2c42dc9a63df630575c30f8a80e48e4a8fde94b0/data""
time="2022-12-07T13:58:05-05:00" level=warning msg="[hostagent] failed to run [/Applications/Finch/lima/bin/qemu-system-aarch64 -M none -netdev help]: stdout="Accelerators supported in QEMU binary:\nhvf\ntcg\n", stderr="qemu-system-aarch64: allocate 1073741824 bytes for jit buffer: Invalid argument\n""
time="2022-12-07T13:58:05-05:00" level=info msg="[hostagent] Starting QEMU (hint: to watch the boot progress, see "/Applications/Finch/lima/data/finch/serial.log")"
time="2022-12-07T13:58:05-05:00" level=info msg="SSH Local Port: 56440"
time="2022-12-07T13:58:05-05:00" level=info msg="[hostagent] Waiting for the essential requirement 1 of 5: "ssh""
time="2022-12-07T13:58:15-05:00" level=info msg="[hostagent] Waiting for the essential requirement 1 of 5: "ssh""
time="2022-12-07T13:58:25-05:00" level=info msg="[hostagent] Waiting for the essential requirement 1 of 5: "ssh""
snipped for brevity, but repeats every 10s
time="2022-12-07T14:08:03-05:00" level=info msg="[hostagent] Waiting for the essential requirement 2 of 5: "user session is ready for ssh""
time="2022-12-07T14:08:04-05:00" level=fatal msg="did not receive an event with the "running" status"
FATA[0600] exit status 1`

Additional context
Mac M1 Pro
Darwin Kernel Version 22.1.0: Sun Oct 9 20:15:09 PDT 2022; root:xnu-8792.41.9~2/RELEASE_ARM64_T6000

[KevinLiAWS]

Hi @timhammond, thank you for your feedback. We are looking into the root cause, meanwhile could you please try the following command to delete these directories/files and see if it works? Thanks.

sudo rm -rf "/Applications/Finch/lima/data/finch/"
sudo rm -rf "/Applications/Finch/lima/data/_config/override.yaml"
sudo rm -rf "/Applications/Finch/lima/data/_config/user"
sudo rm -rf "/Applications/Finch/lima/data/_config/user.pub"
sudo rm -rf "/Applications/Finch/lima/data/_networks/"
sudo rm -rf "/opt/finch/"

[timhammond]

Hi Kevin, No luck with those commands. I did a bit more digging. I found these errors in the Applications/Finch/lima/data/finch/ha.stderr.log

{"level":"info","msg":"Waiting for the essential requirement 1 of 5: \"ssh\"","time":"2022-12-07T19:54:57-05:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-12-07T19:54:57-05:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Applications/Finch/lima/data/_config/user\" -o IdentityFile=\"/Users/hammondt/.ssh/id_ed25519.old\" -o IdentityFile=\"/Users/hammondt/.ssh/id_ed25519\" -o IdentityFile=\"/Users/hammondt/.ssh/id_ed25519.win\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=hammondt -o ControlMaster=auto -o ControlPath=\"/Applications/Finch/lima/data/finch/ssh.sock\" -o ControlPersist=5m -p 64147 127.0.0.1 -- /bin/bash]","time":"2022-12-07T19:54:57-05:00"}
{"level":"debug","msg":"stdout=\"\", stderr=\"hammondt@127.0.0.1: Permission denied (publickey,gssapi-keyex,gssapi-with-mic).\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"hammondt@127.0.0.1: Permission denied (publickey,gssapi-keyex,gssapi-with-mic).\\r\\n\": exit status 255","time":"2022-12-07T19:54:57-05:00"}

I also came across this but it looks like the version included is high enough.

I also moved out my ~/.ssh/config file just in case that was mucking things up.

[timhammond]

@KevinLiAWS I was able to make it work!

I eventually tracked this down to lima-vm/lima#104

I added ssh:loadDotSSHPubKeys:false and then I was able to successfully get the VM to start properly. There must be problematic pub key or something in my .ssh

❯ cat _config/override.yaml
images: []
cpus: 3
memory: 4GiB
ssh:
    loadDotSSHPubKeys: false
networks:
    - lima: finch-shared