Race condition in GCL update causes spurious "Released in newer Snapshot" message #1453
Description
Bug Description
Component snapshots created by PAC push events are incorrectly marked as "Released in newer Snapshot" even when they are the only build for that component. This prevents auto-release from occurring.
I gather as much data as possible to understand the in and out, and spent some LLM token (Claude Opus 4.5) to figure out the issue.
Below is the output of this investigation/interaction after some verification.
Root Cause
In gitops/snapshot.go, the function UpdateComponentImageAndSource() uses time.Now() when called with a Snapshot object instead of using the snapshot's BuildPipelineRunStartTime annotation:
https://github.com/konflux-ci/integration-service/blob/main/gitops/snapshot.go#L1486-L1488
if _, ok := object.(*applicationapiv1alpha1.Snapshot); ok {
buildTimeStr = strconv.FormatInt(time.Now().Unix(), 10) // BUG: should use snapshot's BuildPipelineRunStartTime
}This causes the component's BuildPipelineLastBuiltTime annotation i.e: test.appstudio.openshift.io/lastbuilttime to be set to a timestamp after the snapshot's BuildPipelineRunStartTime i.e: test.appstudio.openshift.io/pipelinerunstarttime, resulting in a false positive in isSnapshotOlderThanLastBuild().
The bug would have been introduced by 64579c7 and 5dfda24
Flow Diagram
sequenceDiagram
autonumber
participant PLR as Build PLR Controller
participant Comp as Component CR
participant Snap as Snapshot CR
participant SnapCtrl as Snapshot Controller
Note over PLR: Build PipelineRun completes<br/>StartTime = 06:08:59
PLR->>Comp: EnsureGlobalCandidateImageUpdated()<br/>UpdateComponentImageAndSource(pipelineRun)
Note over Comp: BuildPipelineLastBuiltTime = "06:08:59" ✓<br/>(from pipelineRun.Status.StartTime)
PLR->>Snap: EnsureSnapshotExists()
Note over Snap: Created with<br/>BuildPipelineRunStartTime = "06:08:59"
Note over SnapCtrl: Snapshot reconciliation starts
SnapCtrl->>Snap: EnsureAllReleasesExist()
SnapCtrl->>Comp: isSnapshotOlderThanLastBuild()?
Note over SnapCtrl: 06:08:59 < 06:08:59 ? NO<br/>→ Should create releases ✓
SnapCtrl->>Comp: EnsureGlobalCandidateImageUpdated()<br/>updateGCLForComponentSnapshot()<br/>UpdateComponentImageAndSource(snapshot)
Note over Comp: ⚠️ BUG: BuildPipelineLastBuiltTime = "06:09:01"<br/>(uses time.Now() instead of snapshot annotation!)
Note over SnapCtrl: Later reconciliation
SnapCtrl->>Snap: EnsureAllReleasesExist()
SnapCtrl->>Comp: isSnapshotOlderThanLastBuild()?
Note over SnapCtrl: 06:08:59 < 06:09:01 ? YES<br/>→ ❌ "Released in newer Snapshot"
The Bug Comparison
flowchart TD
A[EnsureAllReleasesExist] --> B{ReleasePlans exist?}
B -->|No| C[Skip auto-release]
B -->|Yes| D[isSnapshotOlderThanLastBuild?]
D --> E["Get Snapshot.BuildPipelineRunStartTime<br/>(06:08:59)"]
E --> F["Get Component.BuildPipelineLastBuiltTime<br/>(06:09:01 - set by time.Now BUG)"]
F --> G{"snapshotTime < componentTime?<br/>06:08:59 < 06:09:01"}
G -->|"YES ❌"| H["Released in newer Snapshot"<br/>No releases created!]
G -->|NO| I[Create releases ✓]
style H fill:#ff6666,stroke:#333
style I fill:#66ff66,stroke:#333
UpdateComponentImageAndSource() Bug
flowchart TD
subgraph current ["Current Behavior (BUG)"]
A1[Called with Snapshot] --> B1["Use time.Now()"]
B1 --> C1["BuildPipelineLastBuiltTime = NOW ❌"]
end
subgraph expected ["Expected Behavior (FIX)"]
A2[Called with Snapshot] --> B2["Get BuildPipelineRunStartTime<br/>from snapshot annotation"]
B2 --> C2["BuildPipelineLastBuiltTime = StartTime ✓"]
end
style C1 fill:#ff6666,stroke:#333
style C2 fill:#66ff66,stroke:#333
Observed Behavior
Example data from the Fedora Konflux cluster https://konflux.fedoraproject.org/ns/bootc-tenant/applications/fedora-bootc-42 :
| Snapshot | Component | BuildPipelineRunStartTime | Component LastBuiltTime | Result |
|---|---|---|---|---|
| fedora-bootc-42-7zmsl | fedora-bootc-42-iot | 06:08:59 | 06:09:01 | "Released in newer Snapshot" |
| fedora-bootc-42-dv59m | fedora-bootc-42-minimal-plus | 06:08:59 | 06:09:01 | "Released in newer Snapshot" |
| fedora-bootc-42-4qcrw | fedora-bootc-42-minimal | 06:08:59 | 06:09:01 | "Released in newer Snapshot" |
| fedora-bootc-42-xp4fd | fedora-bootc-42-standard | 06:08:58 | 06:09:02 | "Released in newer Snapshot" |
The ~2-4 second difference is caused by time.Now() being called when the Snapshot Controller reconciles the snapshot, overwriting the correct value set by the Build PLR Controller.
Expected Behavior
The snapshot should be auto-released since it represents the latest (and only) build for the component.
Proposed Fix
Modify UpdateComponentImageAndSource() in gitops/snapshot.go to use the snapshot's BuildPipelineRunStartTime annotation instead of time.Now():
diff --git a/gitops/snapshot.go b/gitops/snapshot.go
index ...... 100644
--- a/gitops/snapshot.go
+++ b/gitops/snapshot.go
@@ -1483,8 +1483,19 @@ func UpdateComponentImageAndSource(ctx context.Context, adapterClient client.Cli
buildTimeStr = strconv.FormatInt(pr.Status.StartTime.Unix(), 10)
}
}
- if _, ok := object.(*applicationapiv1alpha1.Snapshot); ok {
- buildTimeStr = strconv.FormatInt(time.Now().Unix(), 10)
+ if snapshot, ok := object.(*applicationapiv1alpha1.Snapshot); ok {
+ if startTimeStr, found := snapshot.Annotations[BuildPipelineRunStartTime]; found && startTimeStr != "" {
+ startTimeMillis, err := strconv.ParseInt(startTimeStr, 10, 64)
+ if err == nil {
+ // Convert milliseconds to seconds if needed
+ if startTimeMillis > 10000000000 {
+ startTimeMillis = startTimeMillis / 1000
+ }
+ buildTimeStr = strconv.FormatInt(startTimeMillis, 10)
+ } else {
+ buildTimeStr = strconv.FormatInt(time.Now().Unix(), 10)
+ }
+ } else {
+ buildTimeStr = strconv.FormatInt(time.Now().Unix(), 10)
+ }
}
return AnnotateComponent(ctx, component, BuildPipelineLastBuiltTime, buildTimeStr, adapterClient)
}