Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6 #472

wking · 2020-10-09T20:26:23Z

This line is descended from 961873d (#82). But we triggered it recently with 88c222c (#448). Drop the line, because it's noisy spew in the log files, with all of the small "fraction-completed" bumps:

$ grep -c 'sync_worker.go:.*Status change' namespaces/openshift-cluster-version/pods/cluster-version-operator-*/cluster-version-operator/cluster-version-operator/logs/current.log6265
$ grep 'sync_worker.go:.*Status change' namespaces/openshift-cluster-version/pods/cluster-version-operator-*/cluster-version-operator/cluster-version-operator/logs/current.log | tail -n4
2020-10-09T18:21:53.523398340Z I1009 18:21:53.522733       1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"ApplyResources", Failure:error(nil), Fraction:0.9936, Completed:0, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false}
2020-10-09T18:21:53.538399862Z I1009 18:21:53.537709       1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"ApplyResources", Failure:error(nil), Fraction:0.9952, Completed:0, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false}
2020-10-09T18:21:53.570915921Z I1009 18:21:53.570847       1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"ApplyResources", Failure:error(nil), Fraction:0.9984, Completed:0, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false}
2020-10-09T18:21:53.585933980Z I1009 18:21:53.585786       1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"", Failure:error(nil), Fraction:1, Completed:10, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0xbfd8487062ea4a14, ext:2681032283239, loc:(*time.Location)(0x26b0400)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false}

openshift-ci-robot · 2020-10-09T20:26:27Z

@wking: This pull request references Bugzilla bug 1886900, which is invalid:

expected the bug to be in one of the following states: NEW, ASSIGNED, ON_DEV, POST, POST, but it is MODIFIED instead

Comment /bugzilla refresh to re-evaluate validity if changes to the Bugzilla bug are made, or edit the title of this pull request to link to a different bug.

Details

In response to this:

Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

And also the "Status report channel was full" lines. These lines are descended from 961873d (sync: Do config syncing in the background, 2019-01-11, openshift#82). But we triggered it recently with 88c222c (install/0000_00_cluster-version-operator_03_deployment: Bump to --v=5, 2020-08-30, openshift#448). Drop the line, because it's noisy spew in the log files, with all of the small "fraction-completed" bumps: $ grep -c 'sync_worker.go:.*Status change' namespaces/openshift-cluster-version/pods/cluster-version-operator-*/cluster-version-operator/cluster-version-operator/logs/current.log 6265 $ grep -c 'sync_worker.go:.*Status report channel was full' namespaces/openshift-cluster-version/pods/cluster-version-operator-*/cluster-version-operator/cluster-version-operator/logs/current.log 5586 $ grep 'sync_worker.go:.*Status change' namespaces/openshift-cluster-version/pods/cluster-version-operator-*/cluster-version-operator/cluster-version-operator/logs/current.log | tail -n4 2020-10-09T18:21:53.523398340Z I1009 18:21:53.522733 1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"ApplyResources", Failure:error(nil), Fraction:0.9936, Completed:0, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false} 2020-10-09T18:21:53.538399862Z I1009 18:21:53.537709 1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"ApplyResources", Failure:error(nil), Fraction:0.9952, Completed:0, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false} 2020-10-09T18:21:53.570915921Z I1009 18:21:53.570847 1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"ApplyResources", Failure:error(nil), Fraction:0.9984, Completed:0, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false} 2020-10-09T18:21:53.585933980Z I1009 18:21:53.585786 1 sync_worker.go:458] Status change cvo.SyncWorkerStatus{Generation:1, Step:"", Failure:error(nil), Fraction:1, Completed:10, Reconciling:true, Initial:false, VersionHash:"NtNVAdtksjk=", LastProgress:time.Time{wall:0xbfd8487062ea4a14, ext:2681032283239, loc:(*time.Location)(0x26b0400)}, Actual:v1.Release{Version:"4.7.0-0.ci.test-2020-10-09-171926-ci-op-8r50wp9l", Image:"registry.build01.ci.openshift.org/ci-op-8r50wp9l/release@sha256:9c90e64d7ccec7475608daf3e7a21ed749d047a330203734501eb7bc95c65ac8", URL:"", Channels:[]string(nil)}, Verified:false}

wking · 2020-10-09T20:31:31Z

/bugzilla refresh

I'm also demoting Status report channel was full with 4e4f789 -> 98a7b66

openshift-ci-robot · 2020-10-09T20:31:36Z

@wking: This pull request references Bugzilla bug 1886900, which is valid. The bug has been updated to refer to the pull request using the external bug tracker.

3 validation(s) were run on this bug

bug is open, matching expected state (open)
bug target release (4.7.0) matches configured target release for branch (4.7.0)
bug is in the state POST, which is one of the valid states (NEW, ASSIGNED, ON_DEV, POST, POST)

Details

In response to this:

/bugzilla refresh

I'm also demoting Status report channel was full with 4e4f789 -> 98a7b66

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

sdodson · 2020-10-09T20:36:14Z

/retest

sdodson · 2020-10-09T20:40:02Z

/lgtm

openshift-ci-robot · 2020-10-09T20:40:20Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: sdodson, wking

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Details

Needs approval from an approver in each of these files:

~~OWNERS~~ [sdodson,wking]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

wking · 2020-10-09T22:07:26Z

We're still the biggest log, but I'm ok with the current status.

/hold cancel

wking · 2020-10-09T22:22:56Z

I've included this in the #471 backport PR.

openshift-ci-robot · 2020-10-09T22:43:04Z

@wking: All pull requests linked via external trackers have merged:

Bugzilla bug 1886900 has been moved to the MODIFIED state.

Details

In response to this:

Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

openshift-ci-robot added the bugzilla/severity-medium Referenced Bugzilla bug's severity is medium for the branch this PR is targeting. label Oct 9, 2020

openshift-ci-robot added the bugzilla/invalid-bug Indicates that a referenced Bugzilla bug is invalid for the branch this PR is targeting. label Oct 9, 2020

openshift-ci-robot requested review from abhinavdahiya and jottofar October 9, 2020 20:26

openshift-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Oct 9, 2020

wking force-pushed the demote-status-change-logging branch from 35cf591 to 4e4f789 Compare October 9, 2020 20:26

wking force-pushed the demote-status-change-logging branch from 4e4f789 to 98a7b66 Compare October 9, 2020 20:29

openshift-ci-robot added bugzilla/valid-bug Indicates that a referenced Bugzilla bug is valid for the branch this PR is targeting. and removed bugzilla/invalid-bug Indicates that a referenced Bugzilla bug is invalid for the branch this PR is targeting. labels Oct 9, 2020

wking mentioned this pull request Oct 9, 2020

Bug 1886900: pkg/cvo/sync_worker: Drop "Manifest: ..." logging #469

Merged

openshift-ci-robot assigned sdodson Oct 9, 2020

openshift-ci-robot added the lgtm Indicates that a PR is ready to be merged. label Oct 9, 2020

openshift-merge-robot merged commit 0fa9b04 into openshift:master Oct 9, 2020

wking deleted the demote-status-change-logging branch October 9, 2020 22:59

wking mentioned this pull request Oct 9, 2020

[release-4.6] Bug 1886947: pkg/cvo/sync_worker: Drop "Manifest: ..." logging #471

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6 #472

Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6 #472

Uh oh!

wking commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

wking commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

sdodson commented Oct 9, 2020

Uh oh!

sdodson commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

wking commented Oct 9, 2020

Uh oh!

wking commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6 #472

Bug 1886900: pkg/cvo/sync_worker: Demote "Status change: ..." logging to v6 #472

Uh oh!

Conversation

wking commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

wking commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

sdodson commented Oct 9, 2020

Uh oh!

sdodson commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

wking commented Oct 9, 2020

Uh oh!

wking commented Oct 9, 2020

Uh oh!

openshift-ci-robot commented Oct 9, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants