From 62e0ea20031ebfa664af5b0d5ab2e76336bac107 Mon Sep 17 00:00:00 2001
From: Sarasa Kisaragi <lingsamuelgrace@gmail.com>
Date: Fri, 8 Jul 2022 13:31:27 +0800
Subject: [PATCH] chore: add log for syncManifest delete upstream (#1132)

---
 pkg/ingress/apisix_route.go   | 10 +++++--
 pkg/ingress/utils/manifest.go | 53 +++++++++++++++++++++++++++++++++++
 pkg/log/default_logger.go     |  5 ++++
 pkg/log/logger.go             |  5 ++++
 4 files changed, 70 insertions(+), 3 deletions(-)

diff --git a/pkg/ingress/apisix_route.go b/pkg/ingress/apisix_route.go
index e5d36f4ac8..3738989f98 100644
--- a/pkg/ingress/apisix_route.go
+++ b/pkg/ingress/apisix_route.go
@@ -375,7 +375,9 @@ func (c *apisixRouteController) onAdd(obj interface{}) {
 		return
 	}
 	log.Debugw("ApisixRoute add event arrived",
-		zap.Any("object", obj))
+		zap.String("key", key),
+		zap.Any("object", obj),
+	)
 
 	ar := kube.MustNewApisixRoute(obj)
 	c.workqueue.Add(&types.Event{
@@ -404,8 +406,9 @@ func (c *apisixRouteController) onUpdate(oldObj, newObj interface{}) {
 		return
 	}
 	log.Debugw("ApisixRoute update event arrived",
-		zap.Any("new object", curr),
-		zap.Any("old object", prev),
+		zap.String("key", key),
+		zap.Any("new object", oldObj),
+		zap.Any("old object", newObj),
 	)
 	c.workqueue.Add(&types.Event{
 		Type: types.EventUpdate,
@@ -437,6 +440,7 @@ func (c *apisixRouteController) onDelete(obj interface{}) {
 		return
 	}
 	log.Debugw("ApisixRoute delete event arrived",
+		zap.String("key", key),
 		zap.Any("final state", ar),
 	)
 	c.workqueue.Add(&types.Event{
diff --git a/pkg/ingress/utils/manifest.go b/pkg/ingress/utils/manifest.go
index 841248ead7..c67de92d97 100644
--- a/pkg/ingress/utils/manifest.go
+++ b/pkg/ingress/utils/manifest.go
@@ -222,6 +222,10 @@ func SyncManifests(ctx context.Context, apisix apisix.APISIX, clusterName string
 		}
 		for _, r := range deleted.Routes {
 			if err := apisix.Cluster(clusterName).Route().Delete(ctx, r); err != nil {
+				log.Warnw("failed to delete route, this may affect upstream deletions",
+					zap.Error(err),
+					zap.Any("route", r),
+				)
 				merr = multierror.Append(merr, err)
 			}
 		}
@@ -240,6 +244,55 @@ func SyncManifests(ctx context.Context, apisix apisix.APISIX, clusterName string
 						zap.String("upstream_id", u.ID),
 						zap.String("upstream_name", u.Name),
 					)
+
+					if log.Level() <= zap.DebugLevel {
+						// this could also happen when the route is synced(deleted) in another syncManifest call,
+						// but arrives later than this
+						// So log the deleted routes in this call to see if it's true
+						if len(deleted.Routes) == 0 {
+							log.Debugw("syncManifest deletes upstream but doesn't delete any routes")
+						} else {
+							found := false
+
+							for _, r := range deleted.Routes {
+								if r.UpstreamId == u.ID {
+									found = true
+									log.Debugw("a deleted route is referencing upstream",
+										zap.Any("route", r),
+									)
+								}
+							}
+							if !found {
+								log.Debugw("no any deleted route is referencing this upstream",
+									zap.String("upstream_id", u.ID),
+								)
+							}
+						}
+
+						// try to find which route is referencing the upstream
+						routes, err := apisix.Cluster(clusterName).Route().List(ctx)
+						if err != nil {
+							log.Debugw("try to find referencing routes, but failed to list",
+								zap.Error(err),
+							)
+						}
+
+						found := false
+						for _, r := range routes {
+							if r.UpstreamId == u.ID {
+								found = true
+								log.Debugw("route is referencing upstream",
+									zap.Any("route", r),
+								)
+							}
+						}
+						if !found {
+							log.Debugw("failed to find a route that references the upstream",
+								zap.String("upstream_id", u.ID),
+								zap.Any("routes", routes),
+							)
+						}
+					}
 				}
 			}
 		}
diff --git a/pkg/log/default_logger.go b/pkg/log/default_logger.go
index 4c5b834795..b6cb40d0f7 100644
--- a/pkg/log/default_logger.go
+++ b/pkg/log/default_logger.go
@@ -33,6 +33,11 @@ func init() {
 	DefaultLogger = l
 }
 
+// Level returns the DefaultLogger log level
+func Level() zapcore.Level {
+	return DefaultLogger.Level()
+}
+
 // Debug uses the fmt.Sprint to construct and log a message using the DefaultLogger.
 func Debug(args ...interface{}) {
 	DefaultLogger.Debug(args...)
diff --git a/pkg/log/logger.go b/pkg/log/logger.go
index 0457790544..c99a0aead8 100644
--- a/pkg/log/logger.go
+++ b/pkg/log/logger.go
@@ -43,6 +43,11 @@ type Logger struct {
 	level  zapcore.Level
 }
 
+// Level returns the log level
+func (logger *Logger) Level() zapcore.Level {
+	return logger.level
+}
+
 func (logger *Logger) write(level zapcore.Level, message string, fields []zapcore.Field) {
 	e := zapcore.Entry{
 		Level:   level,