Skip to content

chore: add reconfigure diagnostic logs #10397

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
weicao wants to merge 3 commits into from
Closed

chore: add reconfigure diagnostic logs #10397

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
cd2a82f
chore: add reconfigure config hash diagnostic logs
weicao Jun 17, 2026
24324fd
chore: add reconfigure timing diagnostics
weicao Jun 18, 2026
dc3b818
chore: add pod reconfigure timing log
weicao Jun 18, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
106 changes: 105 additions & 1 deletion pkg/controller/instance/reconciler_update.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@ import (

kbappsv1 "github.com/apecloud/kubeblocks/apis/apps/v1"
workloads "github.com/apecloud/kubeblocks/apis/workloads/v1"
"github.com/apecloud/kubeblocks/pkg/constant"
"github.com/apecloud/kubeblocks/pkg/controller/kubebuilderx"
"github.com/apecloud/kubeblocks/pkg/controller/lifecycle"
"github.com/apecloud/kubeblocks/pkg/controller/model"
Expand Down Expand Up @@ -138,10 +139,44 @@ func (r *updateReconciler) Reconcile(tree *kubebuilderx.ObjectTree) (kubebuilder
updatePolicy = recreatePolicy
}

reconfigureStartedAt := time.Now()
allUpdated, err := r.reconfigure(tree, inst, pod)
reconfigureDuration := time.Since(reconfigureStartedAt)
if err != nil {
tree.Logger.Info("pod reconfigure reconcile timing",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"desiredConfigHash", configHashesForLog(inst.Spec.Configs),
"updatePolicy", string(updatePolicy),
"specUpdatePolicy", string(specUpdatePolicy),
"reconfigureStartedAt", reconfigureStartedAt.Format(time.RFC3339Nano),
"reconfigureDuration", reconfigureDuration.String(),
"reconfigureDurationMillis", reconfigureDuration.Milliseconds(),
"error", err.Error())
return kubebuilderx.Continue, err
}
tree.Logger.Info("pod reconfigure reconcile timing",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"desiredConfigHash", configHashesForLog(inst.Spec.Configs),
"allConfigUpdated", allUpdated,
"updatePolicy", string(updatePolicy),
"specUpdatePolicy", string(specUpdatePolicy),
"reconfigureStartedAt", reconfigureStartedAt.Format(time.RFC3339Nano),
"reconfigureDuration", reconfigureDuration.String(),
"reconfigureDurationMillis", reconfigureDuration.Milliseconds())
if !allUpdated || updatePolicy != noOpsPolicy {
tree.Logger.Info("pod reconfigure update decision",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"desiredConfigHash", configHashesForLog(inst.Spec.Configs),
"allConfigUpdated", allUpdated,
"updatePolicy", string(updatePolicy),
"specUpdatePolicy", string(specUpdatePolicy))
}
if !allUpdated && updatePolicy == noOpsPolicy {
continue
}
Expand Down Expand Up @@ -169,6 +204,7 @@ func (r *updateReconciler) Reconcile(tree *kubebuilderx.ObjectTree) (kubebuilder
return kubebuilderx.Continue, err
}
}
logPodConfigHashUpdateScheduled(tree, pod, newMergedPod.(*corev1.Pod), "inPlaceUpdate")
err = tree.Update(newMergedPod)
}
if err != nil {
Expand Down Expand Up @@ -219,6 +255,16 @@ func (r *updateReconciler) reconfigure(tree *kubebuilderx.ObjectTree, inst *work
if err != nil {
return false, err
}
if len(toUpdate) > 0 {
detectedAt := time.Now()
tree.Logger.Info("pod has pending reconfigure configs",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"pendingConfigHash", configHashesForLog(toUpdate),
"detectedAt", detectedAt.Format(time.RFC3339Nano),
"detectedAtUnixNano", detectedAt.UnixNano())
}
for _, config := range toUpdate {
if err = r.reconfigureInst(tree, inst, pod, config); err != nil {
return false, err
Expand All @@ -244,12 +290,32 @@ func (r *updateReconciler) reconfigureInst(tree *kubebuilderx.ObjectTree, inst *
}

opts := reconfigureOptions(config)
actionStartedAt := time.Now()
tree.Logger.Info("starting pod reconfigure action",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHashBeforeAction", podConfigHashForLog(pod),
"configName", config.Name,
"desiredConfigHash", ptr.Deref(config.ConfigHash, ""),
"actionStartedAt", actionStartedAt.Format(time.RFC3339Nano),
"actionStartedAtUnixNano", actionStartedAt.UnixNano())
if len(config.ReconfigureActionName) == 0 {
err = lfa.Reconfigure(tree.Context, nil, opts, config.Parameters)
} else {
err = lfa.UserDefined(tree.Context, nil, opts, config.ReconfigureActionName, config.Reconfigure, config.Parameters)
}
actionDuration := time.Since(actionStartedAt)
if err != nil {
tree.Logger.Info("pod reconfigure action failed",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHashBeforeAction", podConfigHashForLog(pod),
"configName", config.Name,
"desiredConfigHash", ptr.Deref(config.ConfigHash, ""),
"actionStartedAt", actionStartedAt.Format(time.RFC3339Nano),
"actionDuration", actionDuration.String(),
"actionDurationMillis", actionDuration.Milliseconds(),
"error", err.Error())
if errors.Is(err, lifecycle.ErrActionNotDefined) {
return nil
}
Expand All @@ -259,10 +325,48 @@ func (r *updateReconciler) reconfigureInst(tree *kubebuilderx.ObjectTree, inst *
}
return err
}
tree.Logger.Info("successfully reconfigure the pod", "pod", pod.Name, "configHash", ptr.Deref(config.ConfigHash, ""))
tree.Logger.Info("successfully reconfigure the pod",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHashBeforeCommit", podConfigHashForLog(pod),
"configName", config.Name,
"desiredConfigHash", ptr.Deref(config.ConfigHash, ""),
"actionStartedAt", actionStartedAt.Format(time.RFC3339Nano),
"actionDuration", actionDuration.String(),
"actionDurationMillis", actionDuration.Milliseconds())
return nil
}

func configHashesForLog(configs []workloads.ConfigTemplate) []string {
hashes := make([]string, 0, len(configs))
for _, config := range configs {
hashes = append(hashes, fmt.Sprintf("%s=%s", config.Name, ptr.Deref(config.ConfigHash, "")))
}
return hashes
}

func logPodConfigHashUpdateScheduled(tree *kubebuilderx.ObjectTree, oldPod, desiredPod *corev1.Pod, reason string) {
oldHash := podConfigHashForLog(oldPod)
desiredHash := podConfigHashForLog(desiredPod)
if oldHash == desiredHash {
return
}
tree.Logger.Info("scheduled pod config hash update",
"pod", oldPod.Name,
"reason", reason,
"oldResourceVersion", oldPod.ResourceVersion,
"oldConfigHash", oldHash,
"desiredConfigHash", desiredHash,
"scheduledAt", time.Now().Format(time.RFC3339Nano))
}

func podConfigHashForLog(pod *corev1.Pod) string {
if pod == nil || pod.Annotations == nil {
return ""
}
return pod.Annotations[constant.CMInsConfigurationHashLabelKey]
}

func reconfigureOptions(config workloads.ConfigTemplate) *lifecycle.Options {
if len(config.ReconfigureArgs) == 0 {
return nil
Expand Down
109 changes: 108 additions & 1 deletion pkg/controller/instanceset/reconciler_update.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ import (

kbappsv1 "github.com/apecloud/kubeblocks/apis/apps/v1"
workloads "github.com/apecloud/kubeblocks/apis/workloads/v1"
"github.com/apecloud/kubeblocks/pkg/constant"
"github.com/apecloud/kubeblocks/pkg/controller/instancetemplate"
"github.com/apecloud/kubeblocks/pkg/controller/kubebuilderx"
"github.com/apecloud/kubeblocks/pkg/controller/lifecycle"
Expand Down Expand Up @@ -167,10 +168,47 @@ func (r *updateReconciler) Reconcile(tree *kubebuilderx.ObjectTree) (kubebuilder
}

// Always call reconfigure to execute reconfigure actions
reconfigureStartedAt := time.Now()
allUpdated, err1 := r.reconfigure(tree, its, pod)
reconfigureDuration := time.Since(reconfigureStartedAt)
if err1 != nil {
tree.Logger.Info("pod reconfigure reconcile timing",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"desiredConfigHash", configHashesForLog(its.Spec.Configs),
"updatePolicy", string(updatePolicy),
"specUpdatePolicy", string(specUpdatePolicy),
"recreateReason", recreateReason,
"reconfigureStartedAt", reconfigureStartedAt.Format(time.RFC3339Nano),
"reconfigureDuration", reconfigureDuration.String(),
"reconfigureDurationMillis", reconfigureDuration.Milliseconds(),
"error", err1.Error())
return kubebuilderx.Continue, err1
}
tree.Logger.Info("pod reconfigure reconcile timing",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"desiredConfigHash", configHashesForLog(its.Spec.Configs),
"allConfigUpdated", allUpdated,
"updatePolicy", string(updatePolicy),
"specUpdatePolicy", string(specUpdatePolicy),
"recreateReason", recreateReason,
"reconfigureStartedAt", reconfigureStartedAt.Format(time.RFC3339Nano),
"reconfigureDuration", reconfigureDuration.String(),
"reconfigureDurationMillis", reconfigureDuration.Milliseconds())
if !allUpdated || updatePolicy != noOpsPolicy {
tree.Logger.Info("pod reconfigure update decision",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"desiredConfigHash", configHashesForLog(its.Spec.Configs),
"allConfigUpdated", allUpdated,
"updatePolicy", string(updatePolicy),
"specUpdatePolicy", string(specUpdatePolicy),
"recreateReason", recreateReason)
}
if !allUpdated && updatePolicy == noOpsPolicy {
updatingPods++
}
Expand Down Expand Up @@ -198,6 +236,7 @@ func (r *updateReconciler) Reconcile(tree *kubebuilderx.ObjectTree) (kubebuilder
return kubebuilderx.Continue, err
}
}
logPodConfigHashUpdateScheduled(tree, pod, newMergedPod.(*corev1.Pod), "inPlaceUpdate")
err = tree.Update(newMergedPod)
}
if err != nil {
Expand Down Expand Up @@ -302,6 +341,16 @@ func (r *updateReconciler) reconfigure(tree *kubebuilderx.ObjectTree, its *workl
if err != nil {
return false, err
}
if len(toUpdate) > 0 {
detectedAt := time.Now()
tree.Logger.Info("pod has pending reconfigure configs",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHash", podConfigHashForLog(pod),
"pendingConfigHash", configHashesForLog(toUpdate),
"detectedAt", detectedAt.Format(time.RFC3339Nano),
"detectedAtUnixNano", detectedAt.UnixNano())
}
for _, config := range toUpdate {
if err = r.reconfigureInst(tree, its, pod, config); err != nil {
return false, err
Expand All @@ -326,12 +375,32 @@ func (r *updateReconciler) reconfigureInst(tree *kubebuilderx.ObjectTree, its *w
}

opts := reconfigureOptions(config)
actionStartedAt := time.Now()
tree.Logger.Info("starting pod reconfigure action",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHashBeforeAction", podConfigHashForLog(pod),
"configName", config.Name,
"desiredConfigHash", ptr.Deref(config.ConfigHash, ""),
"actionStartedAt", actionStartedAt.Format(time.RFC3339Nano),
"actionStartedAtUnixNano", actionStartedAt.UnixNano())
if len(config.ReconfigureActionName) == 0 {
err = lfa.Reconfigure(tree.Context, nil, opts, config.Parameters)
} else {
err = lfa.UserDefined(tree.Context, nil, opts, config.ReconfigureActionName, config.Reconfigure, config.Parameters)
}
actionDuration := time.Since(actionStartedAt)
if err != nil {
tree.Logger.Info("pod reconfigure action failed",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHashBeforeAction", podConfigHashForLog(pod),
"configName", config.Name,
"desiredConfigHash", ptr.Deref(config.ConfigHash, ""),
"actionStartedAt", actionStartedAt.Format(time.RFC3339Nano),
"actionDuration", actionDuration.String(),
"actionDurationMillis", actionDuration.Milliseconds(),
"error", err.Error())
if errors.Is(err, lifecycle.ErrActionNotDefined) {
return nil
}
Expand All @@ -341,10 +410,48 @@ func (r *updateReconciler) reconfigureInst(tree *kubebuilderx.ObjectTree, its *w
}
return err
}
tree.Logger.Info("successfully reconfigure the pod", "pod", pod.Name, "configHash", ptr.Deref(config.ConfigHash, ""))
tree.Logger.Info("successfully reconfigure the pod",
"pod", pod.Name,
"podResourceVersion", pod.ResourceVersion,
"podConfigHashBeforeCommit", podConfigHashForLog(pod),
"configName", config.Name,
"desiredConfigHash", ptr.Deref(config.ConfigHash, ""),
"actionStartedAt", actionStartedAt.Format(time.RFC3339Nano),
"actionDuration", actionDuration.String(),
"actionDurationMillis", actionDuration.Milliseconds())
return nil
}

func configHashesForLog(configs []workloads.ConfigTemplate) []string {
hashes := make([]string, 0, len(configs))
for _, config := range configs {
hashes = append(hashes, fmt.Sprintf("%s=%s", config.Name, ptr.Deref(config.ConfigHash, "")))
}
return hashes
}

func logPodConfigHashUpdateScheduled(tree *kubebuilderx.ObjectTree, oldPod, desiredPod *corev1.Pod, reason string) {
oldHash := podConfigHashForLog(oldPod)
desiredHash := podConfigHashForLog(desiredPod)
if oldHash == desiredHash {
return
}
tree.Logger.Info("scheduled pod config hash update",
"pod", oldPod.Name,
"reason", reason,
"oldResourceVersion", oldPod.ResourceVersion,
"oldConfigHash", oldHash,
"desiredConfigHash", desiredHash,
"scheduledAt", time.Now().Format(time.RFC3339Nano))
}

func podConfigHashForLog(pod *corev1.Pod) string {
if pod == nil || pod.Annotations == nil {
return ""
}
return pod.Annotations[constant.CMInsConfigurationHashLabelKey]
}

func reconfigureOptions(config workloads.ConfigTemplate) *lifecycle.Options {
if len(config.ReconfigureArgs) == 0 {
return nil
Expand Down
1 change: 1 addition & 0 deletions pkg/controller/kubebuilderx/controller.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -130,6 +130,7 @@ func (c *controller) Commit() (ctrl.Result, error) {
}
if c.err = plan.Execute(); c.err != nil {
if apierrors.IsConflict(c.err) {
c.logger.Info("reconcile plan hit conflict, requeueing", "request", c.req, "error", c.err.Error())
return ctrl.Result{Requeue: true}, nil
}
return ctrl.Result{}, c.err
Expand Down
Loading
Loading