Add example config and fix stat update (#31)

* Add debug logging
* Fix: update cached FileInfo if modified
* Exit on register failure

Author: stephen-soltesz

go.sum

@@ -103,6 +103,7 @@ github.com/json-iterator/go v1.1.6/go.mod h1:+SdeFBvtyEkXs7REEP0seUULqWtbJapLOCV
 github.com/json-iterator/go v1.1.8/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/uOdHXbAo4=
 github.com/json-iterator/go v1.1.9/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/uOdHXbAo4=
 github.com/jstemmer/go-junit-report v0.0.0-20190106144839-af01ea7f8024/go.mod h1:6v2b51hI/fHJwM22ozAgKL4VKDeJcHhJFhtBdhmNjmU=
+github.com/jstemmer/go-junit-report v0.9.1 h1:6QPYqodiu3GuPL+7mfx+NwDdp2eTkp9IfEUpgAwUN0o=
 github.com/jstemmer/go-junit-report v0.9.1/go.mod h1:Brl9GWCQeLvo8nXZwPNNblvFj/XSXhF0NWZEnDohbsk=
 github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7VTCxuUUipMqKk8s4w=
 github.com/kabukky/httpscerts v0.0.0-20150320125433-617593d7dcb3/go.mod h1:BYpt4ufZiIGv2nXn4gMxnfKV306n3mWXgNu/d2TqdTU=
@@ -133,6 +134,7 @@ github.com/prometheus/client_golang v1.0.0/go.mod h1:db9x61etRT2tGnBNRi70OPL5Fsn
 github.com/prometheus/client_golang v1.3.0/go.mod h1:hJaj2vgQTGQmVCsAACORcieXFeDPbaTKGT+JTgUa3og=
 github.com/prometheus/client_golang v1.6.0 h1:YVPodQOcK15POxhgARIvnDRVpLcuK8mglnMrWfyrw6A=
 github.com/prometheus/client_golang v1.6.0/go.mod h1:ZLOG9ck3JLRdB5MgO8f+lLTe83AXG6ro35rLTxvnIl4=
+github.com/prometheus/client_golang v1.9.0 h1:Rrch9mh17XcxvEu9D9DEpb4isxjGBtcevQjKvxPRQIU=
 github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo=
 github.com/prometheus/client_model v0.0.0-20190129233127-fd36f4220a90/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA=
 github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA=
@@ -151,6 +153,7 @@ github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsT
 github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A=
 github.com/prometheus/procfs v0.0.11 h1:DhHlBtkHWPYi8O2y31JkK0TF+DGM+51OopZjH/Ia5qI=
 github.com/prometheus/procfs v0.0.11/go.mod h1:lV6e/gmhEcM9IjHGsFOCxxuZ+z1YqCvr4OA4YeYWdaU=
+github.com/prometheus/prometheus v2.5.0+incompatible h1:7QPitgO2kOFG8ecuRn9O/4L9+10He72rVRJvMXrE9Hg=
 github.com/prometheus/prometheus v2.5.0+incompatible/go.mod h1:oAIUtOny2rjMX0OWN5vPR5/q/twIROJvdqnQKDdil/s=
 github.com/prometheus/promu v0.5.0 h1:q7GkmIdBZ+ulL+6v4EDsZL+cW9UCW9J3DHA89bFI83c=
 github.com/prometheus/promu v0.5.0/go.mod h1:sXydR89lpo0YkCrYK1EhYjaJUesenzLhd9CNRAwN+bI=
@@ -180,6 +183,7 @@ golang.org/x/exp v0.0.0-20190510132918-efd6b22b2522/go.mod h1:ZjyILWgesfNpC6sMxT
 golang.org/x/exp v0.0.0-20190829153037-c13cbed26979/go.mod h1:86+5VVa7VpoJ4kLfm080zCjGlMRFzhUhsZKEZO7MGek=
 golang.org/x/exp v0.0.0-20191030013958-a1ab85dbe136/go.mod h1:JXzH8nQsPlswgeRAPE3MuO9GYsAcnJvJ4vnMwN/5qkY=
 golang.org/x/exp v0.0.0-20191129062945-2f5052295587/go.mod h1:2RIsYlXP63K8oxa1u096TMicItID8zy7Y6sNkU49FU4=
+golang.org/x/exp v0.0.0-20191227195350-da58074b4299 h1:zQpM52jfKHG6II1ISZY1ZcpygvuSFZpLwfluuF89XOg=
 golang.org/x/exp v0.0.0-20191227195350-da58074b4299/go.mod h1:2RIsYlXP63K8oxa1u096TMicItID8zy7Y6sNkU49FU4=
 golang.org/x/image v0.0.0-20190227222117-0694c2d4d067/go.mod h1:kZ7UVZpmo3dzQBMxlp+ypCbDeSB+sBbTgSJuh5dn5js=
 golang.org/x/image v0.0.0-20190802002840-cff245a6509b/go.mod h1:FeLwcggjj3mMvU+oOTbSwawSJRM1uh48EjtB4UJZlP0=
@@ -191,6 +195,7 @@ golang.org/x/lint v0.0.0-20190409202823-959b441ac422 h1:QzoH/1pFpZguR8NrRHLcO6jK
 golang.org/x/lint v0.0.0-20190409202823-959b441ac422/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc=
 golang.org/x/lint v0.0.0-20190909230951-414d861bb4ac/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc=
 golang.org/x/lint v0.0.0-20190930215403-16217165b5de/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc=
+golang.org/x/lint v0.0.0-20191125180803-fdd1cda4f05f h1:J5lckAjkw6qYlOZNj90mLYNTEKDvWeuc1yieZ8qUzUE=
 golang.org/x/lint v0.0.0-20191125180803-fdd1cda4f05f/go.mod h1:5qLYkcX4OjUUV8bRuDixDT3tpyyb+LUpUlRWLxfhWrs=
 golang.org/x/mobile v0.0.0-20190312151609-d3739f865fa6/go.mod h1:z+o9i4GpDbdi3rU15maQ/Ox0txvL9dWGYEHz965HBQE=
 golang.org/x/mobile v0.0.0-20190719004257-d2bd2a29d028/go.mod h1:E/iHnbuqvinMTCcRqshq8CkpyQDoeVncDDYHnLhea+o=
@@ -277,6 +282,7 @@ golang.org/x/tools v0.0.0-20191113191852-77e3bb0ad9e7/go.mod h1:b+2E5dAYhXwXZwtn
 golang.org/x/tools v0.0.0-20191115202509-3a792d9c32b2/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
 golang.org/x/tools v0.0.0-20191125144606-a911d9008d1f/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
 golang.org/x/tools v0.0.0-20191216173652-a0e659d51361/go.mod h1:TB2adYChydJhpapKDTa4BR/hXlZSLoq2Wpct/0txZ28=
+golang.org/x/tools v0.0.0-20191227053925-7b8e75db28f4 h1:Toz2IK7k8rbltAXwNAxKcn9OzqyNfMUhUNjz3sL0NMk=
 golang.org/x/tools v0.0.0-20191227053925-7b8e75db28f4/go.mod h1:TB2adYChydJhpapKDTa4BR/hXlZSLoq2Wpct/0txZ28=
 golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
 golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
@@ -346,5 +352,6 @@ honnef.co/go/tools v0.0.0-20190106161140-3f1c8253044a/go.mod h1:rf3lG4BRIbNafJWh
 honnef.co/go/tools v0.0.0-20190418001031-e561f6794a2a h1:LJwr7TCTghdatWv40WobzlKXc9c4s8oGa7QKJUtHhWA=
 honnef.co/go/tools v0.0.0-20190418001031-e561f6794a2a/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4=
 honnef.co/go/tools v0.0.0-20190523083050-ea95bdfd59fc/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4=
+honnef.co/go/tools v0.0.1-2019.2.3 h1:3JgtbtFHMiCmsznwGVTUWbgGov+pVqnlf1dEJTNAXeM=
 honnef.co/go/tools v0.0.1-2019.2.3/go.mod h1:a3bituU0lyd329TUQxRnasdCoJDkEUEAqEt0JzvZhAg=
 rsc.io/binaryregexp v0.2.0/go.mod h1:qTv7/COck+e2FymRvadv62gMdZztPaShugOCi3I+8D8=

internal/setup/setup.go

@@ -5,6 +5,7 @@ import (
 	"log"
 	"os"
 
+	"github.com/m-lab/go/logx"
 	"github.com/m-lab/prometheus-bigquery-exporter/sql"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/spf13/afero"
@@ -26,6 +27,7 @@ func (f *File) IsModified() (bool, error) {
 	var err error
 	if f.stat == nil {
 		f.stat, err = fs.Stat(f.Name)
+		logx.Debug.Println("IsModified:stat1:", f.Name, err)
 		// Return true on the first successful Stat(), or the error otherwise.
 		return err == nil, err
 	}
@@ -34,7 +36,14 @@ func (f *File) IsModified() (bool, error) {
 		log.Printf("Failed to stat %q: %v", f.Name, err)
 		return false, err
 	}
-	return curr.ModTime().After(f.stat.ModTime()), nil
+	logx.Debug.Println("IsModified:stat2:", f.Name, curr.ModTime(), f.stat.ModTime(),
+		curr.ModTime().After(f.stat.ModTime()))
+	modified := curr.ModTime().After(f.stat.ModTime())
+	if modified {
+		// Update the stat cache to the latest version.
+		f.stat = curr
+	}
+	return modified, nil
 }
 
 // Register the given collector. If a collector was previously registered with
@@ -43,6 +52,7 @@ func (f *File) IsModified() (bool, error) {
 func (f *File) Register(c *sql.Collector) error {
 	if f.c != nil {
 		ok := prometheus.Unregister(f.c)
+		logx.Debug.Println("Unregister:", ok)
 		if !ok {
 			// This is a fatal error. If the
 			return fmt.Errorf("Failed to unregister %q", f.Name)
@@ -55,6 +65,7 @@ func (f *File) Register(c *sql.Collector) error {
 		// While collector Update could fail transiently, this may be a fatal error.
 		return err
 	}
+	logx.Debug.Println("Register: success:", f.Name)
 	// Save the registered collector.
 	f.c = c
 	return nil

main.go

@@ -81,10 +81,15 @@ func reloadRegisterUpdate(client *bigquery.Client, files []setup.File, vars map[
 					fileToMetric(f.Name), fileToQuery(f.Name, vars))
 
 				log.Println("Registering:", fileToMetric(f.Name))
-				err = f.Register(c)
+				// NOTE: prometheus collector registration will fail when a file
+				// uses the same name but changes the metrics reported. Because
+				// this cannot be recovered, we use rtx.Must to exit and allow
+				// the runtime environment to restart.
+				rtx.Must(f.Register(c), "Failed to register collector: aborting")
 			} else {
-				log.Println("Updating:", fileToMetric(f.Name))
+				start := time.Now()
 				err = f.Update()
+				log.Println("Updating:", fileToMetric(f.Name), time.Since(start))
 			}
 			if err != nil {
 				log.Println("Error:", f.Name, err)

sql/collector.go

@@ -4,6 +4,9 @@ package sql
 import (
 	"log"
 	"sync"
+	"time"
+
+	"github.com/m-lab/go/logx"
 
 	"github.com/prometheus/client_golang/prometheus"
 )
@@ -66,6 +69,7 @@ func NewCollector(runner QueryRunner, valType prometheus.ValueType, metricName,
 // Describe satisfies the prometheus.Collector interface. Describe is called
 // immediately after registering the collector.
 func (col *Collector) Describe(ch chan<- *prometheus.Desc) {
+	logx.Debug.Println("Describe:", time.Now())
 	if col.descs == nil {
 		// TODO: collect metrics for query exec time.
 		col.descs = make(map[string]*prometheus.Desc, 1)
@@ -84,13 +88,16 @@ func (col *Collector) Describe(ch chan<- *prometheus.Desc) {
 // Collect satisfies the prometheus.Collector interface. Collect reports values
 // from cached metrics.
 func (col *Collector) Collect(ch chan<- prometheus.Metric) {
+	logx.Debug.Println("Collect:", time.Now())
 	col.mux.Lock()
 	// Get reference to current metrics slice to allow Update to run concurrently.
 	metrics := col.metrics
 	col.mux.Unlock()
 
 	for i := range col.metrics {
 		for k, desc := range col.descs {
+			logx.Debug.Printf("%s labels:%#v values:%#v",
+				col.metricName, metrics[i].LabelValues, metrics[i].Values[k])
 			ch <- prometheus.MustNewConstMetric(
 				desc, col.valType, metrics[i].Values[k], metrics[i].LabelValues...)
 		}
@@ -105,8 +112,10 @@ func (col *Collector) String() string {
 // Update runs the collector query and atomically updates the cached metrics.
 // Update is called automaticlly after the collector is registered.
 func (col *Collector) Update() error {
+	logx.Debug.Println("Update:", col.metricName)
 	metrics, err := col.runner.Query(col.query)
 	if err != nil {
+		logx.Debug.Println("Failed to run query:", err)
 		return err
 	}
 	// Swap the cached metrics.