From 3b14db4b83d2aa507d3cb0577503edc875f24c32 Mon Sep 17 00:00:00 2001 From: Seth Hoenig Date: Mon, 21 Nov 2022 08:03:56 -0600 Subject: [PATCH] consul: add trace logging around service registrations (#15311) This PR adds trace logging around the differential done between a Nomad service registration and its corresponding Consul service registration, in an effort to shed light on why a service registration request is being made. --- .changelog/6115.txt | 3 +++ command/agent/consul/service_client.go | 27 +++++++++++++++++---- command/agent/consul/service_client_test.go | 6 ++++- 3 files changed, 30 insertions(+), 6 deletions(-) create mode 100644 .changelog/6115.txt diff --git a/.changelog/6115.txt b/.changelog/6115.txt new file mode 100644 index 000000000..c2dfcf830 --- /dev/null +++ b/.changelog/6115.txt @@ -0,0 +1,3 @@ +```release-note:improvement +consul: add trace logging around service registrations +``` diff --git a/command/agent/consul/service_client.go b/command/agent/consul/service_client.go index 54a76d170..2a72a3439 100644 --- a/command/agent/consul/service_client.go +++ b/command/agent/consul/service_client.go @@ -160,7 +160,7 @@ type ACLsAPI interface { // sidecar - Consul's view (agent, not catalog) of the service definition of the sidecar // associated with existing that may or may not exist. // May be nil. -func agentServiceUpdateRequired(reason syncReason, wanted *api.AgentServiceRegistration, existing *api.AgentService, sidecar *api.AgentService) bool { +func (s *ServiceClient) agentServiceUpdateRequired(reason syncReason, wanted *api.AgentServiceRegistration, existing *api.AgentService, sidecar *api.AgentService) bool { switch reason { case syncPeriodic: // In a periodic sync with Consul, we need to respect the value of @@ -180,7 +180,7 @@ func agentServiceUpdateRequired(reason syncReason, wanted *api.AgentServiceRegis maybeTweakTaggedAddresses(wanted, existing) // Okay now it is safe to compare. - return different(wanted, existing, sidecar) + return s.different(wanted, existing, sidecar) default: // A non-periodic sync with Consul indicates an operation has been set @@ -192,7 +192,7 @@ func agentServiceUpdateRequired(reason syncReason, wanted *api.AgentServiceRegis maybeTweakTaggedAddresses(wanted, existing) // Okay now it is safe to compare. - return different(wanted, existing, sidecar) + return s.different(wanted, existing, sidecar) } } @@ -231,27 +231,43 @@ func maybeTweakTaggedAddresses(wanted *api.AgentServiceRegistration, existing *a // different compares the wanted state of the service registration with the actual // (cached) state of the service registration reported by Consul. If any of the // critical fields are not deeply equal, they considered different. -func different(wanted *api.AgentServiceRegistration, existing *api.AgentService, sidecar *api.AgentService) bool { +func (s *ServiceClient) different(wanted *api.AgentServiceRegistration, existing *api.AgentService, sidecar *api.AgentService) bool { + trace := func(field string, left, right any) { + s.logger.Trace("registrations different", "id", wanted.ID, + "field", field, "wanted", fmt.Sprintf("%#v", left), "existing", fmt.Sprintf("%#v", right), + ) + } + switch { case wanted.Kind != existing.Kind: + trace("kind", wanted.Kind, existing.Kind) return true case wanted.ID != existing.ID: + trace("id", wanted.ID, existing.ID) return true case wanted.Port != existing.Port: + trace("port", wanted.Port, existing.Port) return true case wanted.Address != existing.Address: + trace("address", wanted.Address, existing.Address) return true case wanted.Name != existing.Service: + trace("service name", wanted.Name, existing.Service) return true case wanted.EnableTagOverride != existing.EnableTagOverride: + trace("enable_tag_override", wanted.EnableTagOverride, existing.EnableTagOverride) return true case !maps.Equal(wanted.Meta, existing.Meta): + trace("meta", wanted.Meta, existing.Meta) return true case !maps.Equal(wanted.TaggedAddresses, existing.TaggedAddresses): + trace("tagged_addresses", wanted.TaggedAddresses, existing.TaggedAddresses) return true case !helper.SliceSetEq(wanted.Tags, existing.Tags): + trace("tags", wanted.Tags, existing.Tags) return true case connectSidecarDifferent(wanted, sidecar): + trace("connect_sidecar", wanted.Name, existing.Service) return true } return false @@ -803,7 +819,8 @@ func (c *ServiceClient) sync(reason syncReason) error { serviceInConsul, exists := servicesInConsul[id] sidecarInConsul := getNomadSidecar(id, servicesInConsul) - if !exists || agentServiceUpdateRequired(reason, serviceInNomad, serviceInConsul, sidecarInConsul) { + if !exists || c.agentServiceUpdateRequired(reason, serviceInNomad, serviceInConsul, sidecarInConsul) { + c.logger.Trace("must register service", "id", id, "exists", exists, "reason", reason) if err = c.agentAPI.ServiceRegister(serviceInNomad); err != nil { metrics.IncrCounter([]string{"client", "consul", "sync_failure"}, 1) return err diff --git a/command/agent/consul/service_client_test.go b/command/agent/consul/service_client_test.go index e87845932..3723e3db9 100644 --- a/command/agent/consul/service_client_test.go +++ b/command/agent/consul/service_client_test.go @@ -85,12 +85,16 @@ func TestSyncLogic_agentServiceUpdateRequired(t *testing.T) { type asr = api.AgentServiceRegistration type tweaker func(w asr) *asr // create a conveniently modifiable copy + s := &ServiceClient{ + logger: testlog.HCLogger(t), + } + try := func( t *testing.T, exp bool, reason syncReason, tweak tweaker) { - result := agentServiceUpdateRequired(reason, tweak(wanted()), existing, sidecar) + result := s.agentServiceUpdateRequired(reason, tweak(wanted()), existing, sidecar) require.Equal(t, exp, result) }