Commit 88d54284 authored by Geoff Simmons's avatar Geoff Simmons

Make logging less verbose at the Info level.

Notifications from the API server (Add, Delete, Update) are now
logged at the Debug level.

Details of the monitor loop are also at the Debug level when all is
well, for example when there are no panics, child is running, etc.

Otherwise, messages previously at the Debug level are now at the
Trace level -- logging to trace and debug what the controller is
doing.
parent e1a67dd3
...@@ -88,7 +88,7 @@ func (worker *NamespaceWorker) syncBcfg(key string) error { ...@@ -88,7 +88,7 @@ func (worker *NamespaceWorker) syncBcfg(key string) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("BackendConfig %s/%s: %+v", bcfg.Namespace, worker.log.Tracef("BackendConfig %s/%s: %+v", bcfg.Namespace,
bcfg.Name, bcfg) bcfg.Name, bcfg)
if len(bcfg.Spec.Services) == 0 { if len(bcfg.Spec.Services) == 0 {
......
...@@ -204,10 +204,10 @@ func (ingc *IngressController) logObj(action string, obj interface{}) { ...@@ -204,10 +204,10 @@ func (ingc *IngressController) logObj(action string, obj interface{}) {
t, tErr := meta.TypeAccessor(obj) t, tErr := meta.TypeAccessor(obj)
if mErr == nil && tErr == nil { if mErr == nil && tErr == nil {
if t.GetKind() != "" { if t.GetKind() != "" {
ingc.log.Infof("%s %s: %s/%s", action, t.GetKind(), ingc.log.Debugf("%s %s: %s/%s", action, t.GetKind(),
m.GetNamespace(), m.GetName()) m.GetNamespace(), m.GetName())
} else { } else {
ingc.log.Infof("%s: %s/%s", action, m.GetNamespace(), ingc.log.Debugf("%s: %s/%s", action, m.GetNamespace(),
m.GetName()) m.GetName())
} }
} }
...@@ -253,7 +253,7 @@ func (ingc *IngressController) updateObj(old, new interface{}) { ...@@ -253,7 +253,7 @@ func (ingc *IngressController) updateObj(old, new interface{}) {
if oldErr == nil && newErr == nil && if oldErr == nil && newErr == nil &&
oldMeta.GetResourceVersion() == newMeta.GetResourceVersion() { oldMeta.GetResourceVersion() == newMeta.GetResourceVersion() {
if tErr == nil && t.GetKind() != "" { if tErr == nil && t.GetKind() != "" {
ingc.log.Infof("Update %s %s/%s: unchanged", ingc.log.Debugf("Update %s %s/%s: unchanged",
t.GetKind(), oldMeta.GetNamespace(), t.GetKind(), oldMeta.GetNamespace(),
oldMeta.GetName()) oldMeta.GetName())
syncCounters.WithLabelValues(oldMeta.GetNamespace(), syncCounters.WithLabelValues(oldMeta.GetNamespace(),
...@@ -274,7 +274,7 @@ func (ingc *IngressController) updateObj(old, new interface{}) { ...@@ -274,7 +274,7 @@ func (ingc *IngressController) updateObj(old, new interface{}) {
case *vcr_v1alpha1.BackendConfig: case *vcr_v1alpha1.BackendConfig:
kind = "BackendConfig" kind = "BackendConfig"
} }
ingc.log.Infof("Update %s %s/%s: unchanged", kind, ingc.log.Debugf("Update %s %s/%s: unchanged", kind,
oldMeta.GetNamespace(), oldMeta.GetName()) oldMeta.GetNamespace(), oldMeta.GetName())
syncCounters.WithLabelValues(oldMeta.GetNamespace(), syncCounters.WithLabelValues(oldMeta.GetNamespace(),
kind, "Ignore").Inc() kind, "Ignore").Inc()
...@@ -289,7 +289,7 @@ func (ingc *IngressController) updateObj(old, new interface{}) { ...@@ -289,7 +289,7 @@ func (ingc *IngressController) updateObj(old, new interface{}) {
if oldEndpExists && newEndpExists && if oldEndpExists && newEndpExists &&
len(oldEndp.Subsets) == 0 && len(newEndp.Subsets) == 0 { len(oldEndp.Subsets) == 0 && len(newEndp.Subsets) == 0 {
ingc.log.Infof("Update endpoints %s/%s: empty Subsets, ignoring", ingc.log.Debugf("Update endpoints %s/%s: empty Subsets, ignoring",
newEndp.Namespace, newEndp.Name) newEndp.Namespace, newEndp.Name)
syncCounters.WithLabelValues(oldMeta.GetNamespace(), syncCounters.WithLabelValues(oldMeta.GetNamespace(),
"Endpoints", "Ignore").Inc() "Endpoints", "Ignore").Inc()
...@@ -304,10 +304,10 @@ func (ingc *IngressController) updateObj(old, new interface{}) { ...@@ -304,10 +304,10 @@ func (ingc *IngressController) updateObj(old, new interface{}) {
} }
if metaObj != nil { if metaObj != nil {
if tErr == nil && t.GetKind() != "" { if tErr == nil && t.GetKind() != "" {
ingc.log.Infof("Update %s: %s/%s", t.GetKind(), ingc.log.Debugf("Update %s: %s/%s", t.GetKind(),
(*metaObj).GetNamespace(), (*metaObj).GetName()) (*metaObj).GetNamespace(), (*metaObj).GetName())
} else { } else {
ingc.log.Infof("Update: %s/%s", ingc.log.Debugf("Update: %s/%s",
(*metaObj).GetNamespace(), (*metaObj).GetName()) (*metaObj).GetNamespace(), (*metaObj).GetName())
} }
} }
......
...@@ -49,24 +49,24 @@ func (worker *NamespaceWorker) syncEndp(key string) error { ...@@ -49,24 +49,24 @@ func (worker *NamespaceWorker) syncEndp(key string) error {
return nil return nil
} }
worker.log.Debugf("Checking ingresses for endpoints: %s/%s", worker.log.Tracef("Checking ingresses for endpoints: %s/%s",
worker.namespace, key) worker.namespace, key)
ings, err := worker.getIngsForSvc(svc) ings, err := worker.getIngsForSvc(svc)
if err != nil { if err != nil {
return err return err
} }
if len(ings) == 0 { if len(ings) == 0 {
worker.log.Debugf("No ingresses for endpoints: %s/%s", worker.log.Tracef("No ingresses for endpoints: %s/%s",
worker.namespace, key) worker.namespace, key)
syncCounters.WithLabelValues(worker.namespace, "Endpoints", syncCounters.WithLabelValues(worker.namespace, "Endpoints",
"Ignore").Inc() "Ignore").Inc()
return nil return nil
} }
worker.log.Debugf("Update ingresses for endpoints %s", key) worker.log.Tracef("Update ingresses for endpoints %s", key)
for _, ing := range ings { for _, ing := range ings {
if !worker.isVarnishIngress(ing) { if !worker.isVarnishIngress(ing) {
worker.log.Debugf("Ingress %s/%s: not Varnish", worker.log.Tracef("Ingress %s/%s: not Varnish",
ing.Namespace, ing.Name) ing.Namespace, ing.Name)
continue continue
} }
......
...@@ -65,7 +65,7 @@ func (worker *NamespaceWorker) getVarnishSvcForIng( ...@@ -65,7 +65,7 @@ func (worker *NamespaceWorker) getVarnishSvcForIng(
return nil, err return nil, err
} }
if varnishSvc, exists := ing.Annotations[varnishSvcKey]; exists { if varnishSvc, exists := ing.Annotations[varnishSvcKey]; exists {
worker.log.Debugf("Ingress %s/%s has annotation %s:%s", worker.log.Tracef("Ingress %s/%s has annotation %s:%s",
ing.Namespace, ing.Name, varnishSvcKey, varnishSvc) ing.Namespace, ing.Name, varnishSvcKey, varnishSvc)
targetNs, targetSvc, err := targetNs, targetSvc, err :=
cache.SplitMetaNamespaceKey(varnishSvc) cache.SplitMetaNamespaceKey(varnishSvc)
...@@ -80,14 +80,14 @@ func (worker *NamespaceWorker) getVarnishSvcForIng( ...@@ -80,14 +80,14 @@ func (worker *NamespaceWorker) getVarnishSvcForIng(
return svc, nil return svc, nil
} }
} }
worker.log.Debugf("Ingress %s/%s: Varnish Service %s not found", worker.log.Tracef("Ingress %s/%s: Varnish Service %s not found",
ing.Namespace, ing.Name, varnishSvc) ing.Namespace, ing.Name, varnishSvc)
return nil, nil return nil, nil
} }
worker.log.Debugf("Ingress %s/%s does not have annotation %s", worker.log.Tracef("Ingress %s/%s does not have annotation %s",
ing.Namespace, ing.Name, varnishSvcKey) ing.Namespace, ing.Name, varnishSvcKey)
if len(svcs) == 1 { if len(svcs) == 1 {
worker.log.Debugf("Exactly one Varnish Ingress Service "+ worker.log.Tracef("Exactly one Varnish Ingress Service "+
"cluster-wide: %s", svcs[0]) "cluster-wide: %s", svcs[0])
return svcs[0], nil return svcs[0], nil
} }
...@@ -96,7 +96,7 @@ func (worker *NamespaceWorker) getVarnishSvcForIng( ...@@ -96,7 +96,7 @@ func (worker *NamespaceWorker) getVarnishSvcForIng(
return nil, err return nil, err
} }
if len(svcs) == 1 { if len(svcs) == 1 {
worker.log.Debugf("Exactly one Varnish Ingress Service "+ worker.log.Tracef("Exactly one Varnish Ingress Service "+
"in namespace %s: %s", worker.namespace, svcs[0]) "in namespace %s: %s", worker.namespace, svcs[0])
return svcs[0], nil return svcs[0], nil
} }
...@@ -377,12 +377,12 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec, ...@@ -377,12 +377,12 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec,
vcfg *vcr_v1alpha1.VarnishConfig, svc *api_v1.Service) error { vcfg *vcr_v1alpha1.VarnishConfig, svc *api_v1.Service) error {
if vcfg.Spec.SelfSharding == nil { if vcfg.Spec.SelfSharding == nil {
worker.log.Debugf("No cluster shard configuration for Service "+ worker.log.Tracef("No cluster shard configuration for Service "+
"%s/%s", svc.Namespace, svc.Name) "%s/%s", svc.Namespace, svc.Name)
return nil return nil
} }
worker.log.Debugf("Set cluster shard configuration for Service %s/%s", worker.log.Tracef("Set cluster shard configuration for Service %s/%s",
svc.Namespace, svc.Name) svc.Namespace, svc.Name)
endps, err := worker.getServiceEndpoints(svc) endps, err := worker.getServiceEndpoints(svc)
...@@ -390,7 +390,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec, ...@@ -390,7 +390,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec,
return fmt.Errorf("Error getting endpoints for service %s/%s: "+ return fmt.Errorf("Error getting endpoints for service %s/%s: "+
"%v", svc.Namespace, svc.Name, err) "%v", svc.Namespace, svc.Name, err)
} }
worker.log.Debugf("Endpoints for shard configuration: %+v", endps) worker.log.Tracef("Endpoints for shard configuration: %+v", endps)
var nAddrs int var nAddrs int
var httpPort int32 var httpPort int32
...@@ -423,7 +423,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec, ...@@ -423,7 +423,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec,
"service %s/%s", len(pods.Items), svc.Namespace, "service %s/%s", len(pods.Items), svc.Namespace,
svc.Name) svc.Name)
} }
worker.log.Debugf("Pods for shard configuration: %+v", pods.Items) worker.log.Tracef("Pods for shard configuration: %+v", pods.Items)
// Populate spec.ShardCluster.Nodes with Pod names and the http endpoint // Populate spec.ShardCluster.Nodes with Pod names and the http endpoint
for _, pod := range pods.Items { for _, pod := range pods.Items {
...@@ -437,7 +437,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec, ...@@ -437,7 +437,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec,
node.Addresses[0].Port = httpPort node.Addresses[0].Port = httpPort
spec.ShardCluster.Nodes = append(spec.ShardCluster.Nodes, node) spec.ShardCluster.Nodes = append(spec.ShardCluster.Nodes, node)
} }
worker.log.Debugf("Node configuration for self-sharding in Service "+ worker.log.Tracef("Node configuration for self-sharding in Service "+
"%s/%s: %+v", svc.Namespace, svc.Name, spec.ShardCluster.Nodes) "%s/%s: %+v", svc.Namespace, svc.Name, spec.ShardCluster.Nodes)
cfgSpec := vcfg.Spec.SelfSharding cfgSpec := vcfg.Spec.SelfSharding
...@@ -446,7 +446,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec, ...@@ -446,7 +446,7 @@ func (worker *NamespaceWorker) configSharding(spec *vcl.Spec,
if cfgSpec.Max2ndTTL != "" { if cfgSpec.Max2ndTTL != "" {
spec.ShardCluster.MaxSecondaryTTL = cfgSpec.Max2ndTTL spec.ShardCluster.MaxSecondaryTTL = cfgSpec.Max2ndTTL
} }
worker.log.Debugf("Spec configuration for self-sharding in Service "+ worker.log.Tracef("Spec configuration for self-sharding in Service "+
"%s/%s: %+v", svc.Namespace, svc.Name, spec.ShardCluster) "%s/%s: %+v", svc.Namespace, svc.Name, spec.ShardCluster)
return nil return nil
} }
...@@ -486,11 +486,11 @@ func (worker *NamespaceWorker) configAuth(spec *vcl.Spec, ...@@ -486,11 +486,11 @@ func (worker *NamespaceWorker) configAuth(spec *vcl.Spec,
vcfg.Namespace, vcfg.Name) vcfg.Namespace, vcfg.Name)
return nil return nil
} }
worker.log.Debugf("VarnishConfig %s/%s: configure %d VCL auths", worker.log.Tracef("VarnishConfig %s/%s: configure %d VCL auths",
vcfg.Namespace, vcfg.Name, len(vcfg.Spec.Auth)) vcfg.Namespace, vcfg.Name, len(vcfg.Spec.Auth))
spec.Auths = make([]vcl.Auth, 0, len(vcfg.Spec.Auth)) spec.Auths = make([]vcl.Auth, 0, len(vcfg.Spec.Auth))
for _, auth := range vcfg.Spec.Auth { for _, auth := range vcfg.Spec.Auth {
worker.log.Debugf("VarnishConfig %s/%s configuring VCL auth "+ worker.log.Tracef("VarnishConfig %s/%s configuring VCL auth "+
"from: %+v", vcfg.Namespace, vcfg.Name, auth) "from: %+v", vcfg.Namespace, vcfg.Name, auth)
secret, err := worker.secr.Get(auth.SecretName) secret, err := worker.secr.Get(auth.SecretName)
if err != nil { if err != nil {
...@@ -503,7 +503,7 @@ func (worker *NamespaceWorker) configAuth(spec *vcl.Spec, ...@@ -503,7 +503,7 @@ func (worker *NamespaceWorker) configAuth(spec *vcl.Spec,
vcfg.Namespace, vcfg.Name) vcfg.Namespace, vcfg.Name)
continue continue
} }
worker.log.Debugf("VarnishConfig %s/%s configure %d "+ worker.log.Tracef("VarnishConfig %s/%s configure %d "+
"credentials for realm %s", vcfg.Namespace, vcfg.Name, "credentials for realm %s", vcfg.Namespace, vcfg.Name,
len(secret.Data), auth.Realm) len(secret.Data), auth.Realm)
vclAuth := vcl.Auth{ vclAuth := vcl.Auth{
...@@ -520,13 +520,13 @@ func (worker *NamespaceWorker) configAuth(spec *vcl.Spec, ...@@ -520,13 +520,13 @@ func (worker *NamespaceWorker) configAuth(spec *vcl.Spec,
for user, pass := range secret.Data { for user, pass := range secret.Data {
str := user + ":" + string(pass) str := user + ":" + string(pass)
cred := base64.StdEncoding.EncodeToString([]byte(str)) cred := base64.StdEncoding.EncodeToString([]byte(str))
worker.log.Debugf("VarnishConfig %s/%s: add cred %s "+ worker.log.Tracef("VarnishConfig %s/%s: add cred %s "+
"for realm %s to VCL config", vcfg.Namespace, "for realm %s to VCL config", vcfg.Namespace,
vcfg.Name, cred, vclAuth.Realm) vcfg.Name, cred, vclAuth.Realm)
vclAuth.Credentials = append(vclAuth.Credentials, cred) vclAuth.Credentials = append(vclAuth.Credentials, cred)
} }
configConditions(vclAuth.Conditions, auth.Conditions) configConditions(vclAuth.Conditions, auth.Conditions)
worker.log.Debugf("VarnishConfig %s/%s add VCL auth config: "+ worker.log.Tracef("VarnishConfig %s/%s add VCL auth config: "+
"%+v", vcfg.Namespace, vcfg.Name, vclAuth) "%+v", vcfg.Namespace, vcfg.Name, vclAuth)
spec.Auths = append(spec.Auths, vclAuth) spec.Auths = append(spec.Auths, vclAuth)
} }
...@@ -545,7 +545,7 @@ func (worker *NamespaceWorker) configACL(spec *vcl.Spec, ...@@ -545,7 +545,7 @@ func (worker *NamespaceWorker) configACL(spec *vcl.Spec,
for i, acl := range vcfg.Spec.ACLs { for i, acl := range vcfg.Spec.ACLs {
worker.log.Infof("VarnishConfig %s/%s configuring ACL %s", worker.log.Infof("VarnishConfig %s/%s configuring ACL %s",
vcfg.Namespace, vcfg.Name, acl.Name) vcfg.Namespace, vcfg.Name, acl.Name)
worker.log.Debugf("ACL %s: %+v", acl.Name, acl) worker.log.Tracef("ACL %s: %+v", acl.Name, acl)
vclACL := vcl.ACL{ vclACL := vcl.ACL{
Name: acl.Name, Name: acl.Name,
Addresses: make([]vcl.ACLAddress, len(acl.Addresses)), Addresses: make([]vcl.ACLAddress, len(acl.Addresses)),
...@@ -578,13 +578,13 @@ func (worker *NamespaceWorker) configACL(spec *vcl.Spec, ...@@ -578,13 +578,13 @@ func (worker *NamespaceWorker) configACL(spec *vcl.Spec,
} }
configConditions(vclACL.Conditions, acl.Conditions) configConditions(vclACL.Conditions, acl.Conditions)
if acl.ResultHdr != nil { if acl.ResultHdr != nil {
worker.log.Debugf("ACL %s: ResultHdr=%+v", acl.Name, worker.log.Tracef("ACL %s: ResultHdr=%+v", acl.Name,
*acl.ResultHdr) *acl.ResultHdr)
vclACL.ResultHdr.Header = acl.ResultHdr.Header vclACL.ResultHdr.Header = acl.ResultHdr.Header
vclACL.ResultHdr.Success = acl.ResultHdr.Success vclACL.ResultHdr.Success = acl.ResultHdr.Success
vclACL.ResultHdr.Failure = acl.ResultHdr.Failure vclACL.ResultHdr.Failure = acl.ResultHdr.Failure
} }
worker.log.Debugf("VarnishConfig %s/%s add VCL ACL config: "+ worker.log.Tracef("VarnishConfig %s/%s add VCL ACL config: "+
"%+v", vcfg.Namespace, vcfg.Name, vclACL) "%+v", vcfg.Namespace, vcfg.Name, vclACL)
spec.ACLs[i] = vclACL spec.ACLs[i] = vclACL
} }
...@@ -603,7 +603,7 @@ func (worker *NamespaceWorker) configRewrites(spec *vcl.Spec, ...@@ -603,7 +603,7 @@ func (worker *NamespaceWorker) configRewrites(spec *vcl.Spec,
for i, rw := range vcfg.Spec.Rewrites { for i, rw := range vcfg.Spec.Rewrites {
worker.log.Infof("VarnishConfig %s/%s: configuring rewrite "+ worker.log.Infof("VarnishConfig %s/%s: configuring rewrite "+
"for target %s", vcfg.Namespace, vcfg.Name, rw.Target) "for target %s", vcfg.Namespace, vcfg.Name, rw.Target)
worker.log.Debugf("Rewrite: %v", rw) worker.log.Tracef("Rewrite: %v", rw)
vclRw := vcl.Rewrite{ vclRw := vcl.Rewrite{
Target: rw.Target, Target: rw.Target,
Rules: make([]vcl.RewriteRule, len(rw.Rules)), Rules: make([]vcl.RewriteRule, len(rw.Rules)),
...@@ -785,17 +785,17 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error { ...@@ -785,17 +785,17 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("VCL spec generated from the Ingresses: %v", vclSpec) worker.log.Tracef("VCL spec generated from the Ingresses: %v", vclSpec)
var vcfg *vcr_v1alpha1.VarnishConfig var vcfg *vcr_v1alpha1.VarnishConfig
worker.log.Debugf("Listing VarnishConfigs in namespace %s", worker.log.Tracef("Listing VarnishConfigs in namespace %s",
worker.namespace) worker.namespace)
vcfgs, err := worker.vcfg.List(labels.Everything()) vcfgs, err := worker.vcfg.List(labels.Everything())
if err != nil { if err != nil {
return err return err
} }
for _, v := range vcfgs { for _, v := range vcfgs {
worker.log.Debugf("VarnishConfig: %s/%s: %+v", v.Namespace, worker.log.Tracef("VarnishConfig: %s/%s: %+v", v.Namespace,
v.Name, v) v.Name, v)
for _, svcName := range v.Spec.Services { for _, svcName := range v.Spec.Services {
if svcName == svc.Name { if svcName == svc.Name {
...@@ -851,7 +851,7 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error { ...@@ -851,7 +851,7 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error {
Ver: bcfg.ResourceVersion, Ver: bcfg.ResourceVersion,
} }
} }
worker.log.Debugf("Check if config is loaded: hash=%s "+ worker.log.Tracef("Check if config is loaded: hash=%s "+
"ingressMetaData=%+v vcfgMetaData=%+v bcfgMetaData=%+v", "ingressMetaData=%+v vcfgMetaData=%+v bcfgMetaData=%+v",
vclSpec.Canonical().DeepHash(), ingsMeta, vcfgMeta, bcfgMeta) vclSpec.Canonical().DeepHash(), ingsMeta, vcfgMeta, bcfgMeta)
if worker.vController.HasConfig(svcKey, vclSpec, ingsMeta, vcfgMeta, if worker.vController.HasConfig(svcKey, vclSpec, ingsMeta, vcfgMeta,
...@@ -861,7 +861,7 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error { ...@@ -861,7 +861,7 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error {
vclSpec.Canonical().DeepHash()) vclSpec.Canonical().DeepHash())
return nil return nil
} }
worker.log.Debugf("Update config svc=%s ingressMetaData=%+v "+ worker.log.Tracef("Update config svc=%s ingressMetaData=%+v "+
"vcfgMetaData=%+v bcfgMetaData=%+v: %+v", svcKey, ingsMeta, "vcfgMetaData=%+v bcfgMetaData=%+v: %+v", svcKey, ingsMeta,
vcfgMeta, bcfgMeta, vclSpec) vcfgMeta, bcfgMeta, vclSpec)
err = worker.vController.Update(svcKey, vclSpec, ingsMeta, vcfgMeta, err = worker.vController.Update(svcKey, vclSpec, ingsMeta, vcfgMeta,
...@@ -869,7 +869,7 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error { ...@@ -869,7 +869,7 @@ func (worker *NamespaceWorker) addOrUpdateIng(ing *extensions.Ingress) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("Updated config svc=%s ingressMetaData=%+v "+ worker.log.Tracef("Updated config svc=%s ingressMetaData=%+v "+
"vcfgMetaData=%+v bcfgMetaData=%+v: %+v", svcKey, ingsMeta, "vcfgMetaData=%+v bcfgMetaData=%+v: %+v", svcKey, ingsMeta,
vcfgMeta, bcfgMeta, vclSpec) vcfgMeta, bcfgMeta, vclSpec)
return nil return nil
......
...@@ -137,7 +137,7 @@ func (worker *NamespaceWorker) syncSecret(key string) error { ...@@ -137,7 +137,7 @@ func (worker *NamespaceWorker) syncSecret(key string) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("Found Varnish services for secret %s/%s: %v", worker.log.Tracef("Found Varnish services for secret %s/%s: %v",
secret.Namespace, secret.Name, svcs) secret.Namespace, secret.Name, svcs)
if len(svcs) == 0 { if len(svcs) == 0 {
worker.log.Infof("No Varnish services with admin secret: %s/%s", worker.log.Infof("No Varnish services with admin secret: %s/%s",
...@@ -151,7 +151,7 @@ func (worker *NamespaceWorker) syncSecret(key string) error { ...@@ -151,7 +151,7 @@ func (worker *NamespaceWorker) syncSecret(key string) error {
secret.Namespace, secret.Name, admSecretKey) secret.Namespace, secret.Name, admSecretKey)
} }
secretKey := secret.Namespace + "/" + secret.Name secretKey := secret.Namespace + "/" + secret.Name
worker.log.Debugf("Setting secret %s", secretKey) worker.log.Tracef("Setting secret %s", secretKey)
worker.vController.SetAdmSecret(secretKey, secretData) worker.vController.SetAdmSecret(secretKey, secretData)
return worker.updateVarnishSvcsForSecret(svcs, secretKey) return worker.updateVarnishSvcsForSecret(svcs, secretKey)
...@@ -176,7 +176,7 @@ func (worker *NamespaceWorker) deleteSecret(obj interface{}) error { ...@@ -176,7 +176,7 @@ func (worker *NamespaceWorker) deleteSecret(obj interface{}) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("Found Varnish services for secret %s/%s: %v", worker.log.Tracef("Found Varnish services for secret %s/%s: %v",
secr.Namespace, secr.Name, svcs) secr.Namespace, secr.Name, svcs)
if len(svcs) == 0 { if len(svcs) == 0 {
worker.log.Infof("No Varnish services with admin secret: %s/%s", worker.log.Infof("No Varnish services with admin secret: %s/%s",
......
...@@ -162,13 +162,13 @@ func (worker *NamespaceWorker) syncSvc(key string) error { ...@@ -162,13 +162,13 @@ func (worker *NamespaceWorker) syncSvc(key string) error {
continue continue
} }
updateVCL = true updateVCL = true
worker.log.Debugf("Requeueing Ingress %s/%s after changed "+ worker.log.Tracef("Requeueing Ingress %s/%s after changed "+
"Varnish service %s/%s: %+v", ing.Namespace, "Varnish service %s/%s: %+v", ing.Namespace,
ing.Name, svc.Namespace, svc.Name, ing) ing.Name, svc.Namespace, svc.Name, ing)
worker.queue.Add(&SyncObj{Type: Update, Obj: ing}) worker.queue.Add(&SyncObj{Type: Update, Obj: ing})
} }
if !updateVCL { if !updateVCL {
worker.log.Debugf("No change in VCL due to changed Varnish "+ worker.log.Tracef("No change in VCL due to changed Varnish "+
"service %s/%s", svc.Namespace, svc.Name) "service %s/%s", svc.Namespace, svc.Name)
} }
...@@ -176,14 +176,14 @@ func (worker *NamespaceWorker) syncSvc(key string) error { ...@@ -176,14 +176,14 @@ func (worker *NamespaceWorker) syncSvc(key string) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("Varnish service %s/%s endpoints: %+v", svc.Namespace, worker.log.Tracef("Varnish service %s/%s endpoints: %+v", svc.Namespace,
svc.Name, endps) svc.Name, endps)
// Get the secret name and admin port for the service. We have // Get the secret name and admin port for the service. We have
// to retrieve a Pod spec for the service, then look for the // to retrieve a Pod spec for the service, then look for the
// SecretVolumeSource, and the port matching admPortName. // SecretVolumeSource, and the port matching admPortName.
secrName := "" secrName := ""
worker.log.Debugf("Searching Pods for the secret for %s/%s", worker.log.Tracef("Searching Pods for the secret for %s/%s",
svc.Namespace, svc.Name) svc.Namespace, svc.Name)
pods, err := worker.getPods(svc) pods, err := worker.getPods(svc)
if err != nil { if err != nil {
...@@ -232,7 +232,7 @@ func (worker *NamespaceWorker) syncSvc(key string) error { ...@@ -232,7 +232,7 @@ func (worker *NamespaceWorker) syncSvc(key string) error {
addrs = append(addrs, addr) addrs = append(addrs, addr)
} }
} }
worker.log.Debugf("Varnish service %s/%s addresses: %+v", svc.Namespace, worker.log.Tracef("Varnish service %s/%s addresses: %+v", svc.Namespace,
svc.Name, addrs) svc.Name, addrs)
return worker.vController.AddOrUpdateVarnishSvc( return worker.vController.AddOrUpdateVarnishSvc(
svc.Namespace+"/"+svc.Name, addrs, secrName, !updateVCL) svc.Namespace+"/"+svc.Name, addrs, secrName, !updateVCL)
......
...@@ -167,7 +167,7 @@ func (worker *NamespaceWorker) syncVcfg(key string) error { ...@@ -167,7 +167,7 @@ func (worker *NamespaceWorker) syncVcfg(key string) error {
if err != nil { if err != nil {
return err return err
} }
worker.log.Debugf("VarnishConfig %s/%s: %+v", vcfg.Namespace, worker.log.Tracef("VarnishConfig %s/%s: %+v", vcfg.Namespace,
vcfg.Name, vcfg) vcfg.Name, vcfg)
if len(vcfg.Spec.Services) == 0 { if len(vcfg.Spec.Services) == 0 {
......
...@@ -78,6 +78,9 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool { ...@@ -78,6 +78,9 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool {
metrics := getInstanceMetrics(inst.addr) metrics := getInstanceMetrics(inst.addr)
metrics.monitorChecks.Inc() metrics.monitorChecks.Inc()
vc.log.Infof("Monitoring Varnish instance %s (Service %s)", inst.addr,
svc)
if inst.admSecret == nil { if inst.admSecret == nil {
vc.warnEvt(svc, noAdmSecret, vc.warnEvt(svc, noAdmSecret,
"No admin secret known for endpoint %s", inst.addr) "No admin secret known for endpoint %s", inst.addr)
...@@ -97,7 +100,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool { ...@@ -97,7 +100,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool {
} }
defer adm.Close() defer adm.Close()
inst.Banner = adm.Banner inst.Banner = adm.Banner
vc.log.Infof("Connected to Varnish instance %s, banner: %s", inst.addr, vc.log.Debugf("Connected to Varnish instance %s, banner: %s", inst.addr,
adm.Banner) adm.Banner)
pong, err := adm.Ping() pong, err := adm.Ping()
...@@ -108,7 +111,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool { ...@@ -108,7 +111,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool {
return false return false
} }
metrics.pings.Inc() metrics.pings.Inc()
vc.log.Infof("Succesfully pinged instance %s: %+v", inst.addr, pong) vc.log.Debugf("Succesfully pinged instance %s: %+v", inst.addr, pong)
state, err := adm.Status() state, err := adm.Status()
if err != nil { if err != nil {
...@@ -118,7 +121,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool { ...@@ -118,7 +121,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool {
} }
if state == admin.Running { if state == admin.Running {
metrics.childRunning.Inc() metrics.childRunning.Inc()
vc.log.Infof("Status at %s: %s", inst.addr, state) vc.log.Debugf("Status at %s: %s", inst.addr, state)
} else { } else {
metrics.childNotRunning.Inc() metrics.childNotRunning.Inc()
vc.warnEvt(svc, statusNotRun, "Status at %s: %s", inst.addr, vc.warnEvt(svc, statusNotRun, "Status at %s: %s", inst.addr,
...@@ -132,7 +135,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool { ...@@ -132,7 +135,7 @@ func (vc *VarnishController) checkInst(svc string, inst *varnishInst) bool {
return false return false
} }
if panic == "" { if panic == "" {
vc.log.Infof("No panic at %s", inst.addr) vc.log.Debugf("No panic at %s", inst.addr)
} else { } else {
metrics.panics.Inc() metrics.panics.Inc()
vc.errorEvt(svc, panic, "Panic at %s: %s", inst.addr, panic) vc.errorEvt(svc, panic, "Panic at %s: %s", inst.addr, panic)
...@@ -192,7 +195,8 @@ func (vc *VarnishController) monitor(monitorIntvl time.Duration) { ...@@ -192,7 +195,8 @@ func (vc *VarnishController) monitor(monitorIntvl time.Duration) {
} }
if good { if good {
vc.infoEvt(svcName, monitorGood, vc.infoEvt(svcName, monitorGood,
"Monitor check good") "Monitor check good for Service: %s",
svcName)
} }
} }
} }
......
...@@ -206,14 +206,14 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst, ...@@ -206,14 +206,14 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst,
cfgName string, vclSrc string, metrics *instanceMetrics) error { cfgName string, vclSrc string, metrics *instanceMetrics) error {
vc.log.Infof("Update Varnish instance at %s", inst.addr) vc.log.Infof("Update Varnish instance at %s", inst.addr)
vc.log.Debugf("Varnish instance %s: %+v", inst.addr, *inst) vc.log.Tracef("Varnish instance %s: %+v", inst.addr, *inst)
if inst.admSecret == nil { if inst.admSecret == nil {
return fmt.Errorf("No known admin secret") return fmt.Errorf("No known admin secret")
} }
inst.admMtx.Lock() inst.admMtx.Lock()
defer inst.admMtx.Unlock() defer inst.admMtx.Unlock()
vc.log.Debugf("Connect to %s, timeout=%v", inst.addr, admTimeout) vc.log.Tracef("Connect to %s, timeout=%v", inst.addr, admTimeout)
timer := prometheus.NewTimer(metrics.connectLatency) timer := prometheus.NewTimer(metrics.connectLatency)
adm, err := admin.Dial(inst.addr, *inst.admSecret, admTimeout) adm, err := admin.Dial(inst.addr, *inst.admSecret, admTimeout)
timer.ObserveDuration() timer.ObserveDuration()
...@@ -226,12 +226,12 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst, ...@@ -226,12 +226,12 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst,
vc.log.Infof("Connected to Varnish admin endpoint at %s", inst.addr) vc.log.Infof("Connected to Varnish admin endpoint at %s", inst.addr)
loaded, labelled, ready := false, false, false loaded, labelled, ready := false, false, false
vc.log.Debugf("List VCLs at %s", inst.addr) vc.log.Tracef("List VCLs at %s", inst.addr)
vcls, err := adm.VCLList() vcls, err := adm.VCLList()
if err != nil { if err != nil {
return err return err
} }
vc.log.Debugf("VCL List at %s: %+v", inst.addr, vcls) vc.log.Tracef("VCL List at %s: %+v", inst.addr, vcls)
for _, vcl := range vcls { for _, vcl := range vcls {
if vcl.Name == cfgName { if vcl.Name == cfgName {
loaded = true loaded = true
...@@ -250,12 +250,12 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst, ...@@ -250,12 +250,12 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst,
vc.log.Infof("Config %s already loaded at instance %s", cfgName, vc.log.Infof("Config %s already loaded at instance %s", cfgName,
inst.addr) inst.addr)
} else { } else {
vc.log.Debugf("Load config %s at %s", cfgName, inst.addr) vc.log.Tracef("Load config %s at %s", cfgName, inst.addr)
timer = prometheus.NewTimer(metrics.vclLoadLatency) timer = prometheus.NewTimer(metrics.vclLoadLatency)
err = adm.VCLInline(cfgName, vclSrc) err = adm.VCLInline(cfgName, vclSrc)
timer.ObserveDuration() timer.ObserveDuration()
if err != nil { if err != nil {
vc.log.Debugf("Error loading config %s at %s: %v", vc.log.Tracef("Error loading config %s at %s: %v",
cfgName, inst.addr, err) cfgName, inst.addr, err)
metrics.vclLoadErrs.Inc() metrics.vclLoadErrs.Inc()
return err return err
...@@ -269,7 +269,7 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst, ...@@ -269,7 +269,7 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst,
vc.log.Infof("Config %s already labelled as regular at %s", vc.log.Infof("Config %s already labelled as regular at %s",
cfgName, inst.addr) cfgName, inst.addr)
} else { } else {
vc.log.Debugf("Label config %s as %s at %s", cfgName, vc.log.Tracef("Label config %s as %s at %s", cfgName,
regularLabel, inst.addr) regularLabel, inst.addr)
err = adm.VCLLabel(regularLabel, cfgName) err = adm.VCLLabel(regularLabel, cfgName)
if err != nil { if err != nil {
...@@ -283,7 +283,7 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst, ...@@ -283,7 +283,7 @@ func (vc *VarnishController) updateVarnishInstance(inst *varnishInst,
vc.log.Infof("Config %s already labelled as ready at %s", vc.log.Infof("Config %s already labelled as ready at %s",
readyCfg, inst.addr) readyCfg, inst.addr)
} else { } else {
vc.log.Debugf("Label config %s as %s at %s", readyCfg, vc.log.Tracef("Label config %s as %s at %s", readyCfg,
readinessLabel, inst.addr) readinessLabel, inst.addr)
err = adm.VCLLabel(readinessLabel, readyCfg) err = adm.VCLLabel(readinessLabel, readyCfg)
if err != nil { if err != nil {
...@@ -300,7 +300,7 @@ func (vc *VarnishController) updateVarnishSvc(name string) error { ...@@ -300,7 +300,7 @@ func (vc *VarnishController) updateVarnishSvc(name string) error {
if !exists || svc == nil { if !exists || svc == nil {
return fmt.Errorf("No known Varnish Service %s", name) return fmt.Errorf("No known Varnish Service %s", name)
} }
vc.log.Debugf("Update Varnish svc %s: config=%+v", name, *svc) vc.log.Tracef("Update Varnish svc %s: config=%+v", name, *svc)
svc.cfgLoaded = false svc.cfgLoaded = false
if svc.secrName == "" { if svc.secrName == "" {
return fmt.Errorf("No known admin secret for Varnish Service "+ return fmt.Errorf("No known admin secret for Varnish Service "+
...@@ -360,7 +360,7 @@ func (vc *VarnishController) setCfgLabel(inst *varnishInst, ...@@ -360,7 +360,7 @@ func (vc *VarnishController) setCfgLabel(inst *varnishInst,
inst.admMtx.Lock() inst.admMtx.Lock()
defer inst.admMtx.Unlock() defer inst.admMtx.Unlock()
vc.log.Debugf("Connect to %s, timeout=%v", inst.addr, admTimeout) vc.log.Tracef("Connect to %s, timeout=%v", inst.addr, admTimeout)
timer := prometheus.NewTimer(metrics.connectLatency) timer := prometheus.NewTimer(metrics.connectLatency)
adm, err := admin.Dial(inst.addr, *inst.admSecret, admTimeout) adm, err := admin.Dial(inst.addr, *inst.admSecret, admTimeout)
timer.ObserveDuration() timer.ObserveDuration()
...@@ -377,7 +377,7 @@ func (vc *VarnishController) setCfgLabel(inst *varnishInst, ...@@ -377,7 +377,7 @@ func (vc *VarnishController) setCfgLabel(inst *varnishInst,
inst.Banner = adm.Banner inst.Banner = adm.Banner
vc.log.Infof("Connected to Varnish admin endpoint at %s", inst.addr) vc.log.Infof("Connected to Varnish admin endpoint at %s", inst.addr)
vc.log.Debugf("Set config %s to label %s at %s", inst.addr, cfg, lbl) vc.log.Tracef("Set config %s to label %s at %s", inst.addr, cfg, lbl)
if err := adm.VCLLabel(lbl, cfg); err != nil { if err := adm.VCLLabel(lbl, cfg); err != nil {
if err == io.EOF { if err == io.EOF {
if mayClose { if mayClose {
...@@ -453,13 +453,13 @@ func (vc *VarnishController) updateVarnishSvcAddrs(key string, ...@@ -453,13 +453,13 @@ func (vc *VarnishController) updateVarnishSvcAddrs(key string,
remInsts = append(remInsts, inst) remInsts = append(remInsts, inst)
} }
} }
vc.log.Debugf("Varnish svc %s: keeping instances=%+v, "+ vc.log.Tracef("Varnish svc %s: keeping instances=%+v, "+
"new instances=%+v, removing instances=%+v", key, keepInsts, "new instances=%+v, removing instances=%+v", key, keepInsts,
newInsts, remInsts) newInsts, remInsts)
svc.instances = append(keepInsts, newInsts...) svc.instances = append(keepInsts, newInsts...)
for _, inst := range remInsts { for _, inst := range remInsts {
vc.log.Debugf("Varnish svc %s setting to not ready: %+v", key, vc.log.Tracef("Varnish svc %s setting to not ready: %+v", key,
inst) inst)
if err := vc.setCfgLabel(inst, notAvailCfg, readinessLabel, if err := vc.setCfgLabel(inst, notAvailCfg, readinessLabel,
true); err != nil { true); err != nil {
...@@ -470,10 +470,10 @@ func (vc *VarnishController) updateVarnishSvcAddrs(key string, ...@@ -470,10 +470,10 @@ func (vc *VarnishController) updateVarnishSvcAddrs(key string,
} }
instsGauge.Dec() instsGauge.Dec()
} }
vc.log.Debugf("Varnish svc %s config: %+v", key, *svc) vc.log.Tracef("Varnish svc %s config: %+v", key, *svc)
if loadVCL { if loadVCL {
vc.log.Debugf("Varnish svc %s: load VCL", key) vc.log.Tracef("Varnish svc %s: load VCL", key)
updateErrs := vc.updateVarnishSvc(key) updateErrs := vc.updateVarnishSvc(key)
if updateErrs != nil { if updateErrs != nil {
vadmErrs, ok := updateErrs.(VarnishAdmErrors) vadmErrs, ok := updateErrs.(VarnishAdmErrors)
...@@ -513,7 +513,7 @@ func (vc *VarnishController) AddOrUpdateVarnishSvc(key string, ...@@ -513,7 +513,7 @@ func (vc *VarnishController) AddOrUpdateVarnishSvc(key string,
addr: admAddr, addr: admAddr,
admMtx: &sync.Mutex{}, admMtx: &sync.Mutex{},
} }
vc.log.Debugf("Varnish svc %s: creating instance %+v", vc.log.Tracef("Varnish svc %s: creating instance %+v",
key, *instance) key, *instance)
instances = append(instances, instance) instances = append(instances, instance)
instsGauge.Inc() instsGauge.Inc()
...@@ -521,9 +521,9 @@ func (vc *VarnishController) AddOrUpdateVarnishSvc(key string, ...@@ -521,9 +521,9 @@ func (vc *VarnishController) AddOrUpdateVarnishSvc(key string,
svc.instances = instances svc.instances = instances
vc.svcs[key] = svc vc.svcs[key] = svc
svcsGauge.Inc() svcsGauge.Inc()
vc.log.Debugf("Varnish svc %s: created config", key) vc.log.Tracef("Varnish svc %s: created config", key)
} }
vc.log.Debugf("Varnish svc %s config: %+v", key, svc) vc.log.Tracef("Varnish svc %s config: %+v", key, svc)
svc.secrName = secrName svc.secrName = secrName
if _, exists := vc.secrets[secrName]; exists { if _, exists := vc.secrets[secrName]; exists {
...@@ -534,10 +534,10 @@ func (vc *VarnishController) AddOrUpdateVarnishSvc(key string, ...@@ -534,10 +534,10 @@ func (vc *VarnishController) AddOrUpdateVarnishSvc(key string,
for _, inst := range svc.instances { for _, inst := range svc.instances {
inst.admSecret = secrPtr inst.admSecret = secrPtr
} }
vc.log.Debugf("Varnish svc %s: updated instance with secret %s", key, vc.log.Tracef("Varnish svc %s: updated instance with secret %s", key,
secrName) secrName)
vc.log.Debugf("Update Varnish svc %s: addrs=%+v secret=%s reloadVCL=%v", vc.log.Tracef("Update Varnish svc %s: addrs=%+v secret=%s reloadVCL=%v",
key, addrs, secrName, loadVCL) key, addrs, secrName, loadVCL)
return vc.updateVarnishSvcAddrs(key, addrs, secrPtr, loadVCL) return vc.updateVarnishSvcAddrs(key, addrs, secrPtr, loadVCL)
} }
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment