VM turns on and off repeatedly without getting anything built

[hgl]

After the configuration has been successfully activated with just enable = true, changing any option (e.g., debug = true, or rosetta = true), and activating it, the command line hangs at

connecting to ssh-ng://virby-vm

and Actity Monitor shows a Virtualization.framework process, running 800% for about a couple minutes and then gets terminated and then starts again, rinse and repeat.

Mean while, the command line keeps hanging at the same place.

Any idea how I can solve this?

I can’t enable debug because of this.

[hgl]

I manually enabled writing stdout to a file and found out the vm got into this loop:

[2025-08-19 13:47:55] INFO: Starting VM...
2025-08-19 13:47:55,534 - virby_vm_runner.vm_process - INFO - Cleaned up orphaned vfkit process
2025-08-19 13:47:55,537 - virby_vm_runner.socket_activation - INFO - Found launchd socket on FD 6, bound to ('127.0.0.1', 31222)
2025-08-19 13:47:55,537 - virby_vm_runner.runner - INFO - Starting VM
2025-08-19 13:47:55,537 - virby_vm_runner.vm_process - INFO - Starting Virby VM...
2025-08-19 13:47:55,537 - virby_vm_runner.vm_process - INFO - Starting VM with command: vfkit --cpus 8 --memory 6144 --bootloader efi,variable-store=/var/lib/virby/efistore.nvram,create --device virtio-blk,path=/var/lib/virby/diff.img --device virtio-fs,sharedDir=/var/lib/virby/vm_sshd_keys,mountTag=sshd-keys --device virtio-net,nat,mac=02:94:e0:5a:4c:de --restful-uri tcp://localhost:31223 --device virtio-rng --device virtio-balloon
2025-08-19 13:47:55,543 - virby_vm_runner.vm_process - INFO - VM started with PID 10168
2025-08-19 13:47:55,544 - virby_vm_runner.vm_process - INFO - Discovering VM IP address...
2025-08-19 13:48:56,700 - virby_vm_runner.vm_process - ERROR - Failed to start VM: Failed to discover VM IP within 60 seconds
2025-08-19 13:48:56,701 - virby_vm_runner.vm_process - INFO - Stopping VM...
2025-08-19 13:48:56,701 - virby_vm_runner.vm_process - INFO - Sent SIGTERM to VM process 10168
2025-08-19 13:48:56,703 - virby_vm_runner.vm_process - INFO - VM stopped gracefully
2025-08-19 13:48:56,703 - virby_vm_runner.runner - ERROR - VM runner error: Failed to discover VM IP within 60 seconds
2025-08-19 13:48:56,703 - virby_vm_runner.vm_process - INFO - Stopping VM...
2025-08-19 13:48:56,703 - root - ERROR - Fatal error: Failed to discover VM IP within 60 seconds
[2025-08-19 13:48:56] INFO: Starting VM...

[quinneden]

I'm able to reproduce this, although I can't see a Virtualization.framework in Activity Monitor. Obviously there is a bug in always-on mode with SSH, I'm assuming it's related to launchd too. I will debug and try to figure this out. It's possible to enable debugging for virby if you setup linux-builder first so you can build the virby image.

[hgl]

I suspect this is the cause: crc-org/vfkit#242

I'm experimenting with this fix locally: main...hgl:virby-nix-darwin:dhcp

but I'm currently stopped by this error to verify the fix: https://discourse.nixos.org/t/keep-getting-cache-misses-for-nixos-enter/68141

[quinneden]

Yeah, that absolutely is it. I enabled debug logging and it's timing out trying to discover the IP address.

[hgl]

Any idea about the cache miss error I got from nixes-enter?

[quinneden]

Honestly, I'm not exactly sure, but it may be possible that the store path was invalidated, or maybe garbage collected? I don't know too much about how hydra works or how fast the website updates info for paths after garbage collection, but maybe it's no longer available and the info just isn't updated. I would recommend setting up linux-builder while working on a fix, because you'll have to rebuild the image anyway for testing the changes to then networking module.

[hgl]

I copied your CI config and was using GitHub actions to build the image with my own nixpkgs commit.

Will use linux-builder.

[quinneden]

I tested with the added network config from your fork and I am able to SSH in! If you want to open a PR I'd be happy to merge

[hgl]

I can, but strangely it doesn't work for me. I'm still getting the loop logs.

How do you ssh into it? Is it sudo ssh virby-vm? For me it gets stuck at the last line and doesn't show the prompt:

debug1: OpenSSH_10.0p2, OpenSSL 3.5.1 1 Jul 2025
debug1: Reading configuration data /var/root/.ssh/config
debug1: /var/root/.ssh/config line 7: Applying options for *
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Reading configuration data /etc/ssh/ssh_config.d/100-linux-builder.conf
debug1: Reading configuration data /etc/ssh/ssh_config.d/100-nix-darwin.conf
debug1: Reading configuration data /etc/ssh/ssh_config.d/100-virby-vm.conf
debug1: /etc/ssh/ssh_config.d/100-virby-vm.conf line 1: Applying options for virby-vm
debug1: /etc/ssh/ssh_config line 54: Applying options for *
debug1: Control socket "/var/root/.ssh/master-builder@virby-vm:31222" does not exist
debug1: Connecting to localhost [127.0.0.1] port 31222.
debug1: Connection established.
debug1: identity file /var/lib/virby/ssh_user_ed25519_key type 3
debug1: identity file /var/lib/virby/ssh_user_ed25519_key-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_10.0

[quinneden]

Yeah that's the command I use. You ran darwin-rebuild like normal and pulled your modified image in from your cache? Or locally if you built locally.

[quinneden]

Maybe try sudo su then rm -rf /var/lib/virby/*; rm -f /var/lib/virby/.disk-image-store-path and then restart the daemon with sudo launchctl kickstart -k system/org.nixos.virbyd

[quinneden]

Also did you change the flake input to your fork and run nix flake update virby-nix-darwin, and if you're pulling from your own cache, did you enable it/disable virby-nix-darwin.cachix.org?

[hgl]

I build locally, but might have hit my cachix cache, but I don't think that matters.

I tried both activating with enable = false and rm -rf /var/lib/virby/*; rm -f /var/lib/virby/.disk-image-store-path, still get the the loop.

I'm not using your cache. I made my virby-nix-darwin input directly point to my local git clone.

I will send the PR and try your cache.

[quinneden]

That's weird, I guess once the PR is merged we can see if it's still doing it with the CI-built image

[quinneden]

merged: #10