Error on first boot after install IncusOS 202601220238 on Proxmox 9.1.4

[fperreau]

Hello happy to test IncusOS before secure software diy NAS on new Orico CyberData - cf56pro

I test the installation on Proxmox 9.1.4 (debian 13.3) with IncusOS 202601220238.iso generated
from https://incusos-customizer.linuxcontainers.org.

1/ Partitioning and deploy from ISO is OK,
2/ But after the reboot without media, I have the repeat error:

INFO Starting application  name=incus  version 202601220238
INFO Application TLS certificate fingerprint fingerprint=.............................
ERROR Failed to parse update frequency err=time: invalid duration ""
ERROR invalid crontab expression

Orico CyberData - cf56pro
12th Gen Intel(R) Core(TM) i51240P
vCPU=host

[fperreau]

I change the cpu from host to x86-64-v3 and trap the first error after a circle of reboot.

INFO Starting application  name=incus  version 202601220238
ERROR Failed to run: systemctl enable --now incus.socket incus-lxcfs.service incus-startup.service incus.service: exit status 1 (job for
incus.service failed because a fatal signal was delivered to the control process.
See "systemctl status incus.service" and "journalctl -xeu incus.service" for details.)

I suppose no way to login ... only 8443/TCP is open and "Connection refused" with wget

[gibmat]

ERROR Failed to parse update frequency err=time: invalid duration ""
ERROR invalid crontab expression

Hmm, it seems almost as if your system is missing its state file, as both the update frequency and scrub crontab are initialized with default values on first boot.

We can manually set those values, which should resolve the errors. First, run incus admin os system update edit, and then set a value of "6h" for the configuration:

config:
  auto_reboot: false
  channel: stable
  check_frequency: 6h

Second, run incus admin os system storage edit and set the scrub schedule:

config:
  scrub_schedule: 0 4 * * 0

I change the cpu from host to x86-64-v3

At the moment there's no actual hard requirement on x86-64-v3, and I don't know why that would be causing an error starting Incus itself. If you change the cpu back to "host", do things start properly?

[gibmat]

Interesting, I just encountered this in a test VM while working on something else. Looks like some sort of a race condition, since I tried the same test setup a couple times and couldn't reproduce the failure.

[lambda-m]

I encountered the same and had claude do a deep research into it and use a deploy script which found the following after many automated deploys and tests on exactly this issue... maybe it helps.

I can reproduce this fairly reliably on Proxmox — about 50% of fresh installs
hit it. Traced it through the source to understand why it's persistent once
triggered.

Setup: Proxmox VE 9.1.5, IncusOS 202602200553, OVMF/q35/cpu=host,
4 GiB RAM, 50 GiB disk, SEED_DATA ISO on ide3 with force_reboot: true.
Automated deploy that captures console screenshots every 2s via
qm monitor screendump, so I can see exactly what IncusOS prints at each
stage.

Ran 6 fresh single-VM deploys (destroy + recreate each time). 3 out of 6
showed the crontab error on first boot. No pattern to which runs fail —
tested with and without update.yaml in the seed, no difference.

What the screenshots show on a failing boot:

The first boot from disk proceeds normally through key generation, network,
update downloads, storage, and application startup. Incus starts and port
8443 comes up. Then immediately after the TLS fingerprint line:

ERROR invalid crontab expression

After the 15-second sleep, systemd restarts the daemon. The second startup
is much faster (everything cached), but crashes again with the same error
within 2 seconds. It keeps looping — the error is permanent for that VM.

Why it's permanent (from the source):

startup() has defer func() { _ = s.Save() }() at the top. When
registerJobs() fails, the deferred save writes the current state back to
disk. The problem is that encodeHelper() in encode.go skips zero
values — if v.IsZero() { return nil }. So if ScrubSchedule is empty
at this point, it simply doesn't get written to state.txt.

The file is saved as version 7, but without a ScrubSchedule line. On the
next daemon start, LoadOrCreate() reads version 7, the V7 upgrade
function doesn't run (it only applies to versions < 7), and ScrubSchedule
stays at Go's zero value (empty string). registerJobs("") fails again.
Loop forever.

What I haven't figured out:

initialize() does set ScrubSchedule = "0 4 * * 0" correctly when
creating a fresh state.txt. So something is clearing or invalidating it
between initialize() (early in main()) and registerJobs() (step 21
of 24 in startup()). I don't know what. Two guesses:

• The REST API server starts before startup() runs (in run(), via a
  goroutine). Applications start at step 18. If anything sends a storage
  config update via the API during that window, it could overwrite the
  struct and zero out ScrubSchedule.

• Some edge case in gocron's IsValid() where it intermittently rejects a
  valid expression. Would explain the ~50% hit rate.

I haven't been able to confirm either — just noting them as possibilities.

Suggestion:

The simplest fix would be to not let registerJobs() crash the daemon
over this. Something like:

func registerJobs(s *state.State) error {
    schedule := s.System.Storage.Config.ScrubSchedule
    if schedule == "" {
        schedule = "0 4 * * 0"
        s.System.Storage.Config.ScrubSchedule = schedule
    }

    err := s.JobScheduler.RegisterJob(zfs.PoolScrubJob, schedule, zfs.ScrubAllPools)
    if err != nil {
        slog.Warn("Invalid scrub schedule, falling back to default", "schedule", schedule, "err", err)
        s.System.Storage.Config.ScrubSchedule = "0 4 * * 0"
        return s.JobScheduler.RegisterJob(zfs.PoolScrubJob, "0 4 * * 0", zfs.ScrubAllPools)
    }

    return nil
}

Separately, the zero-value skip in encodeHelper() is what makes the
corruption permanent. If ScrubSchedule were always written (even when
empty), the V7 upgrade path would at least have a chance to fix it on
restart. And Save() using os.WriteFile() (truncate-then-write instead
of write-to-temp + rename) means a crash mid-write could also produce a
partial state file, though I haven't confirmed that's happening here.

[stgraber]

• The REST API server starts before startup() runs (in run(), via a
  goroutine). Applications start at step 18. If anything sends a storage
  config update via the API during that window, it could overwrite the
  struct and zero out ScrubSchedule.

The API validates the pattern, so that's not really possible.

[stgraber]

LoadOrCreate also flushes the file to disk immediately after an initialize() call.

[lambda-m]

Is there anything or any (deploy-)variable I can specifically test or is there some other yet unknown issue in the IncusOS startup that is inherently causing this issue? Happy to spend some cycles on getting to the bottom of this.. do you know if it was reproduced outside of proxmox? I do not directly understand how, as this looks more like a pure software issue to me.

[stgraber]

I've never seen this show up outside of a state file update, on clean install from an up to date image, we've never seen it. And that's with https://linuxcontainers.org/incus/try-it/ literally going through the IncusOS initialization code thousands of times a day...

Just to make sure, you're not installing from an old image which then gets updated on first boot?

[gibmat]

Since the initial report, I've seen this issue one more time. Both occurrences happened during first-boot in fresh VMs created by Incus. I've also had hundreds (thousands?) of fresh VMs start up properly in the same time frame, so while there is some issue I haven't seen it happen with much frequency.

For debugging, I'd suggest setting up IncusOS within an Incus VM, so you can incus exec into the running system and poke at things. (You can refer to some basic debugging information here.) Once in the VM, you should be able to repeatedly test a "first boot" setup for IncusOS by stopping the service, then blowing away /var/lib/incus-os/ and starting the incus-osd daemon by hand.

It may also be useful to copy a locally-built incus-osd with additional debugging logic into the VM and run it, but since this is some sort of race condition be aware that those changes may mask or "fix" this issue we're trying to figure narrow down. 😉

[lambda-m]

Thanks for this feedback, I found my deploy script to perform a hard reboot of the VM at the "disconnect install media" stage which seemed to trigger the race / corruption. With the new flow I have not encountered this issue anymore. If I have a chance I will take your debugging tips and see if I can trigger it again to see if something can be improved perhaps. For now the issue is gone in a practical sense anyway.

[stgraber]

@gibmat Would it make sense to try to force a sync for that file whenever Save() is called?
Thinking of unix.Fdatasync(file.Fd()) basically.

That should force the write to go all the way through regardless of when ext4 feels like flushing to disk.

[gibmat]

I found my deploy script to perform a hard reboot of the VM at the "disconnect install media" stage which seemed to trigger the race / corruption.

I'm very confused that this has any impact on the issue, since at the conclusion of the install process the root partition doesn't even exist. On first boot after an install, systemd-repart creates a fresh ext4 root partition, which is then mounted and used to persist IncusOS state.

If there was an issue with data not being properly synced to disk at the conclusion of the install, I'd expect to get verity errors when the system boots.

I won't say 100% that this isn't the problem, but I'd certainly be surprised.