Skip to content

Commit 941011d

Browse files
amitbhatt818amitbhatt818
authored
Merge pull request #175 from AmitKumarDas/code-55
feat(logs): add important logs during command reconcile
2 parents 028c33d + 141c46d commit 941011d

File tree

3 files changed

+110
-39
lines changed

3 files changed

+110
-39
lines changed

‎pkg/command/job_builder.go

+4-4
Original file line numberDiff line numberDiff line change
@@ -66,14 +66,14 @@ func (b *JobBuilding) getDefaultJob() *unstructured.Unstructured {
6666
"serviceAccountName": os.Getenv("DOPE_SERVICE_ACCOUNT"),
6767
"containers": []interface{}{
6868
map[string]interface{}{
69-
"name": "dcmd",
70-
"image": "mayadataio/dcmd",
69+
"name": "daction",
70+
"image": "mayadataio/daction",
7171
"imagePullPolicy": "Always",
7272
"command": []interface{}{
73-
"/usr/bin/dcmd",
73+
"/usr/bin/daction",
7474
},
7575
"args": []interface{}{
76-
"-v=1",
76+
"-v=3",
7777
fmt.Sprintf("--command-name=%s", b.Command.GetName()),
7878
fmt.Sprintf("--command-ns=%s", b.Command.GetNamespace()),
7979
},

‎pkg/command/job_builder_test.go

+4-4
Original file line numberDiff line numberDiff line change
@@ -56,8 +56,8 @@ func TestBuilderBuild(t *testing.T) {
5656
ExpectedLabelCount: 3,
5757
ExpectedRestartPolicy: "Never",
5858
ExpectedTTLSecondsAfterFinished: 0,
59-
ExpectedImage: "mayadataio/dcmd",
60-
ExpectedImageName: "dcmd",
59+
ExpectedImage: "mayadataio/daction",
60+
ExpectedImageName: "daction",
6161
ExpectedImageArgCount: 3,
6262
ExpectedServiceAccount: "",
6363
},
@@ -91,8 +91,8 @@ func TestBuilderBuild(t *testing.T) {
9191
ExpectedLabelCount: 4, // extra label
9292
ExpectedRestartPolicy: "Never",
9393
ExpectedTTLSecondsAfterFinished: 0,
94-
ExpectedImage: "mayadataio/dcmd",
95-
ExpectedImageName: "dcmd",
94+
ExpectedImage: "mayadataio/daction",
95+
ExpectedImageName: "daction",
9696
ExpectedImageArgCount: 3,
9797
ExpectedServiceAccount: "",
9898
},

‎pkg/command/reconciler.go

+102-31
Original file line numberDiff line numberDiff line change
@@ -105,11 +105,13 @@ func (r *Reconciliation) initChildJobDetails() {
105105
if r.childJob.GetKind() != types.KindJob ||
106106
r.childJob.GetAPIVersion() != types.JobAPIVersion {
107107
r.err = errors.Errorf(
108-
"Invalid child: Expected %s/%s: Got %s/%s",
108+
"Invalid child: Expected %q %q: Got %q %q: Command %q / %q",
109109
types.JobAPIVersion,
110110
types.KindJob,
111111
r.childJob.GetAPIVersion(),
112112
r.childJob.GetKind(),
113+
r.command.GetNamespace(),
114+
r.command.GetName(),
113115
)
114116
return
115117
}
@@ -120,31 +122,79 @@ func (r *Reconciliation) initChildJobDetails() {
120122
}
121123

122124
if !found {
125+
klog.V(3).Infof(
126+
"Job is not available: Command %q / %q",
127+
r.command.GetNamespace(),
128+
r.command.GetName(),
129+
)
123130
return
124131
}
132+
125133
// At this point Job is present in Kubernetes cluster
126134
r.isChildJobFound = true
127-
// Extract status.phase of this Job
128-
phase, found, err := unstructured.NestedString(
135+
136+
// Extract status.failed of this Job
137+
failedCount, found, err := unstructured.NestedInt64(
129138
got.Object,
130139
"status",
131-
"phase",
140+
"failed",
132141
)
133142
if err != nil {
134143
r.err = errors.Wrapf(
135144
err,
136-
"Failed to get status.phase: Kind %q: Name %q / %q",
145+
"Failed to get Job status.failed: Kind %q: Job %q / %q",
137146
r.childJob.GetKind(),
138147
r.childJob.GetNamespace(),
139148
r.childJob.GetName(),
140149
)
141150
return
142151
}
143152
if !found {
144-
// Job's status.phase is not set
153+
klog.V(1).Infof(
154+
"Job status.failed is not set: Kind %q: Job %q / %q",
155+
r.childJob.GetKind(),
156+
r.childJob.GetNamespace(),
157+
r.childJob.GetName(),
158+
)
159+
}
160+
if failedCount > 0 {
161+
r.isChildJobCompleted = false
162+
return
163+
}
164+
165+
// Extract status.active of this Job
166+
activeCount, found, err := unstructured.NestedInt64(
167+
got.Object,
168+
"status",
169+
"active",
170+
)
171+
if err != nil {
172+
r.err = errors.Wrapf(
173+
err,
174+
"Failed to get Job status.active: Kind %q: Job %q / %q",
175+
r.childJob.GetKind(),
176+
r.childJob.GetNamespace(),
177+
r.childJob.GetName(),
178+
)
145179
return
146180
}
147-
r.isChildJobCompleted = phase == types.JobPhaseCompleted
181+
if !found {
182+
klog.V(1).Infof(
183+
"Job status.active is not set: Kind %q: Job %q / %q",
184+
r.childJob.GetKind(),
185+
r.childJob.GetNamespace(),
186+
r.childJob.GetName(),
187+
)
188+
// Job's status.active is not set
189+
//
190+
// Nothing to do
191+
// Wait for next reconcile
192+
return
193+
}
194+
195+
if activeCount > 0 {
196+
r.isChildJobCompleted = true
197+
}
148198
}
149199

150200
func (r *Reconciliation) initCommandDetails() {
@@ -172,12 +222,13 @@ func (r *Reconciliation) initCommandDetails() {
172222
func (r *Reconciliation) initLocking() {
173223
if metac.KubeDetails == nil {
174224
r.err = errors.Errorf(
175-
"Failed to init lock: Nil metac kube details: Command %s %s",
225+
"Failed to init lock: Nil kube details: Command %q / %q",
176226
r.command.GetNamespace(),
177227
r.command.GetName(),
178228
)
179229
return
180230
}
231+
181232
r.locker, r.err = lock.NewLocker(lock.LockingConfig{
182233
// D-Operators uses metac as a library
183234
// Metac on its part populates the kube config & api discovery
@@ -275,7 +326,7 @@ func (r *Reconciliation) createChildJob() (types.CommandStatus, error) {
275326
return types.CommandStatus{
276327
Phase: types.CommandPhaseJobCreated,
277328
Message: fmt.Sprintf(
278-
"Command Job created: %s %s: %s",
329+
"Command Job created: %q %q: %q",
279330
got.GetNamespace(),
280331
got.GetName(),
281332
got.GetUID(),
@@ -302,7 +353,6 @@ func (r *Reconciliation) isChildJobAvailable() (*unstructured.Unstructured, bool
302353
)
303354
}
304355
return got, got != nil, nil
305-
306356
}
307357

308358
func (r *Reconciliation) deleteChildJob() (types.CommandStatus, error) {
@@ -321,7 +371,7 @@ func (r *Reconciliation) deleteChildJob() (types.CommandStatus, error) {
321371
return types.CommandStatus{
322372
Phase: types.CommandPhaseJobDeleted,
323373
Message: fmt.Sprintf(
324-
"Command Job deleted: %s %s: %s",
374+
"Command Job deleted: %q / %q: %q",
325375
r.childJob.GetNamespace(),
326376
r.childJob.GetName(),
327377
r.childJob.GetUID(),
@@ -331,7 +381,9 @@ func (r *Reconciliation) deleteChildJob() (types.CommandStatus, error) {
331381

332382
func (r *Reconciliation) reconcileRunOnceCommand() (types.CommandStatus, error) {
333383
klog.V(1).Infof(
334-
"Reconcile run once command started",
384+
"Reconcile started: Run once: Command %q / %q",
385+
r.command.GetNamespace(),
386+
r.command.GetName(),
335387
)
336388
var isDeleteChildJob = func() bool {
337389
if !r.isChildJobFound || !r.isChildJobCompleted {
@@ -353,16 +405,25 @@ func (r *Reconciliation) reconcileRunOnceCommand() (types.CommandStatus, error)
353405
}
354406
if isCreateChildJob() {
355407
klog.V(1).Infof(
356-
"Will create job",
408+
"Will create command job: Command %q / %q",
409+
r.command.GetNamespace(),
410+
r.command.GetName(),
357411
)
358412
return r.createChildJob()
359413
}
360414
if isDeleteChildJob() {
361415
klog.V(1).Infof(
362-
"Will delete job",
416+
"Will delete command job: Command %q / %q",
417+
r.command.GetNamespace(),
418+
r.command.GetName(),
363419
)
364420
return r.deleteChildJob()
365421
}
422+
klog.V(1).Infof(
423+
"Previous reconciliation is in-progress: Command %q / %q",
424+
r.command.GetNamespace(),
425+
r.command.GetName(),
426+
)
366427
return types.CommandStatus{
367428
Phase: types.CommandPhaseInProgress,
368429
Message: "Previous reconciliation is in-progress",
@@ -371,18 +432,23 @@ func (r *Reconciliation) reconcileRunOnceCommand() (types.CommandStatus, error)
371432

372433
func (r *Reconciliation) reconcileRunAlwaysCommand() (types.CommandStatus, error) {
373434
klog.V(1).Infof(
374-
"Run always: %q",
375-
r.childJob.GetName(),
435+
"Reconcile started: Run always: Command %q / %q",
436+
r.command.GetNamespace(),
437+
r.command.GetName(),
376438
)
377439
if !r.isChildJobFound {
378440
klog.V(1).Infof(
379-
"Will create job",
441+
"Will create command job: Command %q / %q",
442+
r.command.GetNamespace(),
443+
r.command.GetName(),
380444
)
381445
return r.createChildJob()
382446
}
383447
if r.isStatusSet && r.isChildJobCompleted {
384448
klog.V(1).Infof(
385-
"Will delete job",
449+
"Will delete command job: Command %q / %q",
450+
r.command.GetNamespace(),
451+
r.command.GetName(),
386452
)
387453
return r.deleteChildJob()
388454
}
@@ -402,7 +468,9 @@ func (r *Reconciliation) deleteChildJobOnDisabledCommand() (types.CommandStatus,
402468
return output, nil
403469
}
404470
klog.V(1).Infof(
405-
"Will delete job",
471+
"Will delete command job: Command is disabled: Command %q / %q",
472+
r.command.GetNamespace(),
473+
r.command.GetName(),
406474
)
407475
// Delete without any checks
408476
_, err := r.deleteChildJob()
@@ -415,19 +483,25 @@ func (r *Reconciliation) deleteChildJobOnDisabledCommand() (types.CommandStatus,
415483
// Reconcile either creates or deletes a Kubernetes job or does nothing
416484
// as part of reconciling a Command resource.
417485
func (r *Reconciliation) Reconcile() (status types.CommandStatus, err error) {
418-
// klog.V(1).Infof(
419-
// "Reconcilation struct: %#v",
420-
// r,
421-
// )
422486
if r.isRunNever {
423487
return r.deleteChildJobOnDisabledCommand()
424488
}
425489
isLocked, err := r.locker.IsLocked()
426490
if err != nil {
427-
klog.Errorf("Failed to check lock status: %s", err.Error())
491+
klog.Errorf(
492+
"Failed to check lock status for command: %q / %q: %s",
493+
r.command.GetNamespace(),
494+
r.command.GetName(),
495+
err.Error(),
496+
)
428497
return types.CommandStatus{}, err
429498
}
430499
if isLocked {
500+
klog.V(3).Infof(
501+
"Will skip command reconciliation: It is locked: Command %q / %q",
502+
r.command.GetNamespace(),
503+
r.command.GetName(),
504+
)
431505
return types.CommandStatus{
432506
Phase: types.CommandPhaseLocked,
433507
}, nil
@@ -441,9 +515,6 @@ func (r *Reconciliation) Reconcile() (status types.CommandStatus, err error) {
441515
}
442516
return types.CommandStatus{}, err
443517
}
444-
klog.V(1).Infof(
445-
"Reconcile started",
446-
)
447518
// make use of defer to UNLOCK
448519
defer func() {
449520
// FORCE UNLOCK in case of the following:
@@ -456,7 +527,7 @@ func (r *Reconciliation) Reconcile() (status types.CommandStatus, err error) {
456527
if unlockerr != nil {
457528
// swallow unlock error by logging
458529
klog.Errorf(
459-
"Forced unlock failed: Command %q %q: Status %q %q: %s",
530+
"Forced unlock failed: Command %q / %q: Status %q %q: %s",
460531
r.command.Namespace,
461532
r.command.Name,
462533
r.commandStatus.Phase,
@@ -467,7 +538,7 @@ func (r *Reconciliation) Reconcile() (status types.CommandStatus, err error) {
467538
return
468539
}
469540
klog.V(3).Infof(
470-
"Forced unlock was successful: Command %q %q: Status %q %q",
541+
"Forced unlock was successful: Command %q / %q: Status %q %q",
471542
r.command.Namespace,
472543
r.command.Name,
473544
r.commandStatus.Phase,
@@ -491,7 +562,7 @@ func (r *Reconciliation) Reconcile() (status types.CommandStatus, err error) {
491562
if unlockerr != nil {
492563
// swallow the unlock error by logging
493564
klog.Errorf(
494-
"Graceful unlock failed: Command %q %q: Status %q %q: %s",
565+
"Graceful unlock failed: Command %q / %q: Status %q %q: %s",
495566
r.command.Namespace,
496567
r.command.Name,
497568
r.commandStatus.Phase,
@@ -502,7 +573,7 @@ func (r *Reconciliation) Reconcile() (status types.CommandStatus, err error) {
502573
return
503574
}
504575
klog.V(3).Infof(
505-
"Unlocked gracefully: Command %q %q: Status %q %q: %s",
576+
"Unlocked gracefully: Command %q / %q: Status %q %q: %s",
506577
r.command.Namespace,
507578
r.command.Name,
508579
r.commandStatus.Phase,

0 commit comments

Comments
 (0)