Skip to content

Conversation

@jwierzbo
Copy link
Collaborator

@jwierzbo jwierzbo commented Jun 28, 2022

current log output when log.level=trace:

2022-06-28T13:47:35Z DBG Looking for ServiceMonitor CRD... name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z INF ...have discovered ServiceMonitor CRD name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z DBG Initially inspect deployment... name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Pre-inspector refresh start name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh start name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=ServiceMonitor name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=ArangoMember name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=ArangoClusterSynchronization name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=Pod name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=ArangoTask name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=PersistentVolumeClaim name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=ServiceAccount name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=Endpoints name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=Node name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=Secret name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=Service name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector refresh component=PodDisruptionBudget name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z DBG Waiting for arangodeploymentreplications.replication.database.arangodb.com CRD to be ready -  namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:35Z TRC Inspector done component=ServiceMonitor duration=278.730157ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=ArangoMember duration=355.275596ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=ArangoClusterSynchronization duration=406.817983ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=Pod duration=475.139963ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=ArangoTask duration=538.858981ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=PersistentVolumeClaim duration=604.77396ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=ServiceAccount duration=673.178217ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=Endpoints duration=741.458878ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=Node duration=819.12754ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=Secret duration=906.26326ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=Service duration=938.5072ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector done component=PodDisruptionBudget duration=1.006830566s name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Inspector refresh done duration=1.007232931s name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z DBG CRDs ready namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:36Z TRC Ensuring annotations name=deployment namespace=jakubwierzbowski operator-id=lw7qq section=annotations
2022-06-28T13:47:36Z TRC Ensure labels name=deployment namespace=jakubwierzbowski operator-id=lw7qq section=labels
2022-06-28T13:47:37Z TRC Reconciliation loop took 267.827574ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspect loop took 1.810739392s name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z DBG ...deployment inspect started interval=250ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z DBG Looking for ServiceMonitor CRD... name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspect deployment... name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Pre-inspector refresh start name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh start name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=ServiceMonitor name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=Endpoints name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=Node name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=ArangoClusterSynchronization name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=PodDisruptionBudget name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=ArangoMember name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=Pod name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=ArangoTask name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=PersistentVolumeClaim name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=Service name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=Secret name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh skipped component=ServiceAccount name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Inspector refresh done duration=44.953402ms name=deployment namespace=jakubwierzbowski operator-id=lw7qq
2022-06-28T13:47:37Z TRC Ensuring annotations name=deployment namespace=jakubwierzbowski operator-id=lw7qq section=annotations

Copy link
Contributor

@informalict informalict left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, small suggestion


defer func() {
d.log.Info("Reconciliation loop took %s", time.Since(t))
d.log.Trace("Reconciliation loop took %s", time.Since(t))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe we should have here INFO or WARNING when time.Since(t) is higher than some value (e.g. 5 seconds).
Then we would know that the reconciliation loop took too long and should be investigated. e.g.:
if time.Since(t) > time.Second * 10 {
d.log.Info("Reconciliation loop took too long %s", time.Since(t))
} else {
d.log.Trace("Reconciliation loop took %s", time.Since(t))
}

defer cancelReconciliation()
defer func() {
d.log.Info("Inspect loop took %s", time.Since(start))
d.log.Trace("Inspect loop took %s", time.Since(start))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the same here as below comment

@ajanikow ajanikow merged commit 10bd6c7 into master Jun 29, 2022
@ajanikow ajanikow deleted the silent_logs branch June 29, 2022 06:29
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants