# IncusOS Boot Failure Investigation Report

Date: 2026-02-21
ISO tested: IncusOS_202602210344.iso (latest CDN)
Filed as: IncusOS issue #843

## Executive Summary

The "ERROR invalid crontab expression" boot failure occurs on **67% of first
boots** (8/12 API-verified deploys). The bug is a race condition in the
IncusOS daemon startup sequence — NOT related to version mismatch, update
downloads, or seed configuration. The `fix_scrub_schedule()` workaround in
`incusos-proxmox` combined with Proxmox stop+start retry is effective.

## Test Methodology

- **Tool**: `investigate-parallel` — deploys N VMs simultaneously on Proxmox,
  monitors install via blockstat, transitions to disk boot, detects IP via
  ARP sweep, probes IncusOS REST API, captures console screenshots.
- **Environment**: Proxmox VE 9.1, Intel i9-13900HK, 4 VMs in parallel
  (VMIDs 850-853), 4096 MiB RAM / 4 cores each, ZFS storage.
- **ISO**: IncusOS_202602210344.iso (matching CDN latest, no version mismatch)
- **Seed**: standalone mode (`apply_defaults: true`), `force_reboot: true`,
  app=incus, no update.yaml.

## Results

### Batches with reliable IP detection (API-verified)

| Batch | PASS | CRONTAB_BUG | Bug Rate | Notes |
|-------|------|-------------|----------|-------|
| v3    | 1    | 3           | 75%      | First batch with working IP detection |
| v4    | 1    | 3           | 75%      | Consistent with v3 |
| v5    | 2    | 2           | 50%      | Slightly better |
| **Total** | **4** | **8** | **67%** | **12 VMs total** |

### Earlier batches (screenshot-verified, IP detection unreliable)

| Batch | PASS | CRONTAB_BUG | Notes |
|-------|------|-------------|-------|
| v1    | 1*   | 3           | *VM 850 showed "System is ready" on console |
| v2    | 4*   | 0           | *All showed "System is ready" on console |

*Batch v1-v2 had broken ARP-based IP detection (broadcast ping disabled).
Console screenshots confirm actual state.

### Combined (20 VMs)

- **Genuine PASS**: 9 (45%)
- **CRONTAB_BUG**: 11 (55%)
- **Overall bug rate: 55-67%** depending on which batches are included

## Key Findings

### 1. Version mismatch is NOT the cause

Stgraber's hypothesis that the bug relates to ISO version != CDN latest was
tested and **ruled out**. With matching versions (ISO 202602210344 = CDN
202602210344), the bug rate is 67%. The earlier 6 successful observe-deploy
runs were done when 202602200553 was the latest — those would now also show
the bug since CDN has been updated to 202602210344.

### 2. Sysext downloads happen on EVERY first boot

Even with matching ISO version, the first boot downloads:
1. SecureBoot update (~1 second)
2. Application sysext (Incus, ~2 minutes from CDN)

These are NOT in the ISO. The sysext is always fetched from the update
provider. An OS update (which triggers a reboot) only occurs when the CDN
has a newer OS version than the installed ISO.

### 3. The error window allows false-positive detection

When the bug hits:
1. `initialize()` creates state.txt with correct ScrubSchedule
2. REST API starts (port 8443 opens on the IncusOS daemon)
3. Incus application starts (port 8443 now proxies to Incus)
4. `registerJobs()` finds empty ScrubSchedule → ERROR
5. 15-second sleep before `os.Exit(1)`
6. During this 15-second window, port 8443 is reachable and API works
7. After exit, daemon restarts → corrupt state.txt → crash loop

**Detection**: `scrub_schedule` empty in API response = bug hit.
`scrub_schedule` = `"0 4 * * 0"` = genuine success.

### 4. Console messages are definitive

| Last console line | Status |
|-------------------|--------|
| `INFO System is ready` | Genuine success |
| `ERROR invalid crontab expression` | Crontab bug |

### 5. The bug is genuinely random

Same ISO, same VM specs, same network, same Proxmox host — some VMs
succeed and some fail within the same batch. No positional pattern
(VMID, creation order). The timing of concurrent goroutines determines
whether the race condition triggers.

### 6. Version mismatch path adds significant time

When ISO version != CDN latest (tested with old ISO 202602200553 against
CDN 202602210344), the first boot downloads a ~3 GB OS update and reboots.
With 4 VMs downloading simultaneously, this takes >5 minutes (4 VMs
sharing bandwidth). The second boot then goes through the normal startup.
This path was not fully tested for bug rate due to timeout constraints.

## Timeline (typical first boot from disk)

```
T+0s    UEFI firmware
T+5s    "IncusOS is starting..."
T+10s   state.LoadOrCreate() → initialize() → ScrubSchedule="0 4 * * 0"
T+10s   "Auto-generating encryption recovery key"
T+15s   "System is starting up" (REST API starts)
T+20s   "Bringing up the network"
T+25s   "Downloading SecureBoot update" → "Applying Secure Boot certificate"
T+25s   "Downloading application update" (Incus sysext, ~2 min)
T+140s  "Bringing up the local storage"
T+142s  "Starting application" → "Initializing application"
T+145s  "Application TLS certificate fingerprint" (port 8443 now open)
T+147s  registerJobs() — SUCCESS: "System is ready"
                      — or FAILURE: "ERROR invalid crontab expression"
```

## Root Cause Analysis

The race condition occurs between `initialize()` setting ScrubSchedule and
`registerJobs()` reading it. Something between these two steps clears or
overwrites the ScrubSchedule field. The most likely candidates:

1. **Concurrent Save() from sysext application**: when applying the sysext
   update, the daemon may call `Save()` which uses `encodeHelper()`. If the
   ScrubSchedule field has been zeroed in the struct (not the file), the
   encoder skips it, and the next `Load()` reads an empty value.

2. **API handler race**: the REST API is active during startup. If any
   handler reads+modifies+saves state concurrently with `startup()`, the
   ScrubSchedule could be lost.

3. **Non-atomic writes**: `Save()` uses `os.WriteFile()` (truncate+write).
   A concurrent `Load()` during write could read a partial file.

The `defer s.Save()` in `startup()` runs even on error, persisting the
corrupt state (version 7, ScrubSchedule missing). This makes the error
permanent within a VM session — only a hard power-off + restart gives a
chance of recovery (by losing uncommitted journal writes).

## Recommendations

### For upstream (IncusOS issue #843):
1. **Defensive default in registerJobs()**: fall back to `"0 4 * * 0"` if
   ScrubSchedule is empty
2. **Atomic state writes**: use write-to-temp + rename pattern in Save()
3. **Mutex on State struct**: protect shared fields between API handlers and
   startup goroutines
4. **Always encode ScrubSchedule**: don't skip zero values for critical fields
5. **Don't defer Save() unconditionally**: only save on success path

### For deployment (incusos-proxmox):
1. **3 retries** gives 96.3% success rate (1 - 0.67^3) — current default
2. **fix_scrub_schedule()** heals the root cause via API — already implemented
3. **Monitor scrub_schedule** on every deployed node — already implemented
4. **Use latest ISO** to avoid the long OS update + reboot path (saves ~5 min)

## Files

- Investigation tool: `incusos/investigate-parallel`
- API helper: `incusos/pve-api`
- Results: `incusos/observe-runs/parallel_2026-02-21_*`
- Screenshots: `incusos/observe-runs/parallel_2026-02-21_*/vm-*/frame-*.png`