From 7f0ff1e366c17e02c12e4c408bdd75e4be16dd66 Mon Sep 17 00:00:00 2001
From: Kiswono Prayogo <kiswono@gmail.com>
Date: Wed, 28 Feb 2024 17:46:00 +0700
Subject: [PATCH] add more request log

---
 gcoreprovider/gcore.go | 28 ++++++++++++++++++++--------
 main.go                |  4 ++++
 2 files changed, 24 insertions(+), 8 deletions(-)

diff --git a/gcoreprovider/gcore.go b/gcoreprovider/gcore.go
index f02404d..0a79d4f 100644
--- a/gcoreprovider/gcore.go
+++ b/gcoreprovider/gcore.go
@@ -97,7 +97,7 @@ func (p *DnsProvider) ApplyChanges(rootCtx context.Context, changes *plan.Change
 	if !changes.HasChanges() {
 		return nil
 	}
-	log.Infof("%s: starting apply changes createLen=%d, deleteLen=%d, updateOldLen=%d, updateNewLen=%d",
+	log.Infof("%s: ApplyChanges createLen=%d, deleteLen=%d, updateOldLen=%d, updateNewLen=%d",
 		ProviderName, len(changes.Create), len(changes.Delete), len(changes.UpdateOld), len(changes.UpdateNew))
 	ctx, cancel := p.ctxWithMyTimeout(rootCtx)
 	defer cancel()
@@ -135,8 +135,11 @@ func (p *DnsProvider) ApplyChanges(rootCtx context.Context, changes *plan.Change
 			continue
 		}
 		gr2.Go(func() error {
-			return errSafeWrap(strings.Join(errMsg, "; "),
+			err := errSafeWrap(strings.Join(errMsg, "; "),
 				p.client.DeleteRRSetRecord(ctx, zone, d.DNSName, d.RecordType, recordValues...))
+			log.Debugf("%s ApplyChanges.updateNew,DeleteRRSetRecord: %s %s %v ERR=%s",
+				ProviderName, d.DNSName, d.RecordType, recordValues, err)
+			return err
 		})
 	}
 	// remove deleted records
@@ -161,8 +164,11 @@ func (p *DnsProvider) ApplyChanges(rootCtx context.Context, changes *plan.Change
 			errMsg = append(errMsg, msg)
 		}
 		gr1.Go(func() error {
-			return errSafeWrap(strings.Join(errMsg, "; "),
+			err := errSafeWrap(strings.Join(errMsg, "; "),
 				p.client.DeleteRRSetRecord(ctx, zone, d.DNSName, d.RecordType, recordValues...))
+			log.Debugf("%s ApplyChanges.Delete,DeleteRRSetRecord: %s %s %v ERR=%s",
+				ProviderName, d.DNSName, d.RecordType, recordValues, err)
+			return err
 		})
 	}
 	// add created records
@@ -187,8 +193,11 @@ func (p *DnsProvider) ApplyChanges(rootCtx context.Context, changes *plan.Change
 			errMsg = append(errMsg, msg)
 		}
 		gr1.Go(func() error {
-			return errSafeWrap(strings.Join(errMsg, "; "),
+			err := errSafeWrap(strings.Join(errMsg, "; "),
 				p.client.AddZoneRRSet(ctx, zone, c.DNSName, c.RecordType, recordValues, int(c.RecordTTL)))
+			log.Debugf("%s ApplyChanges.Create,AddZoneRRSet: %s %s %v ERR=%s",
+				ProviderName, c.DNSName, c.RecordType, recordValues, err)
+			return err
 		})
 	}
 	// wait preparing before send updates to records
@@ -222,8 +231,11 @@ func (p *DnsProvider) ApplyChanges(rootCtx context.Context, changes *plan.Change
 			continue
 		}
 		gr1.Go(func() error {
-			return errSafeWrap(strings.Join(errMsg, "; "),
+			err := errSafeWrap(strings.Join(errMsg, "; "),
 				p.client.AddZoneRRSet(ctx, zone, c.DNSName, c.RecordType, recordValues, int(c.RecordTTL)))
+			log.Debugf("%s ApplyChanges.UpdateNew,AddZoneRRSet: %s %s %v ERR=%s",
+				ProviderName, c.DNSName, c.RecordType, recordValues)
+			return err
 		})
 	}
 	err = gr1.Wait()
@@ -236,17 +248,17 @@ func (p *DnsProvider) ApplyChanges(rootCtx context.Context, changes *plan.Change
 }
 
 func (p *DnsProvider) GetDomainFilter() endpoint.DomainFilter {
-	log.Debugf("%s: starting get domain filters", ProviderName)
+	log.Debugf("%s: GetDomainFilter", ProviderName)
 	zs, err := p.client.ZonesWithRecords(context.Background())
 	if err != nil {
-		log.Errorf("%s: get domain filters: %v", ProviderName, err)
+		log.Errorf("%s: ERROR GetDomainFilter: %v", ProviderName, err)
 		return endpoint.DomainFilter{}
 	}
 	domains := make([]string, 0)
 	for _, z := range zs {
 		domains = append(domains, z.Name, "."+z.Name)
 	}
-	defer log.Debugf("%s: finishing get domain filters with %+v", ProviderName, domains)
+	defer log.Debugf("%s: GetDomainFilter: %+v", ProviderName, domains)
 	return endpoint.NewDomainFilter(domains)
 }
 
diff --git a/main.go b/main.go
index 33bd758..450e945 100644
--- a/main.go
+++ b/main.go
@@ -89,6 +89,7 @@ func CreateWebServer(p *gcoreprovider.DnsProvider) *webServer {
 		w.WriteHeader(http.StatusOK)
 	})
 	r.Get("/", func(w http.ResponseWriter, r *http.Request) { // negotiate
+		requestLog(r).Debug("GET /")
 		if err := acceptHeaderCheck(w, r); err != nil {
 			requestLog(r).WithField(logFieldError, err).Error("accept header check failed")
 			return
@@ -107,6 +108,7 @@ func CreateWebServer(p *gcoreprovider.DnsProvider) *webServer {
 		}
 	})
 	r.Get("/records", func(w http.ResponseWriter, r *http.Request) {
+		requestLog(r).Debug("GET /records")
 		if err := acceptHeaderCheck(w, r); err != nil {
 			requestLog(r).WithField(logFieldError, err).Error("accept header check failed")
 			return
@@ -133,6 +135,7 @@ func CreateWebServer(p *gcoreprovider.DnsProvider) *webServer {
 		}
 	})
 	r.Post("/records", func(w http.ResponseWriter, r *http.Request) {
+		requestLog(r).Debug("POST /")
 		if err := contentTypeHeaderCheck(w, r); err != nil {
 			requestLog(r).WithField(logFieldError, err).Error("content type header check failed")
 			return
@@ -171,6 +174,7 @@ func CreateWebServer(p *gcoreprovider.DnsProvider) *webServer {
 		w.WriteHeader(http.StatusNoContent)
 	})
 	r.Post("/adjustendpoints", func(w http.ResponseWriter, r *http.Request) {
+		requestLog(r).Debug("POST /adjustendpoints")
 		if err := contentTypeHeaderCheck(w, r); err != nil {
 			log.Errorf("content type header check failed, request method: %s, request path: %s", r.Method, r.URL.Path)
 			return