Bug 1827166 - fail to block y version upgrade when set upgradeable=false
Summary: fail to block y version upgrade when set upgradeable=false
Keywords:
Status: CLOSED DUPLICATE of bug 1826115
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Cluster Version Operator
Version: 4.3.z
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: 4.6.0
Assignee: W. Trevor King
QA Contact: liujia
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-04-23 11:48 UTC by liujia
Modified: 2020-08-08 21:04 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-08-08 21:04:43 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
cvo.log (237.18 KB, text/plain)
2020-04-23 11:52 UTC, liujia
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Github openshift cluster-version-operator pull 360 0 None closed Bug 1827166: pkg/cvo/sync_worker: Log precondition handling 2021-02-20 02:14:09 UTC

Description liujia 2020-04-23 11:48:31 UTC
Description of problem:
Enable featuregate to trigger upgradeable=false condition. Y version upgrade from v4.3 to v4.4 was not blocked.

Version-Release number of the following components:
v4.3.15-4.4.0-rc.11

How reproducible:
always

Steps to Reproduce:
1. Install v4.3.15
2. Enable featuregate to trigger upgradeable=false condition
{
    "lastTransitionTime": "2020-04-23T10:51:07Z",
    "message": "Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: \"TechPreviewNoUpgrade\" does not allow updates",
    "reason": "FeatureGates_RestrictedFeatureGates_TechPreviewNoUpgrade",
    "status": "False",
    "type": "Upgradeable"
  }

3. Patch cv to fast-4.4 channel and do upgrade
# ./oc adm upgrade --to 4.4.0-rc.11
Updating to 4.4.0-rc.11
...
# ./oc adm upgrade
info: An upgrade is in progress. Working towards 4.4.0-rc.11: downloading update
...
# ./oc adm upgrade
info: An upgrade is in progress. Unable to apply 4.4.0-rc.11: the update could not be applied
...
# ./oc adm upgrade
info: An upgrade is in progress. Working towards 4.4.0-rc.11: 83% complete

At last, upgrade successfully.

# ./oc get clusterversion -o json|jq -r '.items[0].status.history[]'
{
  "completionTime": "2020-04-23T11:44:30Z",
  "image": "quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07",
  "startedTime": "2020-04-23T10:54:08Z",
  "state": "Completed",
  "verified": true,
  "version": "4.4.0-rc.11"
}
{
  "completionTime": "2020-04-23T10:32:08Z",
  "image": "quay.io/openshift-release-dev/ocp-release@sha256:0e9642d28c12f5f54c1ab0fffbfd866daa6179a900e745a935f17f8e6e1e28fc",
  "startedTime": "2020-04-23T10:15:06Z",
  "state": "Completed",
  "verified": false,
  "version": "4.3.15"
}

Actual results:
Upgrade can bump successfully.

Expected results:
Upgrade should be blocked.

Additional info:
Please attach logs from ansible-playbook with the -vvv flag

Comment 1 liujia 2020-04-23 11:52:33 UTC
Created attachment 1681092 [details]
cvo.log

Comment 5 W. Trevor King 2020-04-23 22:17:11 UTC
Moved to 4.5.  My hunch is that this is a race where the CVO is delayed in noticing the ClusterOperator setting Upgradeable=False (from comment 0, the delay was from the 10:51:07 ClusterOperator change to the 10:54:08 update initialization, so ~3m).  If that's the issue, this is probably low or medium priority.  If the CVO continues to allow this sort of thing even with a longer delay (10m?), then it's probably high/urgent and... not sure how likely it is to get named a 4.4.0 blocker.  But it would be close.  Will test with a longer delay...

Comment 6 W. Trevor King 2020-04-24 18:03:56 UTC
Sadly, seem like "not a race".

$ oc get -o json clusterversion version | jq -r .status.desired.version
4.3.15
$ oc patch clusterversion version --type json -p '[{"op": "add", "path": "/spec/channel", "value": "candidate-4.4"}]'
$ oc patch featuregate cluster --type json -p '[{"op": "add", "path": "/spec/featureSet", "value": "TechPreviewNoUpgrade"}]'
$ sleep 600

Meanwhile, in a second terminal:

$ oc -n openshift-cluster-version get pods
NAME                                        READY   STATUS    RESTARTS   AGE
cluster-version-operator-5fb76fc5cc-bwngd   1/1     Running   0          18m
$ oc -n openshift-cluster-version logs -f cluster-version-operator-5fb76fc5cc-bwngd
...

Then, post-sleep:

$ oc adm upgrade --to 4.4.0-rc.11
Updating to 4.4.0-rc.11
$ oc adm upgrade
info: An upgrade is in progress. Working towards 4.4.0-rc.11: 17% complete
...

Back to the streamed logs from the second terminal:

I0424 17:34:31.777559       1 cvo.go:471] Desired version from operator is v1.Update{Version:"4.3.15", Image:"registry.svc.ci.openshift.org/ocp/release@sha256:0e9642d28c12f5f54c1ab0fffbfd866daa6179a900e745a935f17f8e6e1e28fc", Force:false}
I0424 17:34:31.778304       1 cvo.go:441] Finished syncing cluster version "openshift-cluster-version/version" (832.691µs)
I0424 17:34:38.952861       1 cvo.go:526] Started syncing upgradeable "openshift-cluster-version/version" (2020-04-24 17:34:38.952853217 +0000 UTC m=+2140.667929080)
I0424 17:34:38.952926       1 upgradeable.go:28] Upgradeable conditions were recently checked, will try later.
...
I0424 17:34:38.953036       1 cvo.go:468] Desired version from spec is v1.Update{Version:"4.4.0-rc.11", Image:"quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07", Force:false}
I0424 17:34:38.953144       1 cvo.go:441] Finished syncing cluster version "openshift-cluster-version/version" (178.62µs)
I0424 17:34:38.953190       1 sync_worker.go:471] Running sync 4.4.0-rc.11 (force=false) on generation 3 in state Updating at attempt 0
I0424 17:34:38.953203       1 sync_worker.go:477] Loading payload
I0424 17:34:38.953229       1 store.go:74] use cached most recent signature config maps
I0424 17:34:38.959158       1 store.go:65] remember most recent signature config maps: signatures-managed
I0424 17:34:38.959187       1 store.go:116] searching for sha256-6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 in signature config map signatures-managed
I0424 17:34:46.777483       1 cvo.go:439] Started syncing cluster version "openshift-cluster-version/version" (2020-04-24 17:34:46.777469065 +0000 UTC m=+2148.492544927)
I0424 17:34:46.777549       1 cvo.go:468] Desired version from spec is v1.Update{Version:"4.4.0-rc.11", Image:"quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400d\
d8df98cd2d6f07", Force:false}
I0424 17:34:46.786577       1 cvo.go:441] Finished syncing cluster version "openshift-cluster-version/version" (9.099581ms)
I0424 17:34:46.786775       1 cvo.go:439] Started syncing cluster version "openshift-cluster-version/version" (2020-04-24 17:34:46.786769485 +0000 UTC m=+2148.501845310)
I0424 17:34:46.786818       1 cvo.go:468] Desired version from spec is v1.Update{Version:"4.4.0-rc.11", Image:"quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400d\
d8df98cd2d6f07", Force:false}
I0424 17:34:46.786930       1 cvo.go:441] Finished syncing cluster version "openshift-cluster-version/version" (157.544µs)
I0424 17:34:46.786583       1 cvo.go:526] Started syncing upgradeable "openshift-cluster-version/version" (2020-04-24 17:34:46.786573984 +0000 UTC m=+2148.501649839)
I0424 17:34:46.786962       1 upgradeable.go:28] Upgradeable conditions were recently checked, will try later.
I0424 17:34:46.786968       1 cvo.go:528] Finished syncing upgradeable "openshift-cluster-version/version" (391.505µs)
I0424 17:34:46.786589       1 cvo.go:503] Started syncing available updates "openshift-cluster-version/version" (2020-04-24 17:34:46.786583501 +0000 UTC m=+2148.501659341)
I0424 17:34:46.786988       1 availableupdates.go:39] Available updates were recently retrieved, will try later.
I0424 17:34:46.786993       1 cvo.go:505] Finished syncing available updates "openshift-cluster-version/version" (407.771µs)
I0424 17:34:48.148622       1 payload.go:210] Loading updatepayload from "/etc/cvo/updatepayloads/3dV_-8XN1JB7Qodu_msYrg"
I0424 17:34:48.595128       1 sync_worker.go:539] Payload loaded from quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 with hash KYpQ0Ba7y-Y=
...
I0424 17:34:48.657875       1 sync_worker.go:621] Running sync for deployment "openshift-cluster-version/cluster-version-operator" (5 of 573)
I0424 17:34:48.674142       1 apps.go:115] Deployment cluster-version-operator is not ready. status: (replicas: 1, updated: 1, ready: 1, unavailable: 0)
I0424 17:34:48.736146       1 start.go:140] Shutting down due to terminated
I0424 17:34:48.736355       1 start.go:188] Stepping down as leader
I0424 17:34:48.736790       1 cvo.go:439] Started syncing cluster version "openshift-cluster-version/version" (2020-04-24 17:34:48.736780502 +0000 UTC m=+2150.451856328)
I0424 17:34:48.736841       1 task_graph.go:583] Canceled worker 12
E0424 17:34:48.736877       1 task.go:77] error running apply for deployment "openshift-cluster-version/cluster-version-operator" (5 of 573): timed out waiting for the condition
...
I0424 17:34:48.740667       1 task_graph.go:603] Workers finished
I0424 17:34:48.740681       1 task_graph.go:611] Result of work: [Could not update deployment "openshift-cluster-version/cluster-version-operator" (5 of 573)]
I0424 17:34:48.740701       1 sync_worker.go:783] Summarizing 1 errors
I0424 17:34:48.740709       1 sync_worker.go:787] Update error 5 of 573: UpdatePayloadFailed Could not update deployment "openshift-cluster-version/cluster-version-operator" (5 of 573) (*errors.errorString: timed out waiting for the condition)
E0424 17:34:48.740738       1 sync_worker.go:329] unable to synchronize image (waiting 1m26.262851224s): Could not update deployment "openshift-cluster-version/cluster-version-operator" (5 of 573)
I0424 17:34:48.740240       1 task_graph.go:531] No more reachable nodes in graph, continue
I0424 17:34:48.740761       1 task_graph.go:567] No more work
I0424 17:34:48.740912       1 cvo.go:468] Desired version from spec is v1.Update{Version:"4.4.0-rc.11", Image:"quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07", Force:false}
I0424 17:34:48.816852       1 cvo.go:441] Finished syncing cluster version "openshift-cluster-version/version" (80.060854ms)
I0424 17:34:48.816980       1 cvo.go:366] Shutting down ClusterVersionOperator
I0424 17:34:48.863476       1 start.go:199] Finished shutdown

I see the signature check happening, but do not see any evidence of the upgradeable precondition check happening.  On the other hand, our only precondition logging is the negative "check failed" [1].  I've filed [2] to get the CVO to explain itself.

[1]: https://github.com/openshift/cluster-version-operator/blob/86b9bdba55a85e2e071603916db4c43b481e7588/pkg/payload/precondition/precondition.go#L74
[2]: https://github.com/openshift/cluster-version-operator/pull/360

Comment 7 W. Trevor King 2020-04-24 18:54:53 UTC
Trying to test now with [1] -> 4.4.

[1]: https://github.com/openshift/cluster-version-operator/pull/362

Comment 8 W. Trevor King 2020-04-24 19:39:22 UTC
Running from cvo#362:

$ oc get -o json clusterversion version | jq -r .status.desired.version
0.0.1-2020-04-24-185833
$ oc patch featuregate cluster --type json -p '[{"op": "add", "path": "/spec/featureSet", "value": "TechPreviewNoUpgrade"}]'

In another terminal:

$ oc -n openshift-cluster-version get pods
NAME                                        READY   STATUS    RESTARTS   AGE
cluster-version-operator-57d9c446df-2s24g   1/1     Running   0          24m
$ oc -n openshift-cluster-version logs -f cluster-version-operator-57d9c446df-2s24g | tee cvo.log

Then trigger the update:

$ oc adm release info quay.io/openshift-release-dev/ocp-release:4.4.0-rc.11-x86_64 | grep Pull
Pull From: quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07
$ oc adm upgrade --allow-explicit-upgrade --to-image quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07
$ oc get -o json clusterversion version | jq -r '.status.conditions[] | .lastTransitionTime + " " + .type + " " + .status + " " + .message' | sort
2020-04-24T19:06:24Z RetrievedUpdates False Unable to retrieve available updates: currently installed version 0.0.1-2020-04-24-185833 not found in the "stable-4.3" channel
2020-04-24T19:23:07Z Available True Done applying 0.0.1-2020-04-24-185833
2020-04-24T19:32:20Z Upgradeable False Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates
2020-04-24T19:32:22Z Failing True The update cannot be verified: unable to locate a valid signature for one or more sources
2020-04-24T19:32:22Z Progressing True Unable to apply quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07: the image may not be safe to use

Grr.  I guess I'll force:

$ oc adm upgrade --clear
$ oc adm upgrade --force --allow-explicit-upgrade --to-image quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07
Updating to release image quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07

Checking the gathered logs:

I0424 19:36:50.605797       1 verify.go:298] Unable to verify sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 against keyring verifier-public-key-openshift-ci
W0424 19:36:50.606081       1 updatepayload.go:100] An image was retrieved from "quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07" that failed verification: The update cannot be verified: unable to locate a valid signature for one or more sources
I0424 19:36:50.606690       1 payload.go:210] Loading updatepayload from "/etc/cvo/updatepayloads/3dV_-8XN1JB7Qodu_msYrg"
E0424 19:36:51.604090       1 precondition.go:59] Precondition "ClusterVersionUpgradeable" failed: Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates
I0424 19:36:51.604316       1 sync_worker.go:530] Forcing past precondition failures: Precondition "ClusterVersionUpgradeable" failed because of "FeatureGates_RestrictedFeatureGates_TechPreviewNoUpgrade": Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates
I0424 19:36:51.604404       1 sync_worker.go:547] Payload loaded from quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 with hash KYpQ0Ba7y-Y=

So that looks right.  Not sure why that precondition wasn't failing when I was starting from 4.3.15.

Should eventually get CI logs for this cluster up at [1], for folks who want to poke around.

[1]: https://prow.svc.ci.openshift.org/view/gcs/origin-ci-test/logs/release-openshift-origin-installer-launch-gcp/538

Comment 10 W. Trevor King 2020-04-25 04:49:25 UTC
Coming in again, with a new run from cvo#362:

$ oc get -o json clusterversion version | jq -r .status.desired.version
0.0.1-2020-04-25-041030
$ oc patch featuregate cluster --type json -p '[{"op": "add", "path": "/spec/featureSet", "value": "TechPreviewNoUpgrade"}]'
$ oc get -o json clusteroperator kube-apiserver | jq -r '.status.conditions[] | select(.type == "Upgradeable") | .lastTransitionTime + " " + .type + " " + .status + " " + .message'
2020-04-25T04:43:21Z Upgradeable False FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates
$ oc get -o json clusterversion version | jq -r '.status.conditions[] | select(.type == "Upgradeable") | .lastTransitionTime + " " + .type + " " + .status + " " + .message'
...no output; CVO hasn't noticed yet...
$ oc get -o json clusterversion version | jq -r '.status.conditions[] | select(.type == "Upgradeable") | .lastTransitionTime + " " + .type + " " + .status + " " + .message'
2020-04-25T04:44:58Z Upgradeable False Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates

In another terminal:

$ oc -n openshift-cluster-version get pods
NAME                                        READY   STATUS    RESTARTS   AGE
cluster-version-operator-687b7d7f89-655zb   1/1     Running   0          20m
$ oc -n openshift-cluster-version logs -f --tail=1 cluster-version-operator-687b7d7f89-655zb | tee cvo.log

Looks like we don't sign CI builds at all at the moment, although I've opened [1] to allow CI -> offical updates.  Anyhow, forcing again:

$ oc adm upgrade --force --allow-explicit-upgrade --to-image quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07

Checking the gathered logs:

I0425 04:46:44.858369       1 store.go:116] searching for sha256-6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 in signature config map signatures-managed
I0425 04:46:45.002408       1 verify.go:298] Unable to verify sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 against keyring verifier-public-key-openshift-ci
W0425 04:46:45.002447       1 updatepayload.go:100] An image was retrieved from "quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07" that failed verification: The update cannot be verified: unable to locate a valid signature for one or more sources
...
I0425 04:47:03.025422       1 payload.go:210] Loading updatepayload from "/etc/cvo/updatepayloads/3dV_-8XN1JB7Qodu_msYrg"
E0425 04:47:03.913561       1 precondition.go:59] Precondition "ClusterVersionUpgradeable" failed: Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates
I0425 04:47:03.913609       1 sync_worker.go:530] Forcing past precondition failures: Precondition "ClusterVersionUpgradeable" failed because of "FeatureGates_RestrictedFeatureGates_TechPreviewNoUpgrade": Cluster operator kube-apiserver cannot be upgraded: FeatureGatesUpgradeable: "TechPreviewNoUpgrade" does not allow updates
I0425 04:47:03.913622       1 sync_worker.go:547] Payload loaded from quay.io/openshift-release-dev/ocp-release@sha256:6f09986c2c878f9675afcf9ee5d4720cf8ec0b9b832ab9400dd8df98cd2d6f07 with hash KYpQ0Ba7y-Y=

I dunno, still looks fine to me.  I guess we'll see what happens if we land these debugging logs and then try to take the 4.5-nightly back down to an official 4.4 release.

[1]: https://github.com/openshift/cluster-update-keys/pull/16

Comment 13 W. Trevor King 2020-04-25 14:20:55 UTC
Logging alone is not a fix.

Comment 14 Lalatendu Mohanty 2020-05-19 18:15:45 UTC
Do we know of the upgradeable = false is not blocking the upgrade only when we enable featuregate or for any reason upgradeable = false is set?

Comment 16 W. Trevor King 2020-05-28 17:19:34 UTC
This bug is important and we want to fix it, but we will probably not have time to close it out this sprint.  I'm adding UpcomingSprint now, and we'll revisit next sprint.

Comment 17 W. Trevor King 2020-06-21 14:10:45 UTC
Haven't had time to get to this yet; adding UpcomingSprint

Comment 19 Jack Ottofaro 2020-07-02 15:51:56 UTC
During debug of https://bugzilla.redhat.com/show_bug.cgi?id=1822513, which is also caused by a race condition, I found it very easy to bypass the Preconditions by:

$ oc patch featuregate cluster --type json -p '[{"op": "add", "path": "/spec/featureSet", "value": "TechPreviewNoUpgrade"}]'

Initially cluster_operator_conditions{name=kube-apiserver} is Upgradeable false but it can take ~minutes before cluster_operator_conditions{name=version} is set Upgradeable false during which time Precondition ClusterVersionUpgradeable passes with "no Upgradeable condition on ClusterVersion".

Comment 20 liujia 2020-07-03 02:03:57 UTC
During 4.4.10 to 4.5.0-rc.5 upgrade with default upgradeable condition triggered by marketplace.
We still hit it when do upgrade with --to command(no this issue when run upgrade with --to-image)

# ./oc version
Client Version: 4.5.0-rc.5
Server Version: 4.4.10

Comment 21 Jack Ottofaro 2020-07-06 12:54:57 UTC
If you use --to-image you may be hitting https://bugzilla.redhat.com/show_bug.cgi?id=1822513 which is being caused by the CVO thread that updates version history adds a new cluster version history entry before the thread loading the upgrade version has set the version field resulting in an empty field. The y-version upgrade check then fails and allows the upgrade.

Comment 25 W. Trevor King 2020-07-10 21:38:59 UTC
I'm still not aware of any CVO logs (since we grew the additional logging) from the outgoing pod when we trip whatever the Upgradeable=False bug was.  Punting to UpcomingSprint.

Comment 26 W. Trevor King 2020-08-01 05:39:40 UTC
I'm going to close this INSUFFICIENT_DATA.  If we can get a reproducer with outgoing-CVO logs, we can re-open.

Comment 27 liujia 2020-08-04 07:59:47 UTC
Hi W. Trevor King,

I'm not sure why this bus is closed with INSUFFICIENT_DATA. It's reported in v4.4 for the 1st time with cvo log attached in comment1. And it's not fixed yet so we hit it again during v4.5. Anything missed here?

Comment 28 W. Trevor King 2020-08-04 22:30:11 UTC
[1] landed some additional logging I need to diagnose the issue.  That went out in 4.5, but I'm not aware of any 4.5-to-whatever updates where the outgoing CVO included the new logging and someone captured the outgoing CVO's logs.  If you can get logs with the logging (they will contain 'Precondition ... passed'), please attach them here and reopen the bug.

[1]: https://github.com/openshift/cluster-version-operator/pull/360

Comment 29 liujia 2020-08-05 09:49:40 UTC
sure, i will give a cvo log for 4.5 later.

Comment 30 liujia 2020-08-07 08:54:53 UTC
Still hit it on v4.5.5-v4.6 nightly upgrade with upgradeable=false.

I post both pre and post cvo logs in attachment.

Comment 33 W. Trevor King 2020-08-08 21:04:43 UTC
cvo_pre is a 4.5.5 install that is later asked to move to a 4.6 nightly:

$ grep 'Running sync.*in state' cvo_pre | head -n1
I0807 07:00:06.965053       1 sync_worker.go:471] Running sync 4.5.5 (force=false) on generation 1 in state Initializing at attempt 0
$ grep 'Running sync.*in state' cvo_pre | tail -n1
I0807 08:24:58.441976       1 sync_worker.go:471] Running sync 4.6.0-0.nightly-2020-08-07-034746 (force=false) on generation 11 in state Updating at attempt 0

Here's the transition:

$ grep 'Desired version\|Precondition\|Payload loaded' cvo_pre | tail -n7
I0807 08:24:52.439911       1 cvo.go:469] Desired version from operator is v1.Update{Version:"4.5.5", Image:"quay.io/openshift-release-dev/ocp-release@sha256:a58573e1c92f5258219022ec104ec254ded0a70370ee8ed2aceea52525639bd4", Force:false}
I0807 08:24:58.441689       1 cvo.go:466] Desired version from spec is v1.Update{Version:"4.6.0-0.nightly-2020-08-07-034746", Image:"registry.svc.ci.openshift.org/ocp/release@sha256:53fa74a6d426822340be6bf86a659cbae92de021ade6d2048fa117713e3ec379", Force:false}
I0807 08:25:07.439708       1 cvo.go:466] Desired version from spec is v1.Update{Version:"4.6.0-0.nightly-2020-08-07-034746", Image:"registry.svc.ci.openshift.org/ocp/release@sha256:53fa74a6d426822340be6bf86a659cbae92de021ade6d2048fa117713e3ec379", Force:false}
I0807 08:25:07.454705       1 cvo.go:466] Desired version from spec is v1.Update{Version:"4.6.0-0.nightly-2020-08-07-034746", Image:"registry.svc.ci.openshift.org/ocp/release@sha256:53fa74a6d426822340be6bf86a659cbae92de021ade6d2048fa117713e3ec379", Force:false}
I0807 08:25:08.087714       1 upgradeable.go:70] Precondition "ClusterVersionUpgradeable" passed: minor from the current 4.6.0-0.nightly-2020-08-07-034746 matches minor from the target 4.6.0-0.nightly-2020-08-07-034746 (both 6).
I0807 08:25:08.087745       1 sync_worker.go:547] Payload loaded from registry.svc.ci.openshift.org/ocp/release@sha256:53fa74a6d426822340be6bf86a659cbae92de021ade6d2048fa117713e3ec379 with hash Gtm_sq0K8MQ=
I0807 08:25:08.531547       1 cvo.go:466] Desired version from spec is v1.Update{Version:"4.6.0-0.nightly-2020-08-07-034746", Image:"registry.svc.ci.openshift.org/ocp/release@sha256:53fa74a6d426822340be6bf86a659cbae92de021ade6d2048fa117713e3ec379", Force:false}

So the problem seems to be that the "current" version being fed into the precondition is actually the new target version.  I think that makes this a dup of bug 1826115, but we can re-open this one if we can still reproduce in updates out of future versions which fix 1826115.

*** This bug has been marked as a duplicate of bug 1826115 ***


Note You need to log in before you can comment on or make changes to this bug.