Also check generated VCLs for updates, reload when updated.

Previously only files specified in the ConfigMap were checked for
changed modification times. If only generated VCL sources were
changed, usually due to Endpoint changes, and the VCL load failed
for any reason, tehn afterward no changed VCL sources or changes
in the ConfigMap were detected. This could lead to VCL never being
updated after a change only in the generated VCLs, although the
config does not correspond to the desired state of the cluster.

Now we keep a record of the latest mtime of all VCL sources,
including generated sources, and reload VCL if any of them are
currently newer.

cmd/main.go

@@ -180,13 +180,15 @@ func main() {
 	}
 
 	tmplMap := make(map[string]string, len(templatePaths))
-	for _, tmplPath := range templatePaths {
+	generated := make([]string, len(templatePaths))
+	for i, tmplPath := range templatePaths {
 		tmplArgs := strings.Split(tmplPath, ":")
 		if len(tmplArgs) != 2 {
 			log.Fatal("illegal template arg: ", tmplPath)
 			os.Exit(-1)
 		}
 		tmplMap[tmplArgs[0]] = tmplArgs[1]
+		generated[i] = tmplArgs[1]
 	}
 
 	fqSvcs := make([]string, len(services))
@@ -239,6 +241,7 @@ func main() {
 
 	updaterCfg := apiclient.SpecUpdaterConfig{
 		SvcKeys:         fqSvcs,
+		Generated:       generated,
 		Main:            *mainF,
 		CfgMapNamespace: cfgMapNamespace,
 		CfgMapName:      cfgMapName,

pkg/apiclient/spec.go

@@ -48,6 +48,7 @@ import (
 // resources that are considered for a VCL update.
 type SpecUpdaterConfig struct {
 	SvcKeys         []string
+	Generated       []string
 	Main            string
 	CfgMapName      string
 	CfgMapNamespace string
@@ -58,13 +59,14 @@ type SpecUpdaterConfig struct {
 // SpecUpdater encapsulates updating the VCL spec from the current
 // state of the k8s cluster.
 type SpecUpdater struct {
-	log    *logrus.Logger
-	cfg    SpecUpdaterConfig
-	vcls   map[string]time.Time
-	vc     *varnish.Controller
-	svc    core_v1_listers.ServiceLister
-	endp   core_v1_listers.EndpointsLister
-	cfgMap core_v1_listers.ConfigMapLister
+	log     *logrus.Logger
+	cfg     SpecUpdaterConfig
+	vcls    map[string]time.Time
+	genvcls map[string]time.Time
+	vc      *varnish.Controller
+	svc     core_v1_listers.ServiceLister
+	endp    core_v1_listers.EndpointsLister
+	cfgMap  core_v1_listers.ConfigMapLister
 }
 
 // NewSpecUpdater creates a SpecUpdater.
@@ -72,15 +74,20 @@ func NewSpecUpdater(
 	log *logrus.Logger,
 	cfg SpecUpdaterConfig,
 	vc *varnish.Controller,
-	listers *Listers) *SpecUpdater {
-
+	listers *Listers,
+) *SpecUpdater {
+	genvcls := make(map[string]time.Time, len(cfg.Generated))
+	for _, gen := range cfg.Generated {
+		genvcls[gen] = time.Time{}
+	}
 	return &SpecUpdater{
-		log:    log,
-		cfg:    cfg,
-		vc:     vc,
-		endp:   listers.endp,
-		svc:    listers.svc,
-		cfgMap: listers.cfgMap,
+		log:     log,
+		cfg:     cfg,
+		genvcls: genvcls,
+		vc:      vc,
+		endp:    listers.endp,
+		svc:     listers.svc,
+		cfgMap:  listers.cfgMap,
 	}
 }
 
@@ -287,8 +294,28 @@ func (updater *SpecUpdater) VCLChanged(cfgMap *api_v1.ConfigMap) (bool, error) {
 	return false, nil
 }
 
+func (updater *SpecUpdater) genVCLChanged() (bool, error) {
+	for path, mtime := range updater.genvcls {
+		info, err := os.Stat(path)
+		if err != nil {
+			if os.IsNotExist(err) {
+				updater.log.Warn("Generated VCL not found: ",
+					path)
+				continue
+			}
+			return false, err
+		}
+		if mtime != info.ModTime() {
+			updater.log.Trace(path, " new mtime ", info.ModTime())
+			return true, nil
+		}
+	}
+	return false, nil
+}
+
 // ClearVCL resets the record of VCL files and their modification
-// times.
+// times. The record of VCL files generated from template is
+// unaffected.
 func (updater *SpecUpdater) ClearVCL() {
 	updater.vcls = nil
 }
@@ -315,6 +342,26 @@ func (updater *SpecUpdater) updatedVCLMap(
 	return
 }
 
+func (updater *SpecUpdater) updatedGenVCLMap() (
+	map[string]time.Time,
+	error,
+) {
+	vclMap := make(map[string]time.Time, len(updater.genvcls))
+	for path := range updater.genvcls {
+		info, err := os.Stat(path)
+		if err != nil {
+			if os.IsNotExist(err) {
+				updater.log.Warn("Generated VCL not found: ",
+					path)
+				continue
+			}
+			return nil, err
+		}
+		vclMap[path] = info.ModTime()
+	}
+	return vclMap, nil
+}
+
 func (updater *SpecUpdater) latestVCLMtime() time.Time {
 	latest := time.Time{}
 	for _, t := range updater.vcls {
@@ -322,13 +369,19 @@ func (updater *SpecUpdater) latestVCLMtime() time.Time {
 			latest = t
 		}
 	}
+	for _, t := range updater.genvcls {
+		if t.After(latest) {
+			latest = t
+		}
+	}
 	return latest
 }
 
 // Update generates a new configuration from the current state of the
 // k8s cluster, and loads it as a new instance of VCL.
 func (updater *SpecUpdater) Update() error {
-	updater.log.Debug("Current VCL file modification times: ", updater.vcls)
+	updater.log.Debug("Current VCL file modification times: ",
+		updater.vcls, updater.genvcls)
 	updater.log.Info("Current latest known VCL file modification time: ",
 		updater.latestVCLMtime())
 	spec, err := updater.getSpec()
@@ -344,10 +397,16 @@ func (updater *SpecUpdater) Update() error {
 			spec.CfgMap.Namespace, spec.CfgMap.Name, err)
 		return err
 	}
+	genVCLChanged, err := updater.genVCLChanged()
+	if err != nil {
+		updater.log.Errorf("Error checking generated VCL mtimes: %v",
+			err)
+		return err
+	}
 	if !updater.vc.HasConfigMap(spec.CfgMap) {
 		if changed, err := updater.VCLChanged(cfgMap); err != nil {
 			return err
-		} else if !changed {
+		} else if !genVCLChanged && !changed {
 			updater.log.Warnf("ConfigMap %s/%s has changed but "+
 				"VCL files have not been updated, not "+
 				"updating Varnish config",
@@ -365,6 +424,12 @@ func (updater *SpecUpdater) Update() error {
 			"times: %v", err)
 		return err
 	}
+	updatedGenMap, err := updater.updatedGenVCLMap()
+	if err != nil {
+		updater.log.Errorf("Cannot update generated VCL mtimes: %v",
+			err)
+		return err
+	}
 	if err = updater.vc.Update(&spec); err != nil {
 		// XXX generate Warn event, inc counter
 		updater.log.Errorf("Update failed: %s", err)
@@ -372,7 +437,9 @@ func (updater *SpecUpdater) Update() error {
 	}
 	// XXX generate Info event, inc counter(?)
 	updater.vcls = updatedMap
-	updater.log.Debug("Updated VCL file modification times: ", updater.vcls)
+	updater.genvcls = updatedGenMap
+	updater.log.Debug("Updated VCL file modification times: ", updater.vcls,
+		updater.genvcls)
 	updater.log.Info("Updated latest known VCL file modification time: ",
 		updater.latestVCLMtime())
 	updater.log.Info("Varnish update succeeded")

pkg/apiclient/spec_test.go

@@ -299,3 +299,109 @@ func TestVCLChanged(t *testing.T) {
 		t.Errorf("VCLChanged(%v) got: true, want: false", cfgMap)
 	}
 }
+
+func flushFile(t *testing.T, path string) {
+	if file, err := os.Open(path); err != nil {
+		t.Fatalf("Open(%s): %v", path, err)
+	} else {
+		if err = file.Sync(); err != nil {
+			t.Fatalf("Sync(%s): %v", path, err)
+		}
+		if err = file.Close(); err != nil {
+			t.Fatalf("Close(%s): %v", path, err)
+		}
+	}
+}
+
+func TestGenVCLChanged(t *testing.T) {
+	tmpdir, err := ioutil.TempDir("", "k8s-vcl-reloader")
+	if err != nil {
+		t.Fatalf("Cannot create tmp directory: %v", err)
+	}
+	defer os.RemoveAll(tmpdir)
+
+	logger, hook := test.NewNullLogger()
+	updater := &SpecUpdater{
+		log:     logger,
+		genvcls: make(map[string]time.Time, 4),
+	}
+	updater.log.Level = logrus.TraceLevel
+
+	for _, file := range []string{"foo", "bar", "baz", "quux"} {
+		updater.genvcls[filepath.Join(tmpdir, file+".vcl")] =
+			time.Time{}
+	}
+	changed, err := updater.genVCLChanged()
+	if err != nil {
+		t.Fatal("genVCLChanged() (no files): ", err)
+	}
+	if changed {
+		t.Error("genVCLChanged(): got: true, want: false")
+	}
+	if hook.LastEntry().Level != logrus.WarnLevel {
+		t.Errorf("genVCLChanged() log level got: %v, want: WarnLevel",
+			hook.LastEntry().Level)
+	}
+	pfx := "Generated VCL not found:"
+	if !strings.HasPrefix(hook.LastEntry().Message, pfx) {
+		t.Errorf("genVCLChanged() log message got: \"%s\", "+
+			"want prefix: %s", hook.LastEntry().Message, pfx)
+	}
+
+	for path := range updater.genvcls {
+		if err = ioutil.WriteFile(path, []byte{}, 0644); err != nil {
+			t.Fatalf("Cannot write %s: %v", path, err)
+		}
+		flushFile(t, path)
+		defer os.Remove(path)
+	}
+	changed, err = updater.genVCLChanged()
+	if err != nil {
+		t.Fatal("genVCLChanged(): ", err)
+	}
+	if !changed {
+		t.Error("genVCLChanged() got: false, want: true")
+	}
+
+	if updater.genvcls, err = updater.updatedGenVCLMap(); err != nil {
+		t.Fatal("updatedGenVCLMap() :", err)
+	}
+	changed, err = updater.genVCLChanged()
+	if err != nil {
+		t.Fatal("genVCLChanged(): ", err)
+	}
+	if changed {
+		t.Error("genVCLChanged() got: true, want: false")
+	}
+
+	paths := make([]string, len(updater.genvcls))
+	i := 0
+	for path := range updater.genvcls {
+		paths[i] = path
+		i++
+	}
+	for _, path := range paths {
+		if err = ioutil.WriteFile(path, []byte{47}, 0644); err != nil {
+			t.Fatalf("Cannot write %s: %v", path, err)
+		}
+		flushFile(t, path)
+		changed, err = updater.genVCLChanged()
+		if err != nil {
+			t.Fatal("genVCLChanged(): ", err)
+		}
+		if !changed {
+			t.Error("genVCLChanged() got: false, want: true")
+		}
+
+		if updater.genvcls, err = updater.updatedGenVCLMap(); err != nil {
+			t.Fatal("updatedGenVCLMap() :", err)
+		}
+		changed, err = updater.genVCLChanged()
+		if err != nil {
+			t.Fatal("genVCLChanged(): ", err)
+		}
+		if changed {
+			t.Error("genVCLChanged() got: true, want: false")
+		}
+	}
+}