Skip to content

Commit 9bca3f4

Browse files
ganbarasSrividyaKamakshi
ganbaras
authored and
SrividyaKamakshi
committed
Addressing Error 429 and Adding more logs
1 parent ee2279e commit 9bca3f4

File tree

4 files changed

+71
-41
lines changed

4 files changed

+71
-41
lines changed

‎internal/commonexport/commonexport_functions.go‎

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -460,11 +460,12 @@ func FindResourcesGeneric(ctx *ResourceDiscoveryContext, tfMeta *TerraformResour
460460
return results, nil
461461
}
462462
}
463-
463+
utils.Debugf("[DEBUG] Initiating GET Datasource Call for %s compartment %s", tfMeta.DatasourceClass, parent.CompartmentId)
464464
if err := datasource.Read(d, clients); err != nil {
465+
utils.Debugf("[DEBUG] GET Datasource Call Failure for %s compartment %s\nError: %s", tfMeta.DatasourceClass, parent.CompartmentId, err)
465466
return results, err
466467
}
467-
468+
utils.Debugf("[DEBUG] GET Datasource Call Success for %s compartment %s", tfMeta.DatasourceClass, parent.CompartmentId)
468469
if !tfMeta.DiscoversWithSingularDatasource() {
469470
// Results are from a plural datasource
470471
itemSchema := datasource.Schema[tfMeta.DatasourceItemsAttr]
@@ -859,10 +860,11 @@ var CheckDuplicateResourceName = func(terraformName string) string {
859860
defer ResourceNameCountLock.Unlock() // Ensure the lock is released even if a panic occurs
860861

861862
originalName := terraformName
862-
863+
utils.Logf("[INFO] Checking Duplicate Resource Name for %s", originalName)
863864
// Check if resource already exists
864865
for {
865866
if _, exists := ResourceNameCount[terraformName]; !exists {
867+
utils.Logf("[INFO] Exiting Duplicate resource name for %s", originalName)
866868
break
867869
}
868870
count := ResourceNameCount[originalName]
@@ -871,7 +873,7 @@ var CheckDuplicateResourceName = func(terraformName string) string {
871873
}
872874

873875
ResourceNameCount[terraformName] = 1
874-
876+
utils.Logf("[INFO] Returning Handled Duplicate resource name for %s as %s", originalName, terraformName)
875877
return terraformName
876878
}
877879

‎internal/resourcediscovery/export_compartment.go‎

Lines changed: 38 additions & 29 deletions
Original file line numberDiff line numberDiff line change
@@ -398,7 +398,7 @@ func getExportConfig(d *schema.ResourceData) (interface{}, error) {
398398
}
399399

400400
func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
401-
utils.Logf("[INFO] Running export command\n")
401+
utils.Logf("[INFO] Running export command for compartment %s", *ctx.CompartmentId)
402402
utils.Logf("[INFO] parallelism: %d", ctx.Parallelism)
403403
defer ctx.PrintSummary()
404404
exportStart := time.Now()
@@ -407,6 +407,7 @@ func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
407407
if err != nil {
408408
return err
409409
}
410+
totalDiscoveredResources := 0
410411
discoveryStart := time.Now()
411412
var discoverWg sync.WaitGroup
412413
discoverWg.Add(len(steps))
@@ -415,23 +416,24 @@ func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
415416
sem <- struct{}{}
416417

417418
go func(i int, step resourceDiscoveryStep) {
418-
utils.Debugf("[DEBUG] discover: Running step %d", i)
419-
defer elapsed(fmt.Sprintf("time taken in discovering resources for step %d", i), step.getBaseStep(), Discovery)()
419+
utils.Debugf("[DEBUG] discover for compartment - %s: Running step %d", *ctx.CompartmentId, i)
420+
defer elapsed(fmt.Sprintf("time taken in discovering resources for step %d for compartment %s", i, *ctx.CompartmentId), step.getBaseStep(), Discovery)()
420421
defer func() {
421422
<-sem
422423
if r := recover(); r != nil {
423424
utils.Logf("[ERROR] panic in discover goroutine")
424425
utils.Logf("[ERROR] panic in discover goroutine")
425426
debug.PrintStack()
426427
}
427-
utils.Debugf("[DEBUG] discoverWg done: step %d", i)
428+
utils.Debugf("[DEBUG] discoverWg done: step %d for compartment %s", i, *ctx.CompartmentId)
428429
discoverWg.Done()
429430
}()
430-
431+
utils.Debugf("[DEBUG] Started Discovery for step %d for compartment %s", i, *ctx.CompartmentId)
431432
err := step.discover()
433+
utils.Debugf("[DEBUG] Finished Discovery for step %d for compartment %s", i, *ctx.CompartmentId)
432434
if err != nil {
433435
// All errors in discover are added to the ctx.errorList
434-
utils.Debugf("[ERROR] error occurred while discovering resources for step %d", i)
436+
utils.Debugf("[ERROR] error occurred while discovering resources for step %d for compartment %s", i, *ctx.CompartmentId)
435437
utils.Logf("[ERROR] error occurred while discovering resources: %s", err.Error())
436438
return
437439
}
@@ -448,29 +450,31 @@ func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
448450
}
449451
}
450452

451-
utils.Debugf("[DEBUG] discover: Completed step %d", i)
453+
utils.Debugf("[DEBUG] discover: Completed step %d for compartment %s", i, *ctx.CompartmentId)
452454
utils.Debugf("[DEBUG] discovered %d resources for step %d", len(step.getDiscoveredResources()), i)
455+
totalDiscoveredResources += len(step.getDiscoveredResources())
453456
}(i, step)
454457

455458
}
456459

457460
// Wait for all steps to complete discovery
458461
discoverWg.Wait()
459462
totalDiscoveryTime := time.Since(discoveryStart)
460-
utils.Debugf("discovering resources for all services took %v\n", totalDiscoveryTime)
463+
utils.Debugf("discovering resources for all services took %v for compartment %s", totalDiscoveryTime, *ctx.CompartmentId)
464+
utils.Debugf("Total Discovered Resources for compartment %s - %d\n", *ctx.CompartmentId, totalDiscoveredResources)
461465
ctx.TimeTakenToDiscover = totalDiscoveryTime
462466
utils.Debug("[DEBUG] ~~~~~~ discover steps completed ~~~~~~")
463467

464468
if ctx.GenerateState {
465469
stateStart := time.Now()
466470
// Run import commands
467471
if ctx.Parallelism > 1 {
468-
utils.Debug("[DEBUG] Generating state in parallel")
472+
utils.Debugf("[DEBUG] Generating state in parallel for compartment %s", *ctx.CompartmentId)
469473
if err := generateStateParallel(ctx, steps); err != nil {
470474
return err
471475
}
472476
} else {
473-
utils.Debug("[DEBUG] Generating state sequentially")
477+
utils.Debugf("[DEBUG] Generating state sequentially for compartment %s", *ctx.CompartmentId)
474478
if err := generateState(ctx, steps); err != nil {
475479
return err
476480
}
@@ -482,7 +486,7 @@ func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
482486
deleteInvalidReferences(tf_export.ReferenceMap, ctx.DiscoveredResources)
483487
}
484488
timeForStateGeneration := time.Since(stateStart)
485-
utils.Debugf("[DEBUG] state generation took %v\n", timeForStateGeneration)
489+
utils.Debugf("[DEBUG] state generation took %v for compartment %s", timeForStateGeneration, *ctx.CompartmentId)
486490
ctx.TimeTakenToGenerateState = timeForStateGeneration
487491
}
488492

@@ -502,26 +506,27 @@ func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
502506
wgDone := make(chan bool)
503507

504508
// Write configuration for imported resources
509+
utils.Debugf("[DEBUG] writing configuration for compartment %s", *ctx.CompartmentId)
505510
configStart := time.Now()
506511
for i, step := range steps {
507512

508513
sem <- struct{}{}
509514
go func(i int, step resourceDiscoveryStep) {
510-
utils.Debugf("[DEBUG] writeConfiguration: Running step %d", i)
515+
utils.Debugf("[DEBUG] writeConfiguration for compartment %s: Running step %d", *ctx.CompartmentId, i)
511516
defer func() {
512517
<-sem
513518
if r := recover(); r != nil {
514-
utils.Logf("[ERROR] panic in writeConfiguration goroutine")
519+
utils.Logf("[ERROR] panic in writeConfiguration goroutine for compartment %s", *ctx.CompartmentId)
515520
debug.PrintStack()
516521
}
517-
utils.Debugf("[DEBUG] configWg done: step %d", i)
522+
utils.Debugf("[DEBUG] configWg done for compartment %s: step %d", *ctx.CompartmentId, i)
518523
configWg.Done()
519524
}()
520525
if err := step.writeConfiguration(); err != nil {
521-
errorChannel <- fmt.Errorf("[ERROR] error writing final configuration for resources found: %s", err.Error())
526+
errorChannel <- fmt.Errorf("[ERROR] error writing final configuration for compartment %s for resources found: %s", *ctx.CompartmentId, err.Error())
522527
}
523528

524-
utils.Debugf("[DEBUG] writeConfiguration: Completed step %d", i)
529+
utils.Debugf("[DEBUG] writeConfiguration for compartment %s: Completed step %d", *ctx.CompartmentId, i)
525530
}(i, step)
526531
}
527532

@@ -536,14 +541,14 @@ func runExportCommand(ctx *tf_export.ResourceDiscoveryContext) error {
536541
select {
537542
case <-wgDone:
538543
utils.Debugf("[DEBUG] ~~~~~~ writeConfiguration steps completed ~~~~~~")
539-
utils.Debugf("[DEBUG] writing config took %v\n", time.Since(configStart))
544+
utils.Debugf("[DEBUG] writing config for compartment %s took %v\n", *ctx.CompartmentId, time.Since(configStart))
540545
break
541546
case errs := <-errorChannel:
542547
close(errorChannel)
543548
for i := 0; i < len(errorChannel); i++ {
544549
errs = multierror.Append(errs, <-errorChannel)
545550
}
546-
utils.Logf("[ERROR] error writing final configuration for resources found: %s", errs.Error())
551+
utils.Debugf("[DEBUG] writing config took %v for compartment %s", time.Since(configStart), *ctx.CompartmentId)
547552
return errs
548553
}
549554

@@ -603,22 +608,23 @@ func generateStateParallel(ctx *tf_export.ResourceDiscoveryContext, steps []reso
603608

604609
for i, step := range steps {
605610
if len(step.getDiscoveredResources()) == 0 {
611+
utils.Debugf("[DEBUG] skipping write temp config for compartment %s for step %d", *ctx.CompartmentId, i)
606612
stateWg.Done()
607613
continue
608614
}
609615

610616
sem <- struct{}{}
611617

612618
go func(i int, step resourceDiscoveryStep) {
613-
utils.Debugf("[DEBUG] writing temp config and state: Running step %d", i)
614-
defer elapsed(fmt.Sprintf("time taken by step %s to generate state", fmt.Sprint(i)), step.getBaseStep(), GeneratingState)()
619+
utils.Debugf("[DEBUG] writing temp config and state for compartment %s: Running step %d", *ctx.CompartmentId, i)
620+
defer elapsed(fmt.Sprintf("time taken by step %s to generate state for compartment %s", fmt.Sprint(i), *ctx.CompartmentId), step.getBaseStep(), GeneratingState)()
615621
defer func() {
616622
<-sem
617623
if r := recover(); r != nil {
618624
utils.Logf("[ERROR] panic in writing temp config and state goroutine")
619625
debug.PrintStack()
620626
}
621-
utils.Debugf("[DEBUG] stateWg done: step %d", i)
627+
utils.Debugf("[DEBUG] stateWg done for compartment %s: step %d", *ctx.CompartmentId, i)
622628
stateWg.Done()
623629
}()
624630

@@ -627,7 +633,7 @@ func generateStateParallel(ctx *tf_export.ResourceDiscoveryContext, steps []reso
627633
and also remove the references to failed resources from the referenceMap */
628634
var err error = nil
629635
if err = step.writeTmpConfigurationForImport(); err != nil {
630-
errorChannel <- fmt.Errorf("[ERROR] error while writing temp config for resources found in step %d: %s", i, err.Error())
636+
errorChannel <- fmt.Errorf("[ERROR] error while writing temp config for compartment %s for resources found in step %d: %s", *ctx.CompartmentId, i, err.Error())
631637
}
632638

633639
// Write temp state file for each service, this step will import resources into a separate state file for each service in parallel
@@ -643,7 +649,7 @@ func generateStateParallel(ctx *tf_export.ResourceDiscoveryContext, steps []reso
643649
}
644650
}
645651

646-
utils.Debugf("writing temp config and state: Completed step %d", i)
652+
utils.Debugf("writing temp config and state for compartment %s: Completed step %d", *ctx.CompartmentId, i)
647653
}(i, step)
648654
}
649655

@@ -657,7 +663,7 @@ func generateStateParallel(ctx *tf_export.ResourceDiscoveryContext, steps []reso
657663
// Wait until either stateWg is done or an error is received through the errorChannel
658664
select {
659665
case <-wgDone:
660-
utils.Debugf("[DEBUG] ~~~~~~ writing temp config and state steps completed ~~~~~~")
666+
utils.Debugf("[DEBUG] ~~~~~~ writing temp config and state steps completed for compartment %s ~~~~~~", *ctx.CompartmentId)
661667
break
662668
case errs := <-errorChannel:
663669
close(errorChannel)
@@ -676,7 +682,7 @@ func generateStateParallel(ctx *tf_export.ResourceDiscoveryContext, steps []reso
676682
}
677683

678684
if ctx.State == nil {
679-
utils.Logf("[INFO] ~~~~~~ no resources were imported to the state file ~~~~~~")
685+
utils.Logf("[INFO] ~~~~~~ no resources were imported to the state file for compartment %s ~~~~~~", *ctx.CompartmentId)
680686
return nil
681687
}
682688

@@ -713,6 +719,7 @@ func generateStateParallel(ctx *tf_export.ResourceDiscoveryContext, steps []reso
713719
if err := ctx.Terraform.Init(backgroundCtx, initArgs...); err != nil {
714720
return err
715721
}
722+
utils.Logf("[INFO] ~~~~~~ Generating State Parallelly Complete for compartment %s ~~~~~~", *ctx.CompartmentId)
716723
return nil
717724
}
718725

@@ -826,6 +833,8 @@ func importResource(ctx *tf_export.ResourceDiscoveryContext, resource *tf_export
826833
ctx.AddErrorToList(rdError)
827834

828835
}
836+
utils.Logf("[INFO] ===> Importing resource '%s' - DONE", resource.GetTerraformReference())
837+
utils.Debugf("[DEBUG] ===> Importing resource '%s' - DONE", resource.GetTerraformReference())
829838
}
830839

831840
func getDiscoverResourceSteps(ctx *tf_export.ResourceDiscoveryContext) ([]resourceDiscoveryStep, error) {
@@ -937,10 +946,10 @@ func findResources(ctx *tf_export.ResourceDiscoveryContext, root *tf_export.OCIR
937946
return foundResources, nil
938947
}
939948

940-
utils.Logf("[INFO] resource discovery: visiting %s\n", root.GetTerraformReference())
941-
utils.Debugf("[DEBUG] resource discovery: visiting %s\n", root.GetTerraformReference())
949+
utils.Logf("[INFO] resource discovery: visiting %s for compartment %s\n", root.GetTerraformReference(), root.CompartmentId)
950+
utils.Debugf("[DEBUG] resource discovery: visiting %s for compartment %s\n", root.GetTerraformReference(), root.CompartmentId)
942951

943-
utils.Logf("[INFO] number of child resource types for %s: %d\n", root.GetTerraformReference(), len(childResourceTypes))
952+
utils.Logf("[INFO] number of child resource types for %s: %d for compartment %s\n", root.GetTerraformReference(), len(childResourceTypes), root.CompartmentId)
944953

945954
findResourcesStart := time.Now()
946955
var findResourcesWg sync.WaitGroup
@@ -1039,7 +1048,7 @@ func findResources(ctx *tf_export.ResourceDiscoveryContext, root *tf_export.OCIR
10391048
// Wait for all steps to complete findResources
10401049
findResourcesWg.Wait()
10411050
totalFindResourcesTime := time.Since(findResourcesStart)
1042-
utils.Debugf("finding resources for %s took %v\n", root.GetTerraformReference(), totalFindResourcesTime)
1051+
utils.Debugf("finding resources for %s took %v for compartment %s\n", root.GetTerraformReference(), totalFindResourcesTime, root.CompartmentId)
10431052

10441053
// create copies of filters so that in each thread, they are not shared
10451054
// since number of filters is expected to be less than the number of threads running in parallel, this is a cost effective approach than locking

‎internal/resourcediscovery/export_resource_helpers.go‎

Lines changed: 10 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -129,7 +129,7 @@ type resourceDiscoveryBaseStep struct {
129129
}
130130

131131
func (r *resourceDiscoveryBaseStep) mergeTempStateFiles(tmpStateOutputDir string) error {
132-
defer elapsed(fmt.Sprintf("merging temp state files for %v", r.name), nil, 0)()
132+
defer elapsed(fmt.Sprintf("merging temp state files for %v for compartment %s", r.name, *r.ctx.CompartmentId), nil, 0)()
133133
files, err := ioutil.ReadDir(tmpStateOutputDir)
134134
if err != nil {
135135
return err
@@ -161,19 +161,19 @@ var terraformInitMockVar = func(r *resourceDiscoveryBaseStep, backgroundCtx cont
161161
}
162162

163163
func (r *resourceDiscoveryBaseStep) writeTmpState() error {
164-
defer elapsed(fmt.Sprintf("writing temp state for %d '%s' resources", len(r.getDiscoveredResources()), r.name), nil, 0)()
164+
defer elapsed(fmt.Sprintf("writing temp state for %d '%s' resources for compartment %s", len(r.getDiscoveredResources()), r.name, *r.ctx.CompartmentId), nil, 0)()
165165
// Run terraform init if not already done
166166
if !isInitDone {
167-
utils.Debugf("[DEBUG] acquiring lock to run terraform init")
167+
utils.Debugf("[DEBUG] acquiring lock to run terraform init for step name %s for compartment %s", r.name, *r.ctx.CompartmentId)
168168
initLock.Lock()
169169
defer func() {
170-
utils.Debugf("[DEBUG] releasing lock")
170+
utils.Debugf("[DEBUG] releasing lock for step name %s for compartment %s", r.name, *r.ctx.CompartmentId)
171171
initLock.Unlock()
172172
}()
173173
// Check for existence of .terraform folder to make sure init is not run already by another thread
174174
if _, err := os.Stat(fmt.Sprintf("%s%s.terraform", *r.ctx.OutputDir, string(os.PathSeparator))); os.IsNotExist(err) {
175175
// Run init command if not already run
176-
utils.Debugf("[DEBUG] writeTmpState: running init")
176+
utils.Debugf("[DEBUG] writeTmpState: running init for step name %s for compartment %s", r.name, *r.ctx.CompartmentId)
177177
backgroundCtx := context.Background()
178178

179179
var initArgs []tfexec.InitOption
@@ -184,7 +184,7 @@ func (r *resourceDiscoveryBaseStep) writeTmpState() error {
184184
}
185185

186186
if err := terraformInitMockVar(r, backgroundCtx, initArgs); err != nil {
187-
utils.Debugf("[ERROR] error occured while terraform init: %s", err.Error())
187+
utils.Debugf("[ERROR] error occured while terraform init for step name %s for compartment %s: %s", r.name, *r.ctx.CompartmentId, err.Error())
188188
return err
189189
}
190190
isInitDone = true
@@ -194,7 +194,7 @@ func (r *resourceDiscoveryBaseStep) writeTmpState() error {
194194
tmpStateOutputFilePrefix := filepath.Join(tmpStateOutputDir, globalvar.DefaultTmpStateFile)
195195

196196
if err := os.RemoveAll(tmpStateOutputDir); err != nil {
197-
utils.Logf("[WARN] unable to delete existing tmp state directory %s", tmpStateOutputDir)
197+
utils.Logf("[WARN] unable to delete existing tmp state directory %s for step name %s for compartment %s", tmpStateOutputDir, r.name, *r.ctx.CompartmentId)
198198
return err
199199
}
200200

@@ -241,14 +241,17 @@ func (r *resourceDiscoveryBaseStep) writeTmpState() error {
241241
}
242242
// wait for all chunks to finish importing resources
243243
importWg.Wait()
244+
utils.Debugf("[DEBUG] Merging Temp State Files for step name %s for compartment %s", r.name, *r.ctx.CompartmentId)
244245
// The found resource only include the data sources (ADs and namespaces) that resource discovery adds
245246
if isAllDataSources {
246247
return nil
247248
}
248249
err := r.mergeTempStateFiles(tmpStateOutputDir)
249250
if err != nil {
251+
utils.Debugf("[DEBUG] ERROR while Merging Temp State Files for step name %s for compartment %s : %s", r.name, *r.ctx.CompartmentId, err)
250252
return err
251253
}
254+
utils.Debugf("[DEBUG] DONE Merging Temp State Files for step name %s for compartment %s", r.name, *r.ctx.CompartmentId)
252255
return nil
253256
}
254257

‎internal/tfresource/retry.go‎

Lines changed: 17 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -65,7 +65,23 @@ func init() {
6565
}
6666

6767
func GetRetryBackoffDuration(response oci_common.OCIOperationResponse, disableNotFoundRetries bool, service string, startTime time.Time, optionals ...interface{}) time.Duration {
68-
return getRetryBackoffDurationWithExpectedRetryDurationFn(response, disableNotFoundRetries, service, startTime, getExpectedRetryDuration, optionals...)
68+
backoffDuration := getRetryBackoffDurationWithExpectedRetryDurationFn(response, disableNotFoundRetries, service, startTime, getExpectedRetryDuration, optionals...)
69+
// Do nothing if service specific retry duration exists
70+
if _, ok := serviceExpectedRetryDurationMap[service]; ok {
71+
return backoffDuration
72+
}
73+
if response.Response != nil && response.Response.HTTPResponse() != nil {
74+
statusCode := response.Response.HTTPResponse().StatusCode
75+
switch statusCode {
76+
case 429:
77+
utils.Logf("[DEGUG] Handling Retry Timeout for API Response Error Code 429")
78+
utils.Logf("[DEGUG] Retry Timeout before handling API Response Error Code 429 is %s", backoffDuration)
79+
expectedRetryDuration := getExpectedRetryDuration(response, disableNotFoundRetries, service, optionals...)
80+
backoffDuration = backoffDuration + expectedRetryDuration
81+
utils.Logf("[DEGUG] Retry Timeout after handling API Response Error Code 429 is %s", backoffDuration)
82+
}
83+
}
84+
return backoffDuration
6985
}
7086

7187
func getRetryBackoffDurationWithExpectedRetryDurationFn(response oci_common.OCIOperationResponse, disableNotFoundRetries bool, service string, startTime time.Time, expectedRetryDurationFn expectedRetryDurationFn, optionals ...interface{}) time.Duration {

0 commit comments

Comments
 (0)