diff --git a/pkg/leeway/build.go b/pkg/leeway/build.go index 7087195..911ba66 100644 --- a/pkg/leeway/build.go +++ b/pkg/leeway/build.go @@ -57,6 +57,10 @@ const ( PackageDownloaded PackageBuildStatus = "downloaded" // PackageInRemoteCache means the package has been built but currently only exists in the remote cache PackageInRemoteCache PackageBuildStatus = "built-remotely" + // PackageVerificationFailed means the package download was attempted but SLSA verification failed + PackageVerificationFailed PackageBuildStatus = "verification-failed" + // PackageDownloadFailed means the package download was attempted but failed + PackageDownloadFailed PackageBuildStatus = "download-failed" ) type buildContext struct { @@ -621,6 +625,7 @@ func Build(pkg *Package, opts ...BuildOption) (err error) { pkgsWillBeDownloaded := make(map[*Package]struct{}) pkg.packagesToDownload(pkgsInLocalCache, pkgsInRemoteCacheMap, pkgsWillBeDownloaded) + // Set initial status before download pkgstatus := make(map[*Package]PackageBuildStatus) unresolvedArgs := make(map[string][]string) for _, dep := range allpkg { @@ -633,7 +638,8 @@ func Build(pkg *Package, opts ...BuildOption) (err error) { } else if existsInLocalCache { pkgstatus[dep] = PackageBuilt } else if willBeDownloaded { - pkgstatus[dep] = PackageDownloaded + // Don't set to `PackageDownloaded` yet as we haven't downloaded it! + pkgstatus[dep] = PackageInRemoteCache } else if existsInRemoteCache { pkgstatus[dep] = PackageInRemoteCache } else { @@ -669,9 +675,27 @@ func Build(pkg *Package, opts ...BuildOption) (err error) { pkgsToDownloadCache[i] = p } + // Errors are logged but don't fail the build err = ctx.RemoteCache.Download(context.Background(), ctx.LocalCache, pkgsToDownloadCache) if err != nil { - return err + // Download errors are already logged by the cache implementation + // We continue with local builds for packages that failed to download + log.WithError(err).Debug("Remote cache download completed with some errors") + } + + // Update status based on actual outcome - check what's actually in local cache now + for _, p := range pkgsToDownload { + if _, nowInCache := ctx.LocalCache.Location(p); nowInCache { + // Successfully downloaded and verified + pkgstatus[p] = PackageDownloaded + } else { + // Download failed or verification failed: we will need to build locally + // TODO: Distinguish between download failures and verification failures. + // Currently can't tell because Download() returns nil on errors (by design for graceful fallback). + // To fix: Change RemoteCache.Download() to return map[string]DownloadResult with typed status, + // then use PackageDownloadFailed vs PackageVerificationFailed appropriately. + pkgstatus[p] = PackageNotBuiltYet + } } ctx.Reporter.BuildStarted(pkg, pkgstatus) @@ -737,9 +761,86 @@ func Build(pkg *Package, opts ...BuildOption) (err error) { } } + // Print build summary + printBuildSummary(ctx, pkg, allpkg, pkgstatus, pkgsToDownload) + return nil } +// printBuildSummary prints a summary of the build showing what was cached, downloaded, and built +func printBuildSummary(ctx *buildContext, targetPkg *Package, allpkg []*Package, initialStatus map[*Package]PackageBuildStatus, pkgsToDownload []*Package) { + var ( + builtLocally int + downloaded int + alreadyCached int + total int + ) + + newlyBuilt := ctx.GetNewPackagesForCache() + newlyBuiltMap := make(map[string]bool) + for _, p := range newlyBuilt { + newlyBuiltMap[p.FullName()] = true + } + + // Track packages that were supposed to be downloaded but weren't + // These likely failed verification or download + var failedDownloads []*Package + pkgsToDownloadMap := make(map[string]bool) + for _, p := range pkgsToDownload { + pkgsToDownloadMap[p.FullName()] = true + } + + for _, p := range allpkg { + total++ + + // Check actual state in local cache + _, inCache := ctx.LocalCache.Location(p) + + if !inCache { + // Package not in cache (shouldn't happen if build succeeded) + continue + } + + // Determine what happened to this package + if newlyBuiltMap[p.FullName()] { + // Package was built during this build + builtLocally++ + + // Check if this was supposed to be downloaded but wasn't + // This indicates verification or download failure + if pkgsToDownloadMap[p.FullName()] && initialStatus[p] != PackageDownloaded { + failedDownloads = append(failedDownloads, p) + } + } else if initialStatus[p] == PackageDownloaded { + // Package was downloaded + downloaded++ + } else if initialStatus[p] == PackageBuilt { + // Package was already cached + alreadyCached++ + } else { + // Package was in cache but we're not sure how it got there + // This could happen if it was built as a dependency + alreadyCached++ + } + } + + log.WithFields(log.Fields{ + "target": targetPkg.FullName(), + "total": total, + "cached_locally": alreadyCached, + "downloaded": downloaded, + "built_locally": builtLocally, + }).Info("Build completed") + + // Highlight packages that failed verification/download + if len(failedDownloads) > 0 { + log.WithField("count", len(failedDownloads)).Warn("Some packages failed verification or download and were rebuilt locally") + for _, p := range failedDownloads { + log.WithField("package", p.FullName()).Warn(" - failed to download/verify, rebuilt locally") + } + } +} + func writeBuildPlan(out io.Writer, pkg *Package, status map[*Package]PackageBuildStatus) error { // BuildStep is a list of packages that can be built in parallel type BuildStep []string @@ -797,6 +898,11 @@ func (p *Package) buildDependencies(buildctx *buildContext) error { return nil } + log.WithFields(log.Fields{ + "package": p.FullName(), + "dependencies": len(deps), + }).Debug("building dependencies") + // Use errgroup to simplify error handling and synchronization g := new(errgroup.Group) @@ -809,7 +915,18 @@ func (p *Package) buildDependencies(buildctx *buildContext) error { } // Wait for all goroutines to complete, returning the first error encountered - return g.Wait() + err := g.Wait() + if err != nil { + log.WithFields(log.Fields{ + "package": p.FullName(), + }).Error("dependency build failed") + return err + } + + log.WithFields(log.Fields{ + "package": p.FullName(), + }).Debug("all dependencies built successfully") + return nil } func (p *Package) build(buildctx *buildContext) (err error) { @@ -817,21 +934,30 @@ func (p *Package) build(buildctx *buildContext) (err error) { doBuild := buildctx.ObtainBuildLock(p) if !doBuild { // Another goroutine is already building this package + log.WithField("package", p.FullName()).Debug("another goroutine is building this package") return nil } defer buildctx.ReleaseBuildLock(p) + // Check if already built before building dependencies + if _, alreadyBuilt := buildctx.LocalCache.Location(p); !p.Ephemeral && alreadyBuilt { + log.WithField("package", p.FullName()).Debug("package already in local cache, skipping") + return nil + } + // Build dependencies first if err := p.buildDependencies(buildctx); err != nil { return err } - // Skip if package is already built (except for ephemeral packages) + // Check again after dependencies - might have been built as a dependency if _, alreadyBuilt := buildctx.LocalCache.Location(p); !p.Ephemeral && alreadyBuilt { - log.WithField("package", p.FullName()).Debug("already built") + log.WithField("package", p.FullName()).Info("package was built as dependency, skipping") return nil } + log.WithField("package", p.FullName()).Info("building package locally") + // Initialize package build report pkgRep := &PackageBuildReport{ phaseEnter: make(map[PackageBuildPhase]time.Time), diff --git a/pkg/leeway/cache/remote/s3.go b/pkg/leeway/cache/remote/s3.go index e25c21d..a879174 100644 --- a/pkg/leeway/cache/remote/s3.go +++ b/pkg/leeway/cache/remote/s3.go @@ -44,6 +44,16 @@ type downloadResult struct { kind string // "artifact" or "attestation" } +// VerificationFailedError is returned when SLSA verification fails +type VerificationFailedError struct { + Package string + Reason string +} + +func (e VerificationFailedError) Error() string { + return fmt.Sprintf("SLSA verification failed for %s: %s", e.Package, e.Reason) +} + // S3Config holds the configuration for S3Cache type S3Config struct { BucketName string @@ -462,6 +472,10 @@ func (s *S3Cache) downloadWithSLSAVerification(ctx context.Context, p cache.Pack {".tar", 2}, } + // Track whether we attempted verification and it failed + var verificationAttempted bool + var lastVerificationError error + for _, attempt := range downloadAttempts { artifactKey := fmt.Sprintf("%s%s", version, attempt.extension) attestationKey := slsa.AttestationKey(artifactKey) @@ -527,11 +541,19 @@ func (s *S3Cache) downloadWithSLSAVerification(ctx context.Context, p cache.Pack } // Step 4: Verify the artifact against attestation + log.WithFields(log.Fields{ + "package": p.FullName(), + "artifact": artifactKey, + "attestation": attestationKey, + }).Debug("Starting SLSA verification") + verifyStart := time.Now() verifyErr := s.slsaVerifier.VerifyArtifact(ctx, tmpArtifactPath, tmpAttestationPath) verifyDuration := time.Since(verifyStart) if verifyErr != nil { + verificationAttempted = true + lastVerificationError = verifyErr log.WithError(verifyErr).WithFields(log.Fields{ "package": p.FullName(), "artifact": artifactKey, @@ -543,6 +565,12 @@ func (s *S3Cache) downloadWithSLSAVerification(ctx context.Context, p cache.Pack continue } + log.WithFields(log.Fields{ + "package": p.FullName(), + "artifact": artifactKey, + "duration": verifyDuration, + }).Debug("SLSA verification succeeded") + // Step 5: Atomically move verified artifact to final location if err := s.atomicMove(tmpArtifactPath, localPath); err != nil { log.WithError(err).WithField("package", p.FullName()).Warn("Failed to move verified artifact") @@ -567,6 +595,19 @@ func (s *S3Cache) downloadWithSLSAVerification(ctx context.Context, p cache.Pack } // All attempts failed + if verificationAttempted { + // Verification was attempted but failed - return error to distinguish from "no artifacts" + log.WithFields(log.Fields{ + "package": p.FullName(), + "version": version, + }).Warn("SLSA verification failed for all attempts, will build locally") + return VerificationFailedError{ + Package: p.FullName(), + Reason: fmt.Sprintf("verification failed: %v", lastVerificationError), + } + } + + // No artifacts found or no verification attempted log.WithFields(log.Fields{ "package": p.FullName(), "version": version, diff --git a/pkg/leeway/reporter.go b/pkg/leeway/reporter.go index a5ebe61..3afc80b 100644 --- a/pkg/leeway/reporter.go +++ b/pkg/leeway/reporter.go @@ -160,13 +160,18 @@ func (r *ConsoleReporter) BuildStarted(pkg *Package, status map[*Package]Package } format := "%s\t%s\t%s\n" - if status == PackageBuilt { + switch status { + case PackageBuilt: lines[i] = fmt.Sprintf(format, color.Green.Sprint("📦\tcached locally"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) - } else if status == PackageInRemoteCache { - lines[i] = fmt.Sprintf(format, color.Green.Sprint("🌎\tcached remotely (ignored)"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) - } else if status == PackageDownloaded { + case PackageInRemoteCache: + lines[i] = fmt.Sprintf(format, color.Green.Sprint("🌎\tcached remotely (available)"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) + case PackageDownloaded: lines[i] = fmt.Sprintf(format, color.Green.Sprint("📥\tcached remotely (downloaded)"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) - } else { + case PackageVerificationFailed: + lines[i] = fmt.Sprintf(format, color.Yellow.Sprint("⚠️\tverification failed (will rebuild)"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) + case PackageDownloadFailed: + lines[i] = fmt.Sprintf(format, color.Yellow.Sprint("⚠️\tdownload failed (will rebuild)"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) + default: lines[i] = fmt.Sprintf(format, color.Yellow.Sprint("🔧\tbuild"), pkg.FullName(), color.Gray.Sprintf("(version %s)", version)) } i++