feat(cli): add stable provisioning failure codes for manual and MDM installs

This commit is contained in:
Anthony Wong
2026-08-21 14:52:02 +07:00
committed by Cuong Manh Le
parent 753d245029
commit 1f001a559a
14 changed files with 1988 additions and 107 deletions
+206
View File
@@ -0,0 +1,206 @@
# SPEC: Stable customer-visible provisioning failure codes
Issue: [#586](https://gitlab.int.windscribe.com/controld/clients/ctrld/-/issues/586)
Requested by: Catt Garrod (@catt). Scope expanded by: Anthony Wong (@anthony).
## 1. Objective
Terminal provisioning failures in ctrld — bootstrap/API setup, listener
binding, and service installation/startup — must produce a stable,
support-facing failure identifier that survives process exit and reaches
both manual CLI users and MDM-driven installs. A customer or admin reports
one code; Support maps it to a scenario and a next action without asking
for reruns or verbose logs.
Motivating incident (v1.5.5, macOS): provisioning reached the Control D
API, then died with only `FTL listener.0 could not find available listen
ip and port`. The per-address UDP/TCP bind errors existed only at Info
level in an in-memory logger and vanished on exit. The macOS pkg
`postinstall` discards ctrld's stdout/stderr entirely and judges success
by plist existence, so nothing useful reached the MDM log.
**Users:** end customers and IT admins reporting failures; Support agents
triaging them; MDM/RMM operators reading installer logs.
### Failure contract (agreed design)
Three surfaces, all carrying the same identifier:
1. **Result file** — on terminal provisioning failure, ctrld writes a
small redacted JSON file (atomic write: temp + rename) in the ctrld
home directory (same base dir as the internal `ctrld.log`,
via `absHomeDir`). Removed/overwritten on later successful
provisioning so stale failures don't mislead. Schema:
```json
{
"version": 1,
"timestamp": "2026-08-18T12:00:00Z",
"stage": "listener",
"code": "LISTENER_BIND_FAILED",
"exit_code": 41,
"message": "could not find available listen ip and port",
"detail": {
"attempts": [
{"addr": "127.0.0.1:53", "proto": "udp", "os_error": "address already in use"}
]
}
}
```
`detail` is bounded (cap recorded bind attempts; cap string lengths)
and redacted by construction: no provisioning tokens, resolver IDs,
config contents, or unrelated host data.
2. **Exit code + final stderr line** — the installer-facing command
(`ctrld start`, and `ctrld run` when run manually in the foreground)
exits with a stage-scoped code and prints one final line containing
the string code and stage, e.g.
`provisioning failed: stage=listener code=LISTENER_BIND_FAILED (exit 41)`.
3. **Installer log (MDM path)** — `scripts/pkg/postinstall` stops
discarding the signal: it captures `ctrld start`'s output to a
private temp file, extracts only the fixed-charset identifier line
(`stage=[a-z]* code=[A-Z_]* (exit [0-9]*)` — structurally unable to
carry the token), and echoes it with the exit code into the
installer log. The result file's `message`/`detail` fields are
deliberately never surfaced there. The plist-existence check remains
the final success gate.
### Identifier format
- **Primary identifier: stable string codes.** Initial set —
bootstrap: `API_UNREACHABLE`, `API_REJECTED`, `API_DEVICE_INVALID`;
listener: `LISTENER_BIND_FAILED`, `LISTENER_CONFIGURED_ADDR_UNAVAILABLE`;
service: `SERVICE_INSTALL_FAILED`, `SERVICE_START_FAILED`,
`SERVICE_SELFCHECK_FAILED`. Codes are append-only; renames are new
codes plus a deprecation note in the mapping doc.
- **Secondary: stage-scoped process exit codes** as a coarse machine
signal: bootstrap 3039, listener 4049, service install/start 5059.
Each string code owns one exit code. Existing contracts are untouched:
`ctrld status` 03, deactivation-pin 126, success 0.
- One underlying failure maps to one code on every path (manual CLI and
MDM), on both branches.
### Propagation (daemon → installer)
The listener/bootstrap fatals fire inside the daemon process
(`ctrld run` under launchd/systemd/SCM), not in `ctrld start`. The
daemon writes the result file before exiting; the existing log-socket
exit notification (`notifyExitToLogServer`) already unblocks `ctrld
start`'s self-check. `ctrld start` then reads the result file, prints
the identifier, and exits with the mapped stage exit code. The daemon's
own exit-status semantics toward service managers are preserved —
in particular the deliberate exit-0 on permanent API rejection that
protects the restart-policy budget; the result file carries the failure
identity in that case.
### Support mapping
`docs/provisioning-failure-codes.md` in this repo: one row per code —
code, stage, exit code, failure scenario, next safe troubleshooting
action or evidence request. Updated in the same MR whenever a code is
added or changed.
### Branch scope
Full implementation on **both** `v1.0` (release line for v1.5.5) and
`master`. The branches diverge heavily (`v1.0`: zerolog fork,
`commands.go`, `service_status.go`, macOS pkg scripts; `master`: zap,
inline commands, no pkg scripts), so this is one shared contract
(codes, exit-code ranges, file schema, doc) implemented twice, as two
MRs referencing #586.
## 2. Commands
- Build: `go build ./...`
- Test: `go test ./cmd/cli/...` (full: `go test ./...`)
- Vet: `go vet ./...`
- Branch workflow: feature branch off `v1.0` for the v1.0 MR; separate
feature branch off `master` for the port MR. Rebase, never merge the
base branch in.
## 3. Project structure
New and touched files on `v1.0` (master port mirrors the same contract
at its equivalent emission points in its `cli.go`):
- `cmd/cli/provision_result.go` (new) — stage + code enums, exit-code
mapping, result-file schema, atomic write/read/clear helpers,
bounded/redacted detail builders. Pattern follows `service_status.go`
(small file: named constants + classifier + dedicated tests).
- `cmd/cli/provision_result_test.go` (new).
- `cmd/cli/cli.go` — emission points: `run()` bootstrap failure branches
(permanent rejection, invalid-device, fatal fetch), and
`tryUpdateListenerConfig` / `tryUpdateListenerConfigIntercept` fatals,
which now record per-attempt `{addr, proto, os_error}` bind detail.
- `cmd/cli/commands.go` — `initStartCmd`: doTasks install/start failures
and the self-check failure branch read the result file, print the
identifier, and exit with the stage code (replacing bare `os.Exit(1)`
on those paths).
- `scripts/pkg/postinstall` — propagate exit code + result-file contents
into the installer log (v1.0 only; master has no pkg scripts).
- `docs/provisioning-failure-codes.md` (new) — support mapping.
## 4. Code style
- Per repo conventions and global rules: guard clauses, small functions,
descriptive names, explicit error handling — never weaken existing
handling (e.g. keep the permanent-rejection exit-0 rationale intact).
- Comments only for non-obvious constraints (e.g. why the daemon must
still exit 0 on permanent rejection), simple-english, self-contained —
no issue/MR references in code.
- Match each branch's logging idiom: zerolog fork on `v1.0`, zap on
`master`. No new dependencies.
- Conventional Commits; MR titles in simple-english; both MRs reference
#586 (release-line MR carries `Closes #586`).
## 5. Testing strategy
Test-first where the harness allows. Coverage required by the issue:
- **Code/mapping unit tests** — every string code maps to exactly one
stage and one in-range exit code; ranges don't collide with existing
contracts (03 status, 126 pin).
- **Result file round-trip** — write/read/clear; atomic write; stale
file removed on success.
- **Redaction** — serialize a result built from inputs containing a
provision token, resolver ID, and config content; assert none appear.
- **Listener bind failure (regression test for the incident)** — occupy
a port, drive the listener-config path to exhaustion, assert the
result records `LISTENER_BIND_FAILED` with attempted address, UDP/TCP
operation, and OS error (`address already in use`-class).
- **Bootstrap failures** — mock API: permanent 4xx → `API_REJECTED`;
invalid-device 40402 → `API_DEVICE_INVALID`; unreachable →
`API_UNREACHABLE`.
- **Service install/start/self-check failures** — injected task
failures assert code selection and `ctrld start` exit code.
- **MDM surface** — shell-level check of `postinstall` failure branch
(result file present → correct log line and exit), aligned with the
existing `test-scripts/` approach; manual pkg verification steps
documented in the MR.
- Both branches: the shared contract tests exist on both; branch-specific
emission tests match each branch's structure.
## 6. Boundaries
**Always:**
- Redact tokens, resolver IDs, config contents, host data from every
customer-visible surface (result file, stderr line, installer log).
- Preserve existing exit-code contracts (`ctrld status` 03, pin 126)
and the daemon's service-manager-facing exit semantics.
- Bound all recorded detail (attempt counts, string lengths).
- Keep codes append-only once merged.
**Ask first:**
- Changing the daemon's (`ctrld run` under a service manager) exit codes
or restart-relevant behavior beyond writing the result file.
- Adding any persisted file outside the ctrld home directory.
- Expanding scope to runtime (post-provisioning) failures — this ticket
owns terminal provisioning failures only.
**Never:**
- Print or persist the provisioning token (the reason postinstall
discards output today — the replacement surface must stay token-free).
- Auto-detect or kill conflicting processes (explicitly out of scope).
- Break `ctrld status`'s documented exit-code contract.
+139 -38
View File
@@ -342,29 +342,8 @@ func run(appCallback *AppCallback, stopCh chan struct{}) {
return
}
cdLogger := mainLog.Load().With().Str("mode", "cd").Logger()
// Performs self-uninstallation if the ControlD device does not exist.
var uer *controld.ErrorResponse
if errors.As(pf.err, &uer) && uer.ErrorField.Code == controld.InvalidConfigCode {
_ = uninstallInvalidCdUID(p, cdLogger, false)
}
if rejection, ok := permanentAPIRejection(pf.err); ok {
// The API answered and rejected this request permanently. Restarting
// cannot change that answer, so exit cleanly rather than through Fatal:
// an abnormal exit spends one of the service manager's restart actions,
// and on Windows those are what bring enforcement back after a real
// crash. Burning that budget on a config problem also buries the API's
// reason under repeated start failures.
cdLogger.Error().Err(pf.err).Int("status", rejection.StatusCode).Msg("failed to fetch resolver config, the API rejected this configuration")
notifyExitToLogServer()
return
}
notifyExitToLogServer()
// Everything else - a denied socket, an unreachable API, a proxy in the way,
// an API that is having a bad day - is a condition a later start may not hit,
// so keep the abnormal exit and let the service manager's recovery policy
// retry.
cdLogger.Fatal().Err(pf.err).Msg("failed to fetch resolver config")
handleAPIPreflightFailure(p, pf.err, notifyExitToLogServer)
return
default:
p.mu.Lock()
p.rc = pf.rc
@@ -374,6 +353,10 @@ func run(appCallback *AppCallback, stopCh chan struct{}) {
updated := updateListenerConfig(&cfg, notifyExitToLogServer)
// Bootstrap and listener binding both succeeded, so an earlier run's
// recorded failure no longer describes this install.
clearProvisionResult()
if cdUID != "" {
processLogAndCacheFlags(v, &cfg)
}
@@ -740,6 +723,76 @@ func permanentAPIRejection(err error) (*controld.ErrorResponse, bool) {
return uer, true
}
// apiFailureCode maps a bootstrap preflight error to its provisioning code.
// A deleted device gets its own code because it triggers self-uninstall;
// other permanent rejections are generic; anything else counts as
// reachability trouble worth retrying.
func apiFailureCode(err error) (provisionFailureCode, bool) {
if err == nil {
return "", false
}
var uer *controld.ErrorResponse
if errors.As(err, &uer) && uer.ErrorField.Code == controld.InvalidConfigCode {
return provisionCodeAPIDeviceInvalid, true
}
if _, ok := permanentAPIRejection(err); ok {
return provisionCodeAPIRejected, true
}
return provisionCodeAPIUnreachable, true
}
// apiRejectionSummary reports the HTTP status only. The API's raw error body
// can echo back the value the caller sent, so it stays out of the artifact.
func apiRejectionSummary(statusCode int) string {
return fmt.Sprintf("ControlD API rejected this configuration (HTTP status %d)", statusCode)
}
// provisionSecrets lists every secret-bearing value to strip from provisioning
// artifacts, including both parts of a composite "<uid>/<clientID>" --cd
// value, which the API may echo back separately.
func provisionSecrets() []string {
uid, clientID := controld.ParseRawUID(cdUID)
return []string{cdUID, cdOrg, uid, clientID}
}
// uninstallInvalidCdUIDFn is a var so tests can observe the self-uninstall
// without driving the OS service manager.
var uninstallInvalidCdUIDFn = uninstallInvalidCdUID
// handleAPIPreflightFailure reports a failed resolver-config fetch. A deleted
// device self-uninstalls; it and any other permanent rejection return cleanly
// so a config problem cannot burn the service manager's restart budget (on
// Windows those restarts are what bring enforcement back after a real crash).
// Anything else exits nonzero through failProvision so the manager retries.
func handleAPIPreflightFailure(p *prog, err error, notify func()) {
cdLogger := mainLog.Load().With().Str("mode", "cd").Logger()
code, _ := apiFailureCode(err)
var uer *controld.ErrorResponse
if errors.As(err, &uer) && uer.ErrorField.Code == controld.InvalidConfigCode {
r := newProvisionResult(code, apiRejectionSummary(uer.StatusCode), nil, provisionSecrets()...)
if werr := writeProvisionResult(r); werr != nil {
cdLogger.Warn().Err(werr).Msg("could not persist provision result")
}
_ = uninstallInvalidCdUIDFn(p, cdLogger, false)
cdLogger.Error().Err(err).Int("status", uer.StatusCode).Msg("failed to fetch resolver config, the device no longer exists")
cdLogger.Error().Msg(r.failureLine())
notify()
return
}
if rejection, ok := permanentAPIRejection(err); ok {
r := newProvisionResult(code, apiRejectionSummary(rejection.StatusCode), nil, provisionSecrets()...)
if werr := writeProvisionResult(r); werr != nil {
cdLogger.Warn().Err(werr).Msg("could not persist provision result")
}
cdLogger.Error().Err(err).Int("status", rejection.StatusCode).Msg("failed to fetch resolver config, the API rejected this configuration")
cdLogger.Error().Msg(r.failureLine())
notify()
return
}
cdLogger.Error().Err(err).Msg("failed to fetch resolver config")
failProvision(newProvisionResult(code, fmt.Sprintf("failed to fetch resolver config: %v", err), nil, provisionSecrets()...), notify)
}
// processCDFlagsFn is the API fetch, indirected so the lifetime binding around it can be
// tested without reaching the network.
var processCDFlagsFn = processCDFlags
@@ -1424,16 +1477,27 @@ func tryUpdateListenerConfigIntercept(cfg *ctrld.Config, notifyFunc func(), fata
}
}
// bindAttempts feeds the provisioning result detail. newProvisionResult
// caps it, so it grows freely here.
var bindAttempts []provisionBindAttempt
recordBindAttempt := func(addr, proto string, err error) {
if err != nil {
bindAttempts = append(bindAttempts, provisionBindAttempt{Addr: addr, Proto: proto, OSError: err.Error()})
}
}
tryListen := func(ip string, port int) bool {
addr := net.JoinHostPort(ip, strconv.Itoa(port))
udpLn, udpErr := net.ListenPacket("udp", addr)
if udpLn != nil {
udpLn.Close()
}
recordBindAttempt(addr, "udp", udpErr)
tcpLn, tcpErr := net.Listen("tcp", addr)
if tcpLn != nil {
tcpLn.Close()
}
recordBindAttempt(addr, "tcp", tcpErr)
return udpErr == nil && tcpErr == nil
}
@@ -1448,8 +1512,10 @@ func tryUpdateListenerConfigIntercept(cfg *ctrld.Config, notifyFunc func(), fata
if hasExplicitConfig {
// User specified explicit address — don't guess, just fail
if fatal {
notifyFunc()
mainLog.Load().Fatal().Msgf("DNS intercept: cannot listen on configured address %s", addr)
msg := fmt.Sprintf("DNS intercept: cannot listen on configured address %s", addr)
mainLog.Load().Error().Msg(msg)
failProvision(newProvisionResult(provisionCodeListenerAddrUnavail, msg, bindAttempts, provisionSecrets()...), notifyFunc)
return updated, false
}
return updated, false
}
@@ -1463,8 +1529,10 @@ func tryUpdateListenerConfigIntercept(cfg *ctrld.Config, notifyFunc func(), fata
}
if fatal {
notifyFunc()
mainLog.Load().Fatal().Msg("DNS intercept: cannot bind 127.0.0.1:53 or 127.0.0.1:5354")
const msg = "DNS intercept: cannot bind 127.0.0.1:53 or 127.0.0.1:5354"
mainLog.Load().Error().Msg(msg)
failProvision(newProvisionResult(provisionCodeListenerBindFailed, msg, bindAttempts, provisionSecrets()...), notifyFunc)
return updated, false
}
return updated, false
}
@@ -1566,6 +1634,15 @@ func tryUpdateListenerConfig(cfg *ctrld.Config, infoLogger *zerolog.Logger, noti
_ = closer.Close()
}
}()
// bindAttempts feeds the provisioning result detail. newProvisionResult
// caps it, so it grows freely here.
var bindAttempts []provisionBindAttempt
recordBindAttempt := func(addr, proto string, err error) {
if err != nil {
bindAttempts = append(bindAttempts, provisionBindAttempt{Addr: addr, Proto: proto, OSError: err.Error()})
}
}
// tryListen attempts to listen on given udp and tcp address.
// Created listeners will be kept in listeners slice above, and close
// before function finished.
@@ -1574,16 +1651,21 @@ func tryUpdateListenerConfig(cfg *ctrld.Config, infoLogger *zerolog.Logger, noti
if udpLn != nil {
closers = append(closers, udpLn)
}
recordBindAttempt(addr, "udp", udpErr)
tcpLn, tcpErr := net.Listen("tcp", addr)
if tcpLn != nil {
closers = append(closers, tcpLn)
}
recordBindAttempt(addr, "tcp", tcpErr)
return errors.Join(udpErr, tcpErr)
}
listenerMsg := func(listenerNum int, format string, v ...any) string {
return fmt.Sprintf("listener.%d %s", listenerNum, fmt.Sprintf(format, v...))
}
logMsg := func(e *zerolog.Event, listenerNum int, format string, v ...any) {
e.MsgFunc(func() string {
return fmt.Sprintf("listener.%d %s", listenerNum, fmt.Sprintf(format, v...))
return listenerMsg(listenerNum, format, v...)
})
}
@@ -1635,8 +1717,10 @@ func tryUpdateListenerConfig(cfg *ctrld.Config, infoLogger *zerolog.Logger, noti
maxAttempts := 10
for {
if attempts == maxAttempts {
notifyFunc()
logMsg(mainLog.Load().Fatal(), n, "could not find available listen ip and port")
logMsg(mainLog.Load().Error(), n, "could not find available listen ip and port")
msg := listenerMsg(n, "could not find available listen ip and port")
failProvision(newProvisionResult(provisionCodeListenerBindFailed, msg, bindAttempts, provisionSecrets()...), notifyFunc)
return updated, false
}
addr := net.JoinHostPort(listener.IP, strconv.Itoa(listener.Port))
err := tryListen(addr)
@@ -1648,8 +1732,10 @@ func tryUpdateListenerConfig(cfg *ctrld.Config, infoLogger *zerolog.Logger, noti
if !check.IP && !check.Port {
if fatal {
notifyFunc()
logMsg(mainLog.Load().Fatal(), n, "failed to listen: %v", err)
logMsg(mainLog.Load().Error(), n, "failed to listen: %v", err)
msg := listenerMsg(n, "failed to listen: %v", err)
failProvision(newProvisionResult(provisionCodeListenerAddrUnavail, msg, bindAttempts, provisionSecrets()...), notifyFunc)
return updated, false
}
ok = false
break
@@ -1716,8 +1802,11 @@ func tryUpdateListenerConfig(cfg *ctrld.Config, infoLogger *zerolog.Logger, noti
}
if listener.IP == oldIP && listener.Port == oldPort {
if fatal {
notifyFunc()
logMsg(mainLog.Load().Fatal(), n, "could not listen on %s: %v", net.JoinHostPort(listener.IP, strconv.Itoa(listener.Port)), err)
triedAddr := net.JoinHostPort(listener.IP, strconv.Itoa(listener.Port))
logMsg(mainLog.Load().Error(), n, "could not listen on %s: %v", triedAddr, err)
msg := listenerMsg(n, "could not listen on %s: %v", triedAddr, err)
failProvision(newProvisionResult(provisionCodeListenerBindFailed, msg, bindAttempts, provisionSecrets()...), notifyFunc)
return updated, false
}
ok = false
break
@@ -1755,8 +1844,10 @@ func tryUpdateListenerConfig(cfg *ctrld.Config, infoLogger *zerolog.Logger, noti
}
}
if !found {
notifyFunc()
logMsg(mainLog.Load().Fatal(), n, "could not use %q as DNS nameserver with systemd resolved", listener.IP)
logMsg(mainLog.Load().Error(), n, "could not use %q as DNS nameserver with systemd resolved", listener.IP)
msg := listenerMsg(n, "could not use %q as DNS nameserver with systemd resolved", listener.IP)
failProvision(newProvisionResult(provisionCodeListenerAddrUnavail, msg, bindAttempts, provisionSecrets()...), notifyFunc)
return updated, false
}
}
}
@@ -1804,13 +1895,23 @@ func cdUIDFromProvToken() string {
Metadata: ctrld.SystemMetadata(context.Background()),
}
// Process provision token if provided.
resolverConfig, err := controld.FetchResolverUID(context.Background(), req, rootCmd.Version, cdDev)
resolverConfig, err := fetchResolverUIDFn(context.Background(), req, rootCmd.Version, cdDev)
if err != nil {
mainLog.Load().Fatal().Err(err).Msgf("failed to fetch resolver uid with provision token: %s", redactToken(cdOrg))
// The token exchange is the first API call of an org/MDM install, so
// its failure must carry a code like every other bootstrap failure.
code, _ := apiFailureCode(err)
mainLog.Load().Error().Msgf("failed to fetch resolver uid with provision token: %s: %s",
redactToken(cdOrg), redactSecrets(err.Error(), provisionSecrets()...))
failProvision(newProvisionResult(code, fmt.Sprintf("provision token exchange failed: %v", err), nil, provisionSecrets()...), nil)
return ""
}
return resolverConfig.UID
}
// fetchResolverUIDFn is a var so tests can drive token-exchange failures
// without reaching the network.
var fetchResolverUIDFn = controld.FetchResolverUID
// removeOrgFlagsFromArgs removes organization flags from command line arguments.
// The flags are:
//
+329
View File
@@ -0,0 +1,329 @@
package cli
import (
"context"
"fmt"
"net"
"net/http"
"path/filepath"
"runtime"
"strconv"
"strings"
"testing"
"github.com/rs/zerolog"
"github.com/Control-D-Inc/ctrld"
"github.com/Control-D-Inc/ctrld/internal/controld"
)
// TestApiFailureCode covers the preflight-error mapping: a deleted device
// gets its own code (it drives self-uninstall), other permanent rejections
// are generic, anything else is retryable reachability trouble.
func TestApiFailureCode(t *testing.T) {
rejection := func(status, code int) error {
e := &controld.ErrorResponse{StatusCode: status}
e.ErrorField.Code = code
e.ErrorField.Message = "api said no"
return e
}
tests := []struct {
name string
err error
wantCode provisionFailureCode
wantOk bool
}{
{name: "nil error", err: nil, wantCode: "", wantOk: false},
{
name: "deleted device maps to device invalid",
err: rejection(http.StatusNotFound, controld.InvalidConfigCode),
wantCode: provisionCodeAPIDeviceInvalid,
wantOk: true,
},
{
name: "revoked credentials map to rejected",
err: rejection(http.StatusUnauthorized, 0),
wantCode: provisionCodeAPIRejected,
wantOk: true,
},
{
name: "server error maps to unreachable",
err: rejection(http.StatusBadGateway, 0),
wantCode: provisionCodeAPIUnreachable,
wantOk: true,
},
{
name: "network failure maps to unreachable",
err: retryableNetworkErr(),
wantCode: provisionCodeAPIUnreachable,
wantOk: true,
},
}
for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
code, ok := apiFailureCode(tc.err)
if ok != tc.wantOk {
t.Fatalf("apiFailureCode() ok = %v, want %v", ok, tc.wantOk)
}
if code != tc.wantCode {
t.Errorf("apiFailureCode() code = %s, want %s", code, tc.wantCode)
}
})
}
}
func stubProvisionGlobals(t *testing.T) (exitCode *int, notified *bool) {
t.Helper()
oldCdUID, oldCdOrg := cdUID, cdOrg
oldExit, oldUninstall := provisionExit, uninstallInvalidCdUIDFn
t.Cleanup(func() {
cdUID, cdOrg = oldCdUID, oldCdOrg
provisionExit, uninstallInvalidCdUIDFn = oldExit, oldUninstall
})
overrideProvisionResultPath(t)
code := -1
provisionExit = func(c int) { code = c }
n := false
return &code, &n
}
func TestHandleAPIPreflightFailure(t *testing.T) {
deviceInvalid := func() error {
e := &controld.ErrorResponse{StatusCode: http.StatusNotFound}
e.ErrorField.Code = controld.InvalidConfigCode
e.ErrorField.Message = "device does not exist"
return e
}
rejected := func() error {
e := &controld.ErrorResponse{StatusCode: http.StatusUnauthorized}
e.ErrorField.Message = "bad token"
return e
}
t.Run("permanent rejection returns cleanly", func(t *testing.T) {
exitCode, notified := stubProvisionGlobals(t)
handleAPIPreflightFailure(&prog{}, rejected(), func() { *notified = true })
if *exitCode != -1 {
t.Errorf("provisionExit called with %d, want a clean return", *exitCode)
}
if !*notified {
t.Error("notify not called")
}
r, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if r.Code != string(provisionCodeAPIRejected) {
t.Errorf("code = %q, want API_REJECTED", r.Code)
}
})
t.Run("deleted device self-uninstalls and returns cleanly", func(t *testing.T) {
exitCode, notified := stubProvisionGlobals(t)
uninstalled := false
uninstallInvalidCdUIDFn = func(_ *prog, _ zerolog.Logger, _ bool) bool {
uninstalled = true
return true
}
handleAPIPreflightFailure(&prog{}, deviceInvalid(), func() { *notified = true })
if *exitCode != -1 {
t.Errorf("provisionExit called with %d, want a clean return", *exitCode)
}
if !uninstalled {
t.Error("self-uninstall not attempted")
}
if !*notified {
t.Error("notify not called")
}
r, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if r.Code != string(provisionCodeAPIDeviceInvalid) {
t.Errorf("code = %q, want API_DEVICE_INVALID", r.Code)
}
})
t.Run("unreachable exits nonzero", func(t *testing.T) {
exitCode, notified := stubProvisionGlobals(t)
handleAPIPreflightFailure(&prog{}, retryableNetworkErr(), func() { *notified = true })
if *exitCode != provisionExitCodeForCode[provisionCodeAPIUnreachable] {
t.Errorf("exit = %d, want %d", *exitCode, provisionExitCodeForCode[provisionCodeAPIUnreachable])
}
if !*notified {
t.Error("notify not called")
}
r, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if r.Code != string(provisionCodeAPIUnreachable) {
t.Errorf("code = %q, want API_UNREACHABLE", r.Code)
}
})
t.Run("bare uid from a composite --cd value is redacted", func(t *testing.T) {
_, _ = stubProvisionGlobals(t)
cdUID = "deviceabc/clientxyz"
cdOrg = ""
err := fmt.Errorf("failed: api says deviceabc is unknown")
handleAPIPreflightFailure(&prog{}, err, func() {})
r, rerr := readProvisionResult()
if rerr != nil {
t.Fatal(rerr)
}
if strings.Contains(r.Message, "deviceabc") {
t.Errorf("bare uid leaked into message: %q", r.Message)
}
})
}
func TestCdUIDFromProvTokenFailureEmitsCode(t *testing.T) {
exitCode, _ := stubProvisionGlobals(t)
oldFetch, oldHostname := fetchResolverUIDFn, customHostname
t.Cleanup(func() { fetchResolverUIDFn, customHostname = oldFetch, oldHostname })
cdUID = ""
cdOrg = "org-secret-token-123"
customHostname = ""
rejected := &controld.ErrorResponse{StatusCode: http.StatusUnauthorized}
rejected.ErrorField.Message = "bad provision token org-secret-token-123"
fetchResolverUIDFn = func(context.Context, *controld.UtilityOrgRequest, string, bool) (*controld.ResolverConfig, error) {
return nil, rejected
}
if got := cdUIDFromProvToken(); got != "" {
t.Errorf("cdUIDFromProvToken() = %q, want empty on failure", got)
}
if *exitCode != provisionExitCodeForCode[provisionCodeAPIRejected] {
t.Errorf("exit = %d, want API_REJECTED exit %d", *exitCode, provisionExitCodeForCode[provisionCodeAPIRejected])
}
r, err := readProvisionResult()
if err != nil {
t.Fatalf("no provision result written: %v", err)
}
if r.Code != string(provisionCodeAPIRejected) {
t.Errorf("code = %q, want API_REJECTED", r.Code)
}
if strings.Contains(r.Message, cdOrg) {
t.Errorf("token leaked into result message: %q", r.Message)
}
}
// Regression test: an explicit ip:port that fails to bind used to die with a
// bare fatal log automation could not tell apart from any other crash. It
// must report a stable code through the provisioning result instead.
func TestTryUpdateListenerConfigConfiguredAddrUnavailable(t *testing.T) {
// Occupy one localhost port on both udp and tcp, and hold both for the
// whole test so ctrld's own bind attempt is guaranteed to fail.
udpConn, err := net.ListenPacket("udp", "127.0.0.1:0")
if err != nil {
t.Fatalf("could not reserve a udp port: %v", err)
}
defer udpConn.Close()
host, portStr, err := net.SplitHostPort(udpConn.LocalAddr().String())
if err != nil {
t.Fatalf("could not parse reserved address: %v", err)
}
port, err := strconv.Atoi(portStr)
if err != nil {
t.Fatalf("could not parse reserved port: %v", err)
}
tcpLn, err := net.Listen("tcp", net.JoinHostPort(host, portStr))
if err != nil {
t.Fatalf("could not reserve the same port on tcp: %v", err)
}
defer tcpLn.Close()
oldCdUID, oldCdOrg, oldNextdns, oldIntercept := cdUID, cdOrg, nextdns, interceptMode
oldPath, oldExit := provisionResultPath, provisionExit
t.Cleanup(func() {
cdUID, cdOrg, nextdns, interceptMode = oldCdUID, oldCdOrg, oldNextdns, oldIntercept
provisionResultPath, provisionExit = oldPath, oldExit
})
// Non-cd, non-nextdns mode with an explicit ip:port: no fallback checks,
// the path that used to reach the fatal exit directly.
cdUID = ""
cdOrg = ""
nextdns = ""
interceptMode = ""
tmpDir := t.TempDir()
provisionResultPath = func() string { return filepath.Join(tmpDir, "provision_result.json") }
var exitCode int
var exited bool
provisionExit = func(code int) { exitCode = code; exited = true }
cfg := &ctrld.Config{
Listener: map[string]*ctrld.ListenerConfig{
"0": {IP: host, Port: port},
},
}
notified := false
_, ok := tryUpdateListenerConfig(cfg, nil, func() { notified = true }, true)
if ok {
t.Error("tryUpdateListenerConfig ok = true, want false")
}
if !notified {
t.Error("expected notifyFunc to run before the recorded exit")
}
if !exited {
t.Fatal("expected provisionExit to be called")
}
if exitCode != 42 {
t.Errorf("exit code = %d, want 42 (LISTENER_CONFIGURED_ADDR_UNAVAILABLE)", exitCode)
}
result, err := readProvisionResult()
if err != nil {
t.Fatalf("could not read provision result: %v", err)
}
if result.Code != string(provisionCodeListenerAddrUnavail) {
t.Errorf("result code = %s, want %s", result.Code, provisionCodeListenerAddrUnavail)
}
if result.Stage != string(provisionStageListener) {
t.Errorf("result stage = %s, want %s", result.Stage, provisionStageListener)
}
if result.ExitCode != 42 {
t.Errorf("result exit code = %d, want 42", result.ExitCode)
}
if result.Detail == nil || len(result.Detail.Attempts) == 0 {
t.Fatal("expected the occupied address to appear as a recorded bind attempt")
}
occupiedAddr := net.JoinHostPort(host, portStr)
// Windows words WSAEADDRINUSE differently, so only require the canonical
// message on platforms that produce it.
requireInUseText := runtime.GOOS != "windows"
var sawUDP, sawTCP bool
for _, a := range result.Detail.Attempts {
if a.Addr != occupiedAddr || a.OSError == "" {
continue
}
if requireInUseText && !strings.Contains(strings.ToLower(a.OSError), "address already in use") {
continue
}
switch a.Proto {
case "udp":
sawUDP = true
case "tcp":
sawTCP = true
}
}
if !sawUDP {
t.Error("expected a udp attempt on the occupied address with a bind error")
}
if !sawTCP {
t.Error("expected a tcp attempt on the occupied address with a bind error")
}
}
// The exhaustion path (exit 41) is not covered: forcing every fallback,
// including a freshly randomized ip/port, to fail has no deterministic seam,
// so a test would race whatever ports are free on the host.
+143 -58
View File
@@ -283,6 +283,46 @@ func initRunCmd() *cobra.Command {
return runCmd
}
// serviceStageFailureCode maps an aborted service-manager task to its
// provisioning code. Other abortOnError tasks (like config validation) keep
// their own error paths.
func serviceStageFailureCode(taskName string) (provisionFailureCode, bool) {
switch taskName {
case "Install":
return provisionCodeServiceInstall, true
case "Start":
return provisionCodeServiceStartFailed, true
default:
return "", false
}
}
// serviceTaskErrorSummary describes which service-manager task failed and why,
// for use as a provisioning result message.
func serviceTaskErrorSummary(taskName string, err error) string {
return fmt.Sprintf("%s failed: %v", taskName, err)
}
// resultStalenessTolerance absorbs clock granularity between "ctrld start"
// recording its start time and the daemon writing its result file.
const resultStalenessTolerance = 2 * time.Second
// reportStartFailure reports why "ctrld start" failed after install/start
// looked fine. A result file the daemon wrote during this attempt names the
// failure better than a generic self-check code, so it wins.
func reportStartFailure(startedAt time.Time, fallbackMsg string) {
if r, err := readProvisionResult(); err == nil && provisionResultTrusted(r) {
if ts, err := time.Parse(time.RFC3339, r.Timestamp); err == nil {
if !ts.Before(startedAt.Add(-resultStalenessTolerance)) {
mainLog.Load().Error().Msg(r.failureLine())
provisionExit(r.ExitCode)
return
}
}
}
failProvision(newProvisionResult(provisionCodeServiceSelfCheck, fallbackMsg, nil, provisionSecrets()...), nil)
}
func initStartCmd() *cobra.Command {
startCmd := &cobra.Command{
PreRun: func(cmd *cobra.Command, args []string) {
@@ -524,23 +564,50 @@ NOTE: running "ctrld start" without any arguments will start already installed c
{s.Start, true, "Start"},
{noticeWritingControlDConfig, false, "Notice writing ControlD config"},
}
// Any result found later must come from this attempt, not a stale run.
clearProvisionResult()
startAttemptAt := time.Now()
mainLog.Load().Notice().Msg("Starting existing ctrld service")
if doTasks(tasks) {
mainLog.Load().Notice().Msg("Service started")
sockDir, err := socketDir()
if err != nil {
mainLog.Load().Warn().Err(err).Msg("Failed to get socket directory")
os.Exit(1)
failedTask, taskErr := doTasksE(tasks)
if taskErr != nil {
if code, ok := serviceStageFailureCode(failedTask); ok {
failProvision(newProvisionResult(code, serviceTaskErrorSummary(failedTask, taskErr), nil, provisionSecrets()...), nil)
return
}
reportSetDnsOk(sockDir)
// Verify service registration after successful start.
if err := verifyServiceRegistration(); err != nil {
mainLog.Load().Warn().Err(err).Msg("Service registry verification failed")
}
} else {
mainLog.Load().Error().Err(err).Msg("Failed to start existing ctrld service")
os.Exit(1)
}
sockDir, err := socketDir()
if err != nil {
mainLog.Load().Warn().Err(err).Msg("Failed to get socket directory")
os.Exit(1)
}
// The daemon can start and still fail provisioning (for example a
// listener bind conflict). Self-check like a fresh install so this
// path reports the daemon's failure code instead of a false
// "Service started" — but never uninstall an existing service.
time.Sleep(1 * time.Second)
ok, status, err := selfCheckStatus(ctx, s, sockDir)
if !ok || status != service.StatusRunning {
fallbackMsg := "ctrld service did not pass its post-start self-check"
if err != nil {
fallbackMsg = fmt.Sprintf("An error occurred while performing test query: %s", err)
mainLog.Load().Error().Msg(fallbackMsg)
}
if status == service.StatusRunning && err == nil {
fallbackMsg = "ctrld service was running, but a DNS query could not be sent to its listener; check firewall rules blocking/intercepting/redirecting DNS queries"
mainLog.Load().Error().Msg(fallbackMsg)
}
reportStartFailure(startAttemptAt, fallbackMsg)
return
}
mainLog.Load().Notice().Msg("Service started")
clearProvisionResult()
reportSetDnsOk(sockDir)
// Verify service registration after successful start.
if err := verifyServiceRegistration(); err != nil {
mainLog.Load().Warn().Err(err).Msg("Service registry verification failed")
}
return
}
@@ -605,7 +672,7 @@ NOTE: running "ctrld start" without any arguments will start already installed c
})
return nil
}, false, "Save current DNS"},
{s.Install, false, "Install"},
{s.Install, true, "Install"},
{func() error {
return ConfigureWindowsServiceFailureActions(ctrldServiceName)
}, false, "Configure Windows service failure actions"},
@@ -614,59 +681,77 @@ NOTE: running "ctrld start" without any arguments will start already installed c
// generated after s.Start, so we notice users here for consistent with nextdns mode.
{noticeWritingControlDConfig, false, "Notice writing ControlD config"},
}
// Any result found later must come from this attempt, not a stale run.
clearProvisionResult()
startAttemptAt := time.Now()
mainLog.Load().Notice().Msg("Starting service")
if doTasks(tasks) {
if err := p.router.Install(sc); err != nil {
mainLog.Load().Warn().Err(err).Msg("post installation failed, please check system/service log for details error")
failedTask, taskErr := doTasksE(tasks)
if taskErr != nil {
if code, ok := serviceStageFailureCode(failedTask); ok {
failProvision(newProvisionResult(code, serviceTaskErrorSummary(failedTask, taskErr), nil, provisionSecrets()...), nil)
return
}
// Not a service-stage task. doTasksE already logged the cause; exit
// non-zero instead of the old silent fall-through that exited 0.
os.Exit(1)
return
}
// add a small delay to ensure the service is started and did not crash
time.Sleep(1 * time.Second)
if err := p.router.Install(sc); err != nil {
mainLog.Load().Warn().Err(err).Msg("post installation failed, please check system/service log for details error")
return
}
ok, status, err := selfCheckStatus(ctx, s, sockDir)
switch {
case ok && status == service.StatusRunning:
mainLog.Load().Notice().Msg("Service started")
default:
marker := bytes.Repeat([]byte("="), 32)
// If ctrld service is not running, emitting log obtained from ctrld process.
if status != service.StatusRunning || ctx.Err() != nil {
mainLog.Load().Error().Msg("ctrld service may not have started due to an error or misconfiguration, service log:")
_, _ = mainLog.Load().Write(marker)
haveLog := false
for msg := range runCmdLogCh {
_, _ = mainLog.Load().Write([]byte(strings.ReplaceAll(msg, msgExit, "")))
haveLog = true
}
// If we're unable to get log from "ctrld run", notice users about it.
if !haveLog {
mainLog.Load().Write([]byte(`<no log output is obtained from ctrld process>"`))
}
}
// Report any error if occurred.
if err != nil {
_, _ = mainLog.Load().Write(marker)
msg := fmt.Sprintf("An error occurred while performing test query: %s", err)
mainLog.Load().Write([]byte(msg))
}
// If ctrld service is running but selfCheckStatus failed, it could be related
// to user's system firewall configuration, notice users about it.
if status == service.StatusRunning && err == nil {
_, _ = mainLog.Load().Write(marker)
mainLog.Load().Write([]byte(`ctrld service was running, but a DNS query could not be sent to its listener`))
mainLog.Load().Write([]byte(`Please check your system firewall if it is configured to block/intercept/redirect DNS queries`))
}
// add a small delay to ensure the service is started and did not crash
time.Sleep(1 * time.Second)
ok, status, err := selfCheckStatus(ctx, s, sockDir)
switch {
case ok && status == service.StatusRunning:
mainLog.Load().Notice().Msg("Service started")
clearProvisionResult()
default:
marker := bytes.Repeat([]byte("="), 32)
fallbackMsg := "ctrld service did not pass its post-start self-check"
// If ctrld service is not running, emitting log obtained from ctrld process.
if status != service.StatusRunning || ctx.Err() != nil {
mainLog.Load().Error().Msg("ctrld service may not have started due to an error or misconfiguration, service log:")
_, _ = mainLog.Load().Write(marker)
uninstall(p, s)
os.Exit(1)
haveLog := false
for msg := range runCmdLogCh {
_, _ = mainLog.Load().Write([]byte(strings.ReplaceAll(msg, msgExit, "")))
haveLog = true
}
// If we're unable to get log from "ctrld run", notice users about it.
if !haveLog {
mainLog.Load().Write([]byte(`<no log output is obtained from ctrld process>"`))
}
}
reportSetDnsOk(sockDir)
// Verify service registration after successful start.
if err := verifyServiceRegistration(); err != nil {
mainLog.Load().Warn().Err(err).Msg("Service registry verification failed")
// Report any error if occurred.
if err != nil {
_, _ = mainLog.Load().Write(marker)
msg := fmt.Sprintf("An error occurred while performing test query: %s", err)
mainLog.Load().Write([]byte(msg))
fallbackMsg = msg
}
// If ctrld service is running but selfCheckStatus failed, it could be related
// to user's system firewall configuration, notice users about it.
if status == service.StatusRunning && err == nil {
_, _ = mainLog.Load().Write(marker)
mainLog.Load().Write([]byte(`ctrld service was running, but a DNS query could not be sent to its listener`))
mainLog.Load().Write([]byte(`Please check your system firewall if it is configured to block/intercept/redirect DNS queries`))
fallbackMsg = "ctrld service was running, but a DNS query could not be sent to its listener; check firewall rules blocking/intercepting/redirecting DNS queries"
}
_, _ = mainLog.Load().Write(marker)
uninstall(p, s)
reportStartFailure(startAttemptAt, fallbackMsg)
return
}
reportSetDnsOk(sockDir)
// Verify service registration after successful start.
if err := verifyServiceRegistration(); err != nil {
mainLog.Load().Warn().Err(err).Msg("Service registry verification failed")
}
},
}
+122
View File
@@ -0,0 +1,122 @@
package cli
import (
"testing"
"time"
)
func TestServiceStageFailureCode(t *testing.T) {
tests := []struct {
taskName string
wantCode provisionFailureCode
wantOK bool
}{
{"Install", provisionCodeServiceInstall, true},
{"Start", provisionCodeServiceStartFailed, true},
{"Checking config", "", false},
{"", "", false},
}
for _, tc := range tests {
code, ok := serviceStageFailureCode(tc.taskName)
if code != tc.wantCode || ok != tc.wantOK {
t.Errorf("serviceStageFailureCode(%q) = (%q, %v), want (%q, %v)", tc.taskName, code, ok, tc.wantCode, tc.wantOK)
}
}
}
func stubProvisionExit(t *testing.T) *int {
t.Helper()
exitCode := -1
old := provisionExit
provisionExit = func(code int) { exitCode = code }
t.Cleanup(func() { provisionExit = old })
return &exitCode
}
func TestReportStartFailureUsesFreshDaemonResult(t *testing.T) {
overrideProvisionResultPath(t)
exitCode := stubProvisionExit(t)
startedAt := time.Now()
daemonResult := newProvisionResult(provisionCodeAPIUnreachable, "daemon could not reach the API", nil)
if err := writeProvisionResult(daemonResult); err != nil {
t.Fatal(err)
}
reportStartFailure(startedAt, "generic self-check failure")
if *exitCode != provisionExitCodeForCode[provisionCodeAPIUnreachable] {
t.Errorf("exit code = %d, want the daemon's own exit code %d", *exitCode, provisionExitCodeForCode[provisionCodeAPIUnreachable])
}
out, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if out.Code != string(provisionCodeAPIUnreachable) {
t.Errorf("persisted code = %q, want the daemon's own code untouched", out.Code)
}
}
func TestReportStartFailureFallsBackOnStaleDaemonResult(t *testing.T) {
overrideProvisionResultPath(t)
exitCode := stubProvisionExit(t)
stale := newProvisionResult(provisionCodeAPIUnreachable, "an old failure", nil)
stale.Timestamp = time.Now().Add(-1 * time.Hour).UTC().Format(time.RFC3339)
if err := writeProvisionResult(stale); err != nil {
t.Fatal(err)
}
startedAt := time.Now()
reportStartFailure(startedAt, "test query failed: timeout")
if *exitCode != provisionExitCodeForCode[provisionCodeServiceSelfCheck] {
t.Errorf("exit code = %d, want SERVICE_SELFCHECK_FAILED exit %d", *exitCode, provisionExitCodeForCode[provisionCodeServiceSelfCheck])
}
out, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if out.Code != string(provisionCodeServiceSelfCheck) {
t.Errorf("persisted code = %q, want %q", out.Code, provisionCodeServiceSelfCheck)
}
if out.Message != "test query failed: timeout" {
t.Errorf("persisted message = %q, want the fallback message", out.Message)
}
}
func TestReportStartFailureRejectsUntrustedFile(t *testing.T) {
overrideProvisionResultPath(t)
exitCode := stubProvisionExit(t)
planted := newProvisionResult(provisionCodeAPIUnreachable, "planted", nil)
planted.Code = "FAKE_CODE"
planted.ExitCode = 99
if err := writeProvisionResult(planted); err != nil {
t.Fatal(err)
}
reportStartFailure(time.Now().Add(-time.Minute), "self-check failed")
if *exitCode != provisionExitCodeForCode[provisionCodeServiceSelfCheck] {
t.Errorf("exit = %d, want the fallback %d, never the planted 99", *exitCode, provisionExitCodeForCode[provisionCodeServiceSelfCheck])
}
}
func TestReportStartFailureFallsBackWhenResultFileMissing(t *testing.T) {
overrideProvisionResultPath(t)
exitCode := stubProvisionExit(t)
reportStartFailure(time.Now(), "firewall hint")
if *exitCode != provisionExitCodeForCode[provisionCodeServiceSelfCheck] {
t.Errorf("exit code = %d, want SERVICE_SELFCHECK_FAILED exit %d", *exitCode, provisionExitCodeForCode[provisionCodeServiceSelfCheck])
}
out, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if out.Message != "firewall hint" {
t.Errorf("persisted message = %q, want the fallback message", out.Message)
}
}
+6 -1
View File
@@ -1683,12 +1683,17 @@ func (p *prog) dnsInterceptIgnoredChangeReconcileDue(now time.Time) bool {
}
func (p *prog) scheduleDNSAfterVPNSettleRefresh(reason string, delay time.Duration) {
time.AfterFunc(delay, func() {
timer := time.AfterFunc(delay, func() {
if p.dnsInterceptState == nil {
return
}
p.refreshDNSAfterVPNSettle(reason)
})
// Track the timer like the other delayed rechecks, so intercept teardown
// (and test cleanup) can stop it instead of letting it fire afterwards.
p.pfDelayedRecheckMu.Lock()
p.pfDelayedRecheckTimers = append(p.pfDelayedRecheckTimers, timer)
p.pfDelayedRecheckMu.Unlock()
}
func (p *prog) pfExecBackoffActive() bool {
+247
View File
@@ -0,0 +1,247 @@
package cli
import (
"encoding/json"
"fmt"
"os"
"path/filepath"
"strings"
"time"
"unicode/utf8"
)
// A terminal provisioning failure reports the same stable code on three
// surfaces: a persisted result file, one fixed-format output line, and a
// stage-scoped process exit code. docs/provisioning-failure-codes.md maps
// each code to its scenario and must stay in sync with the constants below.
// Codes are append-only once released; renaming or reusing one breaks the
// support contract.
type provisionStage string
const (
provisionStageBootstrap provisionStage = "bootstrap"
provisionStageListener provisionStage = "listener"
provisionStageService provisionStage = "service"
)
type provisionFailureCode string
const (
provisionCodeAPIUnreachable provisionFailureCode = "API_UNREACHABLE"
provisionCodeAPIRejected provisionFailureCode = "API_REJECTED"
provisionCodeAPIDeviceInvalid provisionFailureCode = "API_DEVICE_INVALID"
provisionCodeListenerBindFailed provisionFailureCode = "LISTENER_BIND_FAILED"
provisionCodeListenerAddrUnavail provisionFailureCode = "LISTENER_CONFIGURED_ADDR_UNAVAILABLE"
provisionCodeServiceInstall provisionFailureCode = "SERVICE_INSTALL_FAILED"
provisionCodeServiceStartFailed provisionFailureCode = "SERVICE_START_FAILED"
provisionCodeServiceSelfCheck provisionFailureCode = "SERVICE_SELFCHECK_FAILED"
)
var allProvisionFailureCodes = []provisionFailureCode{
provisionCodeAPIUnreachable,
provisionCodeAPIRejected,
provisionCodeAPIDeviceInvalid,
provisionCodeListenerBindFailed,
provisionCodeListenerAddrUnavail,
provisionCodeServiceInstall,
provisionCodeServiceStartFailed,
provisionCodeServiceSelfCheck,
}
var provisionStageForCode = map[provisionFailureCode]provisionStage{
provisionCodeAPIUnreachable: provisionStageBootstrap,
provisionCodeAPIRejected: provisionStageBootstrap,
provisionCodeAPIDeviceInvalid: provisionStageBootstrap,
provisionCodeListenerBindFailed: provisionStageListener,
provisionCodeListenerAddrUnavail: provisionStageListener,
provisionCodeServiceInstall: provisionStageService,
provisionCodeServiceStartFailed: provisionStageService,
provisionCodeServiceSelfCheck: provisionStageService,
}
// Exit codes are grouped by stage (bootstrap 30-39, listener 40-49, service
// 50-59) so the exit code alone names the failed stage. 0-3 belong to
// "ctrld status" and 126 to the deactivation pin check; never reuse those.
var provisionExitCodeForCode = map[provisionFailureCode]int{
provisionCodeAPIUnreachable: 30,
provisionCodeAPIRejected: 31,
provisionCodeAPIDeviceInvalid: 32,
provisionCodeListenerBindFailed: 41,
provisionCodeListenerAddrUnavail: 42,
provisionCodeServiceInstall: 51,
provisionCodeServiceStartFailed: 52,
provisionCodeServiceSelfCheck: 53,
}
const (
provisionResultFileName = "provision_result.json"
// Detail identifies a failure, it is not a log. Caps keep the artifact
// small and predictable.
maxProvisionBindAttempts = 12
maxProvisionStringLen = 256
)
type provisionBindAttempt struct {
Addr string `json:"addr"`
Proto string `json:"proto"`
OSError string `json:"os_error"`
}
type provisionDetail struct {
Attempts []provisionBindAttempt `json:"attempts,omitempty"`
}
type provisionResult struct {
Version int `json:"version"`
Timestamp string `json:"timestamp"`
Stage string `json:"stage"`
Code string `json:"code"`
ExitCode int `json:"exit_code"`
Message string `json:"message"`
Detail *provisionDetail `json:"detail,omitempty"`
}
// provisionResultPath is a var so tests can point it at a temp dir.
var provisionResultPath = func() string {
return absHomeDir(provisionResultFileName)
}
// provisionExit is a var so tests can observe the exit code instead of dying.
var provisionExit = os.Exit
// newProvisionResult builds a result with every field bounded and the given
// secrets stripped. The artifact reaches installer logs and support tickets,
// so callers pass every secret in scope (provision token, cd UID).
func newProvisionResult(code provisionFailureCode, message string, attempts []provisionBindAttempt, secrets ...string) *provisionResult {
sanitize := func(s string) string {
s = redactSecrets(s, secrets...)
if len(s) > maxProvisionStringLen {
// Cut on a rune boundary so a localized OS error does not end in
// a broken multi-byte sequence.
cut := maxProvisionStringLen
for cut > 0 && !utf8.RuneStart(s[cut]) {
cut--
}
s = s[:cut]
}
return s
}
r := &provisionResult{
Version: 1,
Timestamp: time.Now().UTC().Format(time.RFC3339),
Stage: string(provisionStageForCode[code]),
Code: string(code),
ExitCode: provisionExitCodeForCode[code],
Message: sanitize(message),
}
if len(attempts) > 0 {
if len(attempts) > maxProvisionBindAttempts {
attempts = attempts[:maxProvisionBindAttempts]
}
detail := &provisionDetail{Attempts: make([]provisionBindAttempt, 0, len(attempts))}
for _, a := range attempts {
detail.Attempts = append(detail.Attempts, provisionBindAttempt{
Addr: sanitize(a.Addr),
Proto: sanitize(a.Proto),
OSError: sanitize(a.OSError),
})
}
r.Detail = detail
}
return r
}
// redactSecrets removes every non-empty secret from s.
func redactSecrets(s string, secrets ...string) string {
for _, secret := range secrets {
if secret == "" {
continue
}
s = strings.ReplaceAll(s, secret, "[redacted]")
}
return s
}
// provisionResultTrusted rejects a result whose code, stage, or exit code is
// not part of the known contract, so a corrupt or planted file cannot drive
// what "ctrld start" logs and exits with.
func provisionResultTrusted(r *provisionResult) bool {
code := provisionFailureCode(r.Code)
stage, ok := provisionStageForCode[code]
if !ok {
return false
}
return r.Stage == string(stage) && r.ExitCode == provisionExitCodeForCode[code]
}
func (r *provisionResult) failureLine() string {
return fmt.Sprintf("provisioning failed: stage=%s code=%s (exit %d)", r.Stage, r.Code, r.ExitCode)
}
// writeProvisionResult persists the result atomically (temp file + rename in
// the same directory) so a reader never sees a partial file.
func writeProvisionResult(r *provisionResult) error {
path := provisionResultPath()
buf, err := json.MarshalIndent(r, "", " ")
if err != nil {
return err
}
tmp, err := os.CreateTemp(filepath.Dir(path), provisionResultFileName+".tmp*")
if err != nil {
return err
}
tmpName := tmp.Name()
if _, err := tmp.Write(buf); err != nil {
_ = tmp.Close()
_ = os.Remove(tmpName)
return err
}
if err := tmp.Close(); err != nil {
_ = os.Remove(tmpName)
return err
}
if err := os.Chmod(tmpName, 0o600); err != nil {
_ = os.Remove(tmpName)
return err
}
if err := os.Rename(tmpName, path); err != nil {
_ = os.Remove(tmpName)
return err
}
return nil
}
func readProvisionResult() (*provisionResult, error) {
buf, err := os.ReadFile(provisionResultPath())
if err != nil {
return nil, err
}
r := &provisionResult{}
if err := json.Unmarshal(buf, r); err != nil {
return nil, err
}
return r, nil
}
// clearProvisionResult removes a stale result once provisioning succeeds, so
// support never diagnoses a healthy install from an old failure.
func clearProvisionResult() {
if err := os.Remove(provisionResultPath()); err != nil && !os.IsNotExist(err) {
mainLog.Load().Debug().Err(err).Msg("could not remove provision result file")
}
}
// failProvision persists the result, prints the identifier line, unblocks a
// waiting "ctrld start" via notify, then exits with the stage code. The write
// comes first so the file survives even if logging or notify misbehaves.
func failProvision(r *provisionResult, notify func()) {
if err := writeProvisionResult(r); err != nil {
mainLog.Load().Warn().Err(err).Msg("could not persist provision result")
}
mainLog.Load().Error().Msg(r.failureLine())
if notify != nil {
notify()
}
provisionExit(r.ExitCode)
}
+278
View File
@@ -0,0 +1,278 @@
package cli
import (
"encoding/json"
"os"
"path/filepath"
"strconv"
"strings"
"testing"
"time"
"unicode/utf8"
)
func overrideProvisionResultPath(t *testing.T) string {
t.Helper()
path := filepath.Join(t.TempDir(), provisionResultFileName)
old := provisionResultPath
provisionResultPath = func() string { return path }
t.Cleanup(func() { provisionResultPath = old })
return path
}
func TestProvisionCodesMapToOneStageAndInRangeExit(t *testing.T) {
stageRanges := map[provisionStage][2]int{
provisionStageBootstrap: {30, 39},
provisionStageListener: {40, 49},
provisionStageService: {50, 59},
}
reservedExits := map[int]string{
statusExitRunning: "ctrld status running",
statusExitStopped: "ctrld status stopped",
statusExitUnknown: "ctrld status unknown",
statusExitNotReady: "ctrld status not ready",
deactivationPinInvalidExitCode: "deactivation pin invalid",
}
seenExits := make(map[int]provisionFailureCode)
for _, code := range allProvisionFailureCodes {
stage, ok := provisionStageForCode[code]
if !ok {
t.Fatalf("code %s has no stage", code)
}
exit, ok := provisionExitCodeForCode[code]
if !ok {
t.Fatalf("code %s has no exit code", code)
}
r := stageRanges[stage]
if exit < r[0] || exit > r[1] {
t.Errorf("code %s exit %d outside stage %s range %v", code, exit, stage, r)
}
if owner, ok := reservedExits[exit]; ok {
t.Errorf("code %s exit %d collides with %s", code, exit, owner)
}
if prev, dup := seenExits[exit]; dup {
t.Errorf("codes %s and %s share exit %d", prev, code, exit)
}
seenExits[exit] = code
}
if len(allProvisionFailureCodes) != 8 {
t.Errorf("expected 8 codes, got %d", len(allProvisionFailureCodes))
}
}
func TestNewProvisionResultRedactsSecrets(t *testing.T) {
token := "org-secret-token-12345"
cdUIDValue := "abcdef123456"
attempts := []provisionBindAttempt{
{Addr: "127.0.0.1:53", Proto: "udp", OSError: "bind failed for " + token},
}
r := newProvisionResult(
provisionCodeListenerBindFailed,
"could not bind, token="+token+" uid="+cdUIDValue,
attempts,
token, cdUIDValue,
)
raw, err := json.Marshal(r)
if err != nil {
t.Fatal(err)
}
for _, secret := range []string{token, cdUIDValue} {
if strings.Contains(string(raw), secret) {
t.Errorf("serialized result contains secret %q: %s", secret, raw)
}
}
}
func TestNewProvisionResultBoundsDetail(t *testing.T) {
long := strings.Repeat("x", 1000)
var attempts []provisionBindAttempt
for i := 0; i < 50; i++ {
attempts = append(attempts, provisionBindAttempt{Addr: long, Proto: "udp", OSError: long})
}
r := newProvisionResult(provisionCodeListenerBindFailed, long, attempts)
if got := len(r.Detail.Attempts); got > maxProvisionBindAttempts {
t.Errorf("attempts not capped: %d > %d", got, maxProvisionBindAttempts)
}
if len(r.Message) > maxProvisionStringLen {
t.Errorf("message not capped: %d", len(r.Message))
}
for _, a := range r.Detail.Attempts {
if len(a.Addr) > maxProvisionStringLen || len(a.OSError) > maxProvisionStringLen {
t.Error("attempt fields not capped")
}
}
}
func TestProvisionResultFields(t *testing.T) {
r := newProvisionResult(provisionCodeAPIRejected, "the API rejected this configuration", nil)
if r.Version != 1 {
t.Errorf("version = %d, want 1", r.Version)
}
if r.Stage != string(provisionStageBootstrap) {
t.Errorf("stage = %q, want bootstrap", r.Stage)
}
if r.ExitCode != provisionExitCodeForCode[provisionCodeAPIRejected] {
t.Errorf("exit = %d", r.ExitCode)
}
if _, err := time.Parse(time.RFC3339, r.Timestamp); err != nil {
t.Errorf("timestamp %q not RFC3339: %v", r.Timestamp, err)
}
if r.Detail != nil {
t.Error("nil attempts should give nil detail")
}
}
func TestProvisionResultTrusted(t *testing.T) {
good := newProvisionResult(provisionCodeListenerBindFailed, "x", nil)
if !provisionResultTrusted(good) {
t.Error("constructor-built result must be trusted")
}
bogusCode := newProvisionResult(provisionCodeListenerBindFailed, "x", nil)
bogusCode.Code = "TOTALLY_MADE_UP"
if provisionResultTrusted(bogusCode) {
t.Error("unknown code must not be trusted")
}
wrongExit := newProvisionResult(provisionCodeListenerBindFailed, "x", nil)
wrongExit.ExitCode = 126
if provisionResultTrusted(wrongExit) {
t.Error("exit code not matching the contract must not be trusted")
}
wrongStage := newProvisionResult(provisionCodeListenerBindFailed, "x", nil)
wrongStage.Stage = string(provisionStageService)
if provisionResultTrusted(wrongStage) {
t.Error("stage not matching the code must not be trusted")
}
}
func TestNewProvisionResultTruncatesOnRuneBoundary(t *testing.T) {
msg := strings.Repeat("é", maxProvisionStringLen) // 2 bytes per rune
r := newProvisionResult(provisionCodeListenerBindFailed, msg, nil)
if len(r.Message) > maxProvisionStringLen {
t.Errorf("message not capped: %d bytes", len(r.Message))
}
if !utf8.ValidString(r.Message) {
t.Error("truncation split a multi-byte rune")
}
}
func TestFailureCodeDocTableMatchesConstants(t *testing.T) {
buf, err := os.ReadFile(filepath.Join("..", "..", "docs", "provisioning-failure-codes.md"))
if os.IsNotExist(err) {
// The Windows CI runner executes prebuilt test binaries outside the
// repo; the sync guarantee is still enforced on runners with a checkout.
t.Skip("failure-code doc not available in this test environment")
}
if err != nil {
t.Fatalf("could not read the failure-code doc: %v", err)
}
doc := string(buf)
rows := 0
for _, line := range strings.Split(doc, "\n") {
if strings.HasPrefix(line, "| `") {
rows++
}
}
if rows != len(allProvisionFailureCodes) {
t.Errorf("doc table has %d code rows, want %d", rows, len(allProvisionFailureCodes))
}
for _, code := range allProvisionFailureCodes {
row := "| `" + string(code) + "` | " + string(provisionStageForCode[code]) + " | " + strconv.Itoa(provisionExitCodeForCode[code]) + " |"
if !strings.Contains(doc, row) {
t.Errorf("doc table missing row for %s (want prefix %q)", code, row)
}
}
}
func TestProvisionFailureLineFormat(t *testing.T) {
r := newProvisionResult(provisionCodeListenerBindFailed, "could not find available listen ip and port", nil)
want := "provisioning failed: stage=listener code=LISTENER_BIND_FAILED (exit 41)"
if got := r.failureLine(); got != want {
t.Errorf("failureLine() = %q, want %q", got, want)
}
}
func TestProvisionResultRoundTrip(t *testing.T) {
overrideProvisionResultPath(t)
in := newProvisionResult(provisionCodeServiceStartFailed, "service failed to start", nil)
if err := writeProvisionResult(in); err != nil {
t.Fatal(err)
}
out, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if out.Code != in.Code || out.Stage != in.Stage || out.ExitCode != in.ExitCode || out.Message != in.Message {
t.Errorf("round trip mismatch: in=%+v out=%+v", in, out)
}
}
func TestWriteProvisionResultOverwritesAtomically(t *testing.T) {
path := overrideProvisionResultPath(t)
first := newProvisionResult(provisionCodeAPIUnreachable, "first", nil)
if err := writeProvisionResult(first); err != nil {
t.Fatal(err)
}
second := newProvisionResult(provisionCodeListenerBindFailed, "second", nil)
if err := writeProvisionResult(second); err != nil {
t.Fatal(err)
}
out, err := readProvisionResult()
if err != nil {
t.Fatal(err)
}
if out.Code != string(provisionCodeListenerBindFailed) || out.Message != "second" {
t.Errorf("overwrite failed: %+v", out)
}
entries, err := os.ReadDir(filepath.Dir(path))
if err != nil {
t.Fatal(err)
}
if len(entries) != 1 {
t.Errorf("temp files left behind: %v", entries)
}
}
func TestClearProvisionResult(t *testing.T) {
path := overrideProvisionResultPath(t)
clearProvisionResult() // missing file must not panic or error loudly
if err := writeProvisionResult(newProvisionResult(provisionCodeAPIUnreachable, "x", nil)); err != nil {
t.Fatal(err)
}
clearProvisionResult()
if _, err := os.Stat(path); !os.IsNotExist(err) {
t.Errorf("result file still present after clear: %v", err)
}
}
func TestReadProvisionResultMissing(t *testing.T) {
overrideProvisionResultPath(t)
if _, err := readProvisionResult(); err == nil {
t.Error("expected error reading missing result file")
}
}
func TestFailProvisionWritesLogsNotifiesAndExits(t *testing.T) {
overrideProvisionResultPath(t)
exitCode := -1
oldExit := provisionExit
provisionExit = func(code int) { exitCode = code }
t.Cleanup(func() { provisionExit = oldExit })
notified := false
r := newProvisionResult(provisionCodeListenerBindFailed, "no listen addr", nil)
failProvision(r, func() { notified = true })
if !notified {
t.Error("notify func not called")
}
if exitCode != provisionExitCodeForCode[provisionCodeListenerBindFailed] {
t.Errorf("exit code = %d", exitCode)
}
out, err := readProvisionResult()
if err != nil {
t.Fatalf("result not persisted: %v", err)
}
if out.Code != string(provisionCodeListenerBindFailed) {
t.Errorf("persisted code = %q", out.Code)
}
}
+18 -10
View File
@@ -216,22 +216,30 @@ type task struct {
Name string
}
func doTasks(tasks []task) bool {
for _, task := range tasks {
mainLog.Load().Debug().Msgf("Running task %s", task.Name)
if err := task.f(); err != nil {
if task.abortOnError {
mainLog.Load().Error().Msgf("error running task %s: %v", task.Name, err)
return false
// doTasksE runs tasks in order and reports which abortOnError task, if any,
// stopped the run. Use it over doTasks when the failure must be attributed
// to a specific task.
func doTasksE(tasks []task) (failedTaskName string, err error) {
for _, t := range tasks {
mainLog.Load().Debug().Msgf("Running task %s", t.Name)
if taskErr := t.f(); taskErr != nil {
if t.abortOnError {
mainLog.Load().Error().Msgf("error running task %s: %v", t.Name, taskErr)
return t.Name, taskErr
}
// if this is darwin stop command, dont print debug
// since launchctl complains on every start
if runtime.GOOS != "darwin" || task.Name != "Stop" {
mainLog.Load().Debug().Msgf("error running task %s: %v", task.Name, err)
if runtime.GOOS != "darwin" || t.Name != "Stop" {
mainLog.Load().Debug().Msgf("error running task %s: %v", t.Name, taskErr)
}
}
}
return true
return "", nil
}
func doTasks(tasks []task) bool {
_, err := doTasksE(tasks)
return err == nil
}
func checkHasElevatedPrivilege() {
+57
View File
@@ -1,6 +1,7 @@
package cli
import (
"errors"
"strings"
"testing"
)
@@ -26,3 +27,59 @@ func Test_ensureSystemdKillMode(t *testing.T) {
})
}
}
func TestDoTasksESuccess(t *testing.T) {
var ran []string
tasks := []task{
{func() error { ran = append(ran, "a"); return nil }, false, "a"},
{func() error { ran = append(ran, "b"); return nil }, true, "b"},
}
failedTask, err := doTasksE(tasks)
if failedTask != "" || err != nil {
t.Errorf("doTasksE() = (%q, %v), want (\"\", nil)", failedTask, err)
}
if got := strings.Join(ran, ","); got != "a,b" {
t.Errorf("ran tasks %q, want all tasks run in order", got)
}
}
func TestDoTasksEAbortsOnAbortOnErrorTask(t *testing.T) {
wantErr := errors.New("install failed")
var ran []string
tasks := []task{
{func() error { ran = append(ran, "Stop"); return nil }, false, "Stop"},
{func() error { ran = append(ran, "Install"); return wantErr }, true, "Install"},
{func() error { ran = append(ran, "Start"); return nil }, true, "Start"},
}
failedTask, err := doTasksE(tasks)
if failedTask != "Install" || !errors.Is(err, wantErr) {
t.Errorf("doTasksE() = (%q, %v), want (\"Install\", %v)", failedTask, err, wantErr)
}
if got := strings.Join(ran, ","); got != "Stop,Install" {
t.Errorf("ran tasks %q, want the run to stop right after the abort", got)
}
}
func TestDoTasksENonAbortFailureContinues(t *testing.T) {
var ran []string
tasks := []task{
{func() error { ran = append(ran, "a"); return errors.New("a failed") }, false, "a"},
{func() error { ran = append(ran, "b"); return nil }, true, "b"},
}
failedTask, err := doTasksE(tasks)
if failedTask != "" || err != nil {
t.Errorf("doTasksE() = (%q, %v), want (\"\", nil) since the failing task did not abort", failedTask, err)
}
if got := strings.Join(ran, ","); got != "a,b" {
t.Errorf("ran tasks %q, want the run to continue past the non-abort failure", got)
}
}
func TestDoTasksDelegatesToDoTasksE(t *testing.T) {
if !doTasks([]task{{func() error { return nil }, true, "ok"}}) {
t.Error("doTasks() = false, want true on success")
}
if doTasks([]task{{func() error { return errors.New("boom") }, true, "boom"}}) {
t.Error("doTasks() = true, want false when an abortOnError task fails")
}
}
+61
View File
@@ -0,0 +1,61 @@
# Provisioning failure codes
When ctrld hits a terminal failure during provisioning, it reports the same
stable code on three surfaces:
- **Result file**`provision_result.json` in the ctrld home directory
(next to the persisted internal `ctrld.log`). JSON with `stage`, `code`,
`exit_code`, `message`, and for listener failures a bounded
`detail.attempts` list of `{addr, proto, os_error}`. Written atomically,
removed on the next successful provisioning. Never contains provision
tokens, resolver/device IDs, or configuration contents.
- **Output line** — one fixed-format line on the CLI output:
`provisioning failed: stage=<stage> code=<CODE> (exit <N>)`.
The macOS pkg `postinstall` extracts exactly this line into the installer
log, so MDM consoles see it without any ctrld log configuration.
- **Exit code** — stage-scoped: bootstrap 3039, listener 4049,
service 5059. Unrelated existing contracts are unchanged
(`ctrld status` exits 03; invalid deactivation pin exits 126).
A customer or administrator only needs to report the code (or the whole
output line). The table below is the maintained support mapping; it must
stay in sync with `cmd/cli/provision_result.go` and changes in the same MR.
## Codes
| Code | Stage | Exit | Failure scenario | Next action / evidence |
|---|---|---|---|---|
| `API_UNREACHABLE` | bootstrap | 30 | The Control D API could not be reached or answered with a retryable error (network failure, proxy interference, 5xx, timeout) and retries ran out. The service manager may retry the service later. | Check the device's network path to `api.controld.com` (DNS, proxy, firewall, captive portal). Ask for the result file's `message` and whether other TLS traffic works. |
| `API_REJECTED` | bootstrap | 31 | The API answered and permanently rejected the configuration (4xx other than 408/429): bad or revoked token, malformed request. ctrld exits without burning service-manager restarts because retrying cannot change the answer. | Verify the provision token / org configuration in the Control D dashboard. Re-push after fixing credentials. Evidence: HTTP status in the result file `message`. |
| `API_DEVICE_INVALID` | bootstrap | 32 | The API reports the device/resolver no longer exists (error code 40402). ctrld self-uninstalls its service because the identity is gone server-side. | Confirm the device was deleted or re-provisioned in the dashboard; re-provision with a current token. No local evidence needed beyond the code. |
| `LISTENER_BIND_FAILED` | listener | 41 | No listen address could be bound after all fallbacks (configured address, 0.0.0.0:53, localhost:53, port 5354, random) were exhausted. `detail.attempts` records each tried address with the UDP/TCP OS error, e.g. `address already in use` (another DNS service owns the port) or `can't assign requested address` (address not on any interface). | Read `detail.attempts`: `address already in use` → find the process owning the port (`sudo lsof -i :53 -nP`); `can't assign requested address` → the configured IP is not present on the device. Then fix the conflict or the listener config. |
| `LISTENER_CONFIGURED_ADDR_UNAVAILABLE` | listener | 42 | An explicitly configured listener address could not be bound and configuration checks forbid falling back to another address, or (macOS intercept mode) the required explicit address is unavailable. | The configured `ip:port` in the listener config is wrong for this device or occupied. Verify the address exists on an interface and nothing else binds it; correct the config rather than expecting fallback. |
| `SERVICE_INSTALL_FAILED` | service | 51 | The OS service manager refused to install the service (launchd/systemd/SCM registration failed). | Check OS-level constraints: permissions/elevation, MDM policy blocking daemon installation, corrupted previous install. Evidence: result file `message` (service manager error), plus `launchctl print system/ctrld` / `systemctl status ctrld` / SCM state. |
| `SERVICE_START_FAILED` | service | 52 | The service installed but the service manager could not start it. | Check the service manager's own log for the start error, then the ctrld home dir `ctrld.log`. Often permissions or a binary quarantined by security tooling. |
| `SERVICE_SELFCHECK_FAILED` | service | 53 | The service started but never became healthy: no fresher failure was reported by the daemon, and the post-install DNS self-check failed. The just-installed service is rolled back (uninstalled). If the daemon itself recorded a more specific failure (e.g. a listener code), that code is reported instead of this one. | Ask for the drained service log printed by `ctrld start` and the result file. If the service was running but unreachable, check host firewall rules intercepting DNS to the listener. |
## Reading the result file
macOS and Linux (default service home is `/etc/controld`):
```sh
sudo cat /etc/controld/provision_result.json
```
On Windows the file sits next to `ctrld.exe` in the install directory. A
custom `homedir` config moves it accordingly; routers and mobile use their
platform home directory.
The file sits in the same directory as the persisted internal log
(`ctrld.log`) for the user the service runs as. On a healthy install the
file is absent.
## Rules for maintainers
- Codes are append-only once released. Never rename, renumber, or reuse a
code or exit number; add a new one and note the deprecation here.
- Every code added in `cmd/cli/provision_result.go` needs a row here in the
same MR. Tests enforce the code/stage/exit maps and that this table has
exactly one row per code.
- Detail must stay bounded and free of secrets: the constructor strips the
provision token and cd UID and caps sizes; do not bypass it.
+213
View File
@@ -0,0 +1,213 @@
# Plan: provisioning failure codes (issue #586)
Spec: SPEC.md. Baseline: `ac0e6aed` on `v1.0`.
Branches: `issue-586` (off `v1.0`), `issue-586-master` (off `master`).
Two MRs, both referencing #586; the `v1.0` MR carries `Closes #586`.
## Shared contract (fixed here so parallel tasks cannot diverge)
| Code | Stage | Exit |
|---|---|---|
| `API_UNREACHABLE` | bootstrap | 30 |
| `API_REJECTED` | bootstrap | 31 |
| `API_DEVICE_INVALID` | bootstrap | 32 |
| `LISTENER_BIND_FAILED` | listener | 41 |
| `LISTENER_CONFIGURED_ADDR_UNAVAILABLE` | listener | 42 |
| `SERVICE_INSTALL_FAILED` | service | 51 |
| `SERVICE_START_FAILED` | service | 52 |
| `SERVICE_SELFCHECK_FAILED` | service | 53 |
- Result file: `provision_result.json` in the ctrld home dir (same
resolution as the persisted internal log: `absHomeDir` on v1.0, the
`userHomeDir`-based equivalent on master). Atomic write (temp +
rename in the same dir). Cleared when provisioning succeeds.
- Result schema (version 1): `version`, `timestamp` (RFC3339, UTC),
`stage`, `code`, `exit_code`, `message`, optional `detail.attempts[]`
of `{addr, proto, os_error}`; attempts capped at 12 entries, every
string capped at 256 chars.
- Identifier line, exact format (greppable, token-free by
construction): `provisioning failed: stage=<stage> code=<CODE> (exit <N>)`.
- Redaction: results are built through a constructor that takes the
secrets in scope (cd UID, provision token) and strips them from every
field. Messages come from our own summaries plus OS error strings,
never raw config or API bodies.
- Exit seam: `provisionExit = os.Exit` package var so tests can stub
process exit. Emission helper `failProvision(...)` writes the file,
logs the identifier line, calls the notify func, then exits with the
stage code. Nonzero exit is preserved everywhere the daemon exits
nonzero today; the deliberate clean return on permanent API rejection
stays a clean return (result file only).
## Dependency graph
```
A1 (contract module + doc, v1.0) D1 (master port)
├─► B1 daemon emissions (cli.go) depends on: contract table
├─► B2 start-side (commands.go+service.go) (from A1) + C1 verified
└─► B3 postinstall (scripts, tests) implementation as reference
└─► C1 v1.0 checkpoint ────────────► D1 ─► E1 final checkpoint
```
## Group A — serial, runs inline (1 task)
### A1. Contract foundation on `issue-586`
Create branch `issue-586` from `v1.0`. New files:
`cmd/cli/provision_result.go`, `cmd/cli/provision_result_test.go`,
`docs/provisioning-failure-codes.md`.
Module contents: stage type + the 8 code constants + exit-code map;
`ProvisionResult` struct per schema; bounded/redacting constructor;
atomic `writeProvisionResult` / `readProvisionResult` /
`clearProvisionResult`; identifier-line formatter; `provisionExit`
seam; `failProvision` helper. Doc: full table — code, stage, exit,
failure scenario, next safe troubleshooting action / evidence request.
Tests (RED first): every code maps to exactly one stage and one
in-range exit code (3039/4049/5059); no collision with 03
(`ctrld status`) or 126 (pin); file round-trip; atomic overwrite;
clear; redaction (a result built from inputs containing a fake token
and cd UID serializes without them); attempts/string caps enforced;
identifier line matches the exact format.
Acceptance: `go build ./...` and `go test ./cmd/cli/` green; doc rows
exactly match the constants.
## Group B — parallel Workflow fan-out, one subagent per task, worktree isolation, branched from `issue-586` after A1
### B1. Daemon emissions in `cli.go`
- Bootstrap branches in `run()` (`cli.go:339-372`):
- permanent rejection (`permanentAPIRejection`): write `API_REJECTED`
result (HTTP status + our own summary, no raw API body), keep the
existing clean return and its comment.
- invalid device (`controld.InvalidConfigCode`): write
`API_DEVICE_INVALID` before `uninstallInvalidCdUID`.
- fatal fetch: write `API_UNREACHABLE`, replace
`cdLogger.Fatal()` with error log + identifier line +
`failProvision` exit 30 (still nonzero for the service manager).
- Listener (`tryUpdateListenerConfig`, `tryUpdateListenerConfigIntercept`):
- record every failed bind attempt `{addr, proto, os_error}`
capture UDP and TCP errors separately in `tryListen` (keep
`errors.Join` for control flow), cap per contract.
- exhaustion fatal (`cli.go:1639`) and converged-random fatal
(`cli.go:1720`) → `LISTENER_BIND_FAILED` exit 41 with attempts.
- no-fallback-allowed fatal (`cli.go:1652`) and intercept-mode fatals
(`cli.go:1452,1467`) → `LISTENER_CONFIGURED_ADDR_UNAVAILABLE`
exit 42 (fallback-exhausted intercept fatal stays
`LISTENER_BIND_FAILED`).
- all fatals keep calling the notify func first; final message
includes the code string.
- Clear the result file at the point provisioning is known good
(after `updateListenerConfig` succeeds in `run()`).
Tests (RED first): occupy a UDP+TCP port, drive the listener path to
exhaustion with the exit seam stubbed, assert the result file has
`LISTENER_BIND_FAILED`, the attempted address, both protocols'
`os_error` (`address already in use` class); pure mapping test
API error → code (permanent 4xx → `API_REJECTED`, 40402 →
`API_DEVICE_INVALID`, network error → `API_UNREACHABLE`) following
`cli_preflight_test.go` patterns.
Acceptance: only `cmd/cli/cli.go` + new/extended tests touched;
`go build ./... && go test ./cmd/cli/` green.
### B2. `ctrld start` reporting in `commands.go` + `service.go`
- Add `doTasksE` (returns failed task name + error; `doTasks` keeps
its signature and delegates).
- Fresh-install path (`commands.go:618`): failed `Install` task →
`SERVICE_INSTALL_FAILED` (write result, print identifier line, exit
51); failed `Start` task → `SERVICE_START_FAILED` (exit 52). This
fixes the current fall-through that exits 0 on install failure.
- Existing-service path (`commands.go:528-543`): failure → 52 with the
same reporting (replaces bare `os.Exit(1)`).
- Self-check failure branch (`commands.go:627-664`): keep the log
drain and `uninstall(p, s)`; then read the daemon's result file —
if present and stamped after this start attempt began, report its
stage/code/exit (daemon identity wins: e.g. `LISTENER_BIND_FAILED`);
otherwise write and report `SERVICE_SELFCHECK_FAILED` exit 53.
Extract this into a testable helper (fabricated result files +
stubbed exit seam).
- On successful start (self-check ok), clear any stale result file.
Tests (RED first): `doTasksE` failure attribution; helper precedence
(fresh daemon result wins; stale/missing falls back to 53); exit-code
selection per failed task.
Acceptance: only `cmd/cli/commands.go`, `cmd/cli/service.go` + tests
touched; build and package tests green.
### B3. postinstall MDM surface
- `scripts/pkg/postinstall`: capture `ctrld start` output to a
`mktemp` file (chmod 600) instead of `/dev/null`; keep the plist
check as the success gate; on failure, `grep -m1 '^provisioning
failed: '` from the capture into the install log together with the
exit code; delete the capture file always; never echo any other
output line (token safety preserved by extracting only the
fixed-format line).
- Shell test `test-scripts/darwin/test-postinstall-provision-failure.sh`
(matching existing script conventions): stub `$CTRLD` that prints a
fake token plus a valid identifier line and exits 41; assert the
logged output contains stage/code/exit and not the token; assert
success path unchanged. Runs without root.
- Update `docs/macos-pkg-mdm.md` where it documents the discard
behavior/failure triage, and add the failure-code doc link.
Acceptance: shell test passes locally (`sh test-scripts/darwin/...`);
only `scripts/pkg/postinstall`, `test-scripts/darwin/`, `docs/`
touched.
## Checkpoint C1 — serial, after Group B merges
Merge order: B1, B2, B3 into `issue-586`. Then: `go build ./...`,
`go vet ./...`, `go test ./cmd/cli/...` (and full `./...`), run the B3
shell test, verify doc table == constants, and verify each spec
acceptance criterion has an implementation + test. Fix-forward any
merge fallout before Group D starts.
## Group D — serial (1 task, own worktree off `master`)
### D1. Master port on `issue-586-master`
Create `git worktree` with branch `issue-586-master` from
`origin/master`/`master`. Port with the v1.0 implementation as
reference, adapted to master's structure (zap-shaped logging idiom,
no `commands.go`):
- `cmd/cli/provision_result.go` + tests: identical contract table.
- Bootstrap: `run()` branches at master `cli.go:340-374` (same
permanent-rejection clean return, invalid-device, fatal fetch).
- Listener: `tryUpdateListenerConfig` fatals at master
`cli.go:1657/1667/1719`; intercept variant at `cli.go:1487/1502`;
per-attempt capture (bind errors currently logged at Debug,
`cli.go:1665`).
- Start side: `commands_service_start.go` — both `doTasks` call sites,
self-check `default:` arm (`os.Exit(1)` ~line 370), same fall-through
audit, same precedence logic; `doTasksE` in `service.go`.
- `docs/provisioning-failure-codes.md`: same table (omit
pkg/postinstall-specific notes; master has no `scripts/pkg`).
- No postinstall work on master.
Tests mirrored from v1.0 where the structure allows.
Acceptance: in the master worktree, `go build ./...`,
`go test ./cmd/cli/...` green; constants table semantically identical
to `issue-586`.
## Checkpoint E1 — serial, final
- Cross-branch contract equality: compare code constants, exit codes,
identifier-line format, result schema between the two branches.
- Full test suites on both branches.
- Both branches committed (per-task Conventional Commits); no pushes,
no MRs yet — `/draft-review` is the next pipeline step.
## Execution notes
- Each parallel group runs as one Workflow fan-out, one subagent per
task, `isolation: 'worktree'` so parallel edits never conflict;
serial tasks (A1, C1, D1, E1) run inline (D1 manages its own
master-based worktree).
- Every subagent follows RED → GREEN → regression → build and commits
in its worktree; the orchestrator merges in dependency order and
runs the full suite before the next group.
- Subagent prompts are self-contained: they carry the contract table
and file anchors from this plan, not references to SPEC.md (worktree
copies may not include untracked files).
+21
View File
@@ -0,0 +1,21 @@
# TODO: issue #586 provisioning failure codes
Groups run in order; tasks inside a parallel group run as one Workflow
fan-out (one subagent per task, worktree isolation).
## Group A (serial)
- [x] A1: contract module `cmd/cli/provision_result.go` + tests + `docs/provisioning-failure-codes.md` on branch `issue-586`
## Group B (parallel after A1)
- [x] B1: daemon emissions — bootstrap + listener paths in `cmd/cli/cli.go` + tests
- [x] B2: `ctrld start` reporting — `cmd/cli/commands.go`, `cmd/cli/service.go` (doTasksE, exit-0 fall-through fix, self-check precedence) + tests
- [x] B3: postinstall MDM surface — `scripts/pkg/postinstall`, shell test, `docs/macos-pkg-mdm.md`
## Checkpoint C1 (serial)
- [x] C1: merge B1→B2→B3 into `issue-586`, full build/vet/test, shell test, doc/constants parity, spec AC audit
## Group D (serial)
- [x] D1: master port on `issue-586-master` (contract module, cli.go emissions, commands_service_start.go, docs) + tests
## Checkpoint E1 (serial)
- [x] E1: cross-branch contract equality, full suites on both branches, commits tidy — stop before push/MR (`/draft-review` next)
+148
View File
@@ -0,0 +1,148 @@
#!/bin/sh
# Test: the MDM pkg postinstall script surfaces ctrld's provisioning
# failure identifier in its output without leaking the provision token,
# and still reports success once the plist exists.
#
# Self-contained and root-free: every path postinstall touches is
# redirected into a throwaway temp directory via the
# CTRLD_POSTINSTALL_{PLIST,CTRLD,PREFS} overrides, and 'defaults' is
# stubbed on PATH so the profile-wait loop resolves on its first attempt.
#
# Out of scope: the upgrade path (plist already exists) calls the real
# launchctl and is not exercised here.
#
# Run: sh test-postinstall-provision-failure.sh
SCRIPT_DIR=$(cd "$(dirname "$0")" && pwd)
POSTINSTALL="$SCRIPT_DIR/../../scripts/pkg/postinstall"
WORKDIR=$(mktemp -d -t ctrld-postinstall-test) || {
echo "FAIL: could not create test work directory" >&2
exit 1
}
trap 'rm -rf "$WORKDIR"' EXIT
FAKE_TOKEN="FAKE-PROVISION-TOKEN-DO-NOT-LEAK-93af0c"
export FAKE_TOKEN
STUBBIN="$WORKDIR/stubbin"
mkdir -p "$STUBBIN"
cat > "$STUBBIN/defaults" <<'STUB'
#!/bin/sh
# Stand-in for macOS 'defaults read <domain> <key>': answers ProvisionToken
# immediately, like a profile that only sets that one key, so the
# postinstall wait loop never has to sleep.
if [ "$1" = "read" ] && [ "$3" = "ProvisionToken" ]; then
echo "$FAKE_TOKEN"
exit 0
fi
exit 1
STUB
chmod +x "$STUBBIN/defaults"
FAILURES=0
fail() {
echo "FAIL: $1" >&2
FAILURES=$((FAILURES + 1))
}
assert_eq() {
# assert_eq <actual> <expected> <description>
if [ "$1" != "$2" ]; then
fail "$3 (expected '$2', got '$1')"
fi
}
assert_contains() {
# assert_contains <haystack> <needle> <description>
case "$1" in
*"$2"*) ;;
*) fail "$3 (expected to find '$2')" ;;
esac
}
assert_not_contains() {
# assert_not_contains <haystack> <needle> <description>
case "$1" in
*"$2"*) fail "$3 (must not contain '$2')" ;;
*) ;;
esac
}
# run_postinstall runs postinstall with the given plist/ctrld overrides and
# a private TMPDIR, so the caller can check that the postinstall's own
# capture file (created inside that TMPDIR via mktemp) does not survive.
run_postinstall() {
plist_override=$1
ctrld_override=$2
capture_tmpdir=$3
output=$(PATH="$STUBBIN:$PATH" \
TMPDIR="$capture_tmpdir" \
CTRLD_POSTINSTALL_PLIST="$plist_override" \
CTRLD_POSTINSTALL_CTRLD="$ctrld_override" \
CTRLD_POSTINSTALL_PREFS="/does/not/matter" \
sh "$POSTINSTALL" 2>&1)
exit_code=$?
}
# --- Failure case: ctrld reports a listener bind failure ---------------
failure_dir="$WORKDIR/failure"
failure_tmp="$failure_dir/tmp"
mkdir -p "$failure_tmp"
failure_plist="$failure_dir/ctrld.plist"
failure_ctrld="$failure_dir/ctrld"
cat > "$failure_ctrld" <<'STUB'
#!/bin/sh
# Stands in for a ctrld that fails to bind its listener: echoes the raw
# token (as ctrld's own error output may) plus the fixed-format failure
# identifier behind a log-style prefix, then exits with the stage code.
echo "$FAKE_TOKEN"
echo "2024-01-01T00:00:00Z ERR ctrld: provisioning failed: stage=listener code=LISTENER_BIND_FAILED (exit 41)"
exit 41
STUB
chmod +x "$failure_ctrld"
run_postinstall "$failure_plist" "$failure_ctrld" "$failure_tmp"
assert_eq "$exit_code" "1" "failure case: postinstall exit code"
assert_contains "$output" "stage=listener" "failure case: output names the stage"
assert_contains "$output" "LISTENER_BIND_FAILED" "failure case: output names the code"
assert_contains "$output" "41" "failure case: output names the exit code"
assert_not_contains "$output" "$FAKE_TOKEN" "failure case: output must not contain the provision token"
leftover=$(ls -A "$failure_tmp" 2>/dev/null)
assert_eq "$leftover" "" "failure case: capture temp file removed"
# --- Success case: ctrld provisions and writes the plist ----------------
success_dir="$WORKDIR/success"
success_tmp="$success_dir/tmp"
mkdir -p "$success_tmp"
success_plist="$success_dir/ctrld.plist"
success_ctrld="$success_dir/ctrld"
cat > "$success_ctrld" <<STUB
#!/bin/sh
# Stands in for a ctrld that provisions successfully: writes the plist
# postinstall's success gate checks for, then exits clean.
: > "$success_plist"
exit 0
STUB
chmod +x "$success_ctrld"
run_postinstall "$success_plist" "$success_ctrld" "$success_tmp"
assert_eq "$exit_code" "0" "success case: postinstall exit code"
assert_contains "$output" "provisioning complete" "success case: output mentions success"
if [ "$FAILURES" -gt 0 ]; then
echo "$FAILURES assertion(s) failed" >&2
exit 1
fi
echo "OK: postinstall surfaces provisioning failure codes without leaking the token"
exit 0