Fetch tokens after every longpoll close event

Reviewed-on: #2

.env

@@ -1,3 +1,4 @@
+KDOORPI_DOOR=workshop
 KDOORPI_API_ALLOWED=http://127.0.0.1:3333/allowed
 KDOORPI_API_LONGPOLL=http://127.0.0.1:3333/longpoll
 KDOORPI_API_SWIPE=http://127.0.0.1:3333/cardswipe

Dockerfile

@@ -0,0 +1,17 @@
+FROM golang:1.21 as build
+
+WORKDIR /godoor
+
+# pre-copy/cache go.mod for pre-downloading dependencies and only redownloading them in subsequent builds if they change
+COPY go.mod go.sum ./
+RUN go mod download && go mod verify
+
+
+COPY . .
+RUN make build
+
+FROM scratch
+WORKDIR /
+COPY --from=build /godoor/godoor /godoor
+
+ENTRYPOINT ["/godoor"]

Makefile

@@ -1,4 +1,16 @@
-dev:
+.PHONY: all build build_arm64 dev
-	GOOS=linux GOARCH=arm64 go build .
+
+all: build
+
+GOBUILDLDFLAGS="-X main.Version=`git describe --dirty`"
+#GOBUILDLDFLAGS="-X main.Version=`git describe --dirty`  -linkmode 'external' -extldflags '-static'"
+
+build:
+	go build -tags netgo -ldflags=${GOBUILDLDFLAGS} .
+
+build_arm64:
+	GOOS=linux GOARCH=arm64 go build -tags netgo -ldflags=${GOBUILDLDFLAGS} .
+
+dev: build_arm64
 	scp godoor workshopdoor:/tmp/
 	ssh workshopdoor 'mv -f /tmp/godoor ~/ && sudo systemctl restart godoor'

go.mod

@@ -3,8 +3,20 @@ module godoor
 go 1.18
 
 require (
-	github.com/joho/godotenv v1.5.1 // indirect
+	github.com/joho/godotenv v1.5.1
-	github.com/warthog618/gpiod v0.8.0 // indirect
+	github.com/prometheus/client_golang v1.16.0
-	golang.org/x/crypto v0.0.0-20220331220935-ae2d96664a29 // indirect
+	github.com/warthog618/gpiod v0.8.0
-	golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1 // indirect
+	golang.org/x/crypto v0.0.0-20220331220935-ae2d96664a29
+)
+
+require (
+	github.com/beorn7/perks v1.0.1 // indirect
+	github.com/cespare/xxhash/v2 v2.2.0 // indirect
+	github.com/golang/protobuf v1.5.3 // indirect
+	github.com/matttproud/golang_protobuf_extensions v1.0.4 // indirect
+	github.com/prometheus/client_model v0.3.0 // indirect
+	github.com/prometheus/common v0.42.0 // indirect
+	github.com/prometheus/procfs v0.10.1 // indirect
+	golang.org/x/sys v0.8.0 // indirect
+	google.golang.org/protobuf v1.30.0 // indirect
 )

go.sum

@@ -1,10 +1,40 @@
+github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
+github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
+github.com/cespare/xxhash/v2 v2.2.0 h1:DC2CZ1Ep5Y4k3ZQ899DldepgrayRUGE6BBZ/cd9Cj44=
+github.com/cespare/xxhash/v2 v2.2.0/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs=
+github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
+github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
+github.com/golang/protobuf v1.3.5/go.mod h1:6O5/vntMXwX2lRkT1hjjk0nAC1IDOTvTlVgjlRvqsdk=
+github.com/golang/protobuf v1.5.0/go.mod h1:FsONVRAS9T7sI+LIUmWTfcYkHO4aIWwzhcaSAoJOfIk=
+github.com/golang/protobuf v1.5.3 h1:KhyjKVUg7Usr/dYsdSqoFveMYd5ko72D+zANwlG1mmg=
+github.com/golang/protobuf v1.5.3/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY=
+github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
+github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
 github.com/joho/godotenv v1.5.1 h1:7eLL/+HRGLY0ldzfGMeQkb7vMd0as4CfYvUVzLqw0N0=
 github.com/joho/godotenv v1.5.1/go.mod h1:f4LDr5Voq0i2e/R5DDNOoa2zzDfwtkZa6DnEwAbqwq4=
+github.com/matttproud/golang_protobuf_extensions v1.0.4 h1:mmDVorXM7PCGKw94cs5zkfA9PSy5pEvNWRP0ET0TIVo=
+github.com/matttproud/golang_protobuf_extensions v1.0.4/go.mod h1:BSXmuO+STAnVfrANrmjBb36TMTDstsz7MSK+HVaYKv4=
+github.com/pilebones/go-udev v0.0.0-20180820235104-043677e09b13 h1:Y+ynP+0QIjUejN2tsuIlWOJG1CThJy6amRuWlBL94Vg=
+github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
+github.com/prometheus/client_golang v1.16.0 h1:yk/hx9hDbrGHovbci4BY+pRMfSuuat626eFsHb7tmT8=
+github.com/prometheus/client_golang v1.16.0/go.mod h1:Zsulrv/L9oM40tJ7T815tM89lFEugiJ9HzIqaAx4LKc=
+github.com/prometheus/client_model v0.3.0 h1:UBgGFHqYdG/TPFD1B1ogZywDqEkwp3fBMvqdiQ7Xew4=
+github.com/prometheus/client_model v0.3.0/go.mod h1:LDGWKZIo7rky3hgvBe+caln+Dr3dPggB5dvjtD7w9+w=
+github.com/prometheus/common v0.42.0 h1:EKsfXEYo4JpWMHH5cg+KOUWeuJSov1Id8zGR8eeI1YM=
+github.com/prometheus/common v0.42.0/go.mod h1:xBwqVerjNdUDjgODMpudtOMwlOwf2SaTr1yjz4b7Zbc=
+github.com/prometheus/procfs v0.10.1 h1:kYK1Va/YMlutzCGazswoHKo//tZVlFpKYh+PymziUAg=
+github.com/prometheus/procfs v0.10.1/go.mod h1:nwNm2aOCAYw8uTR/9bWRREkZFxAUcWzPHWJq+XBB/FM=
+github.com/stretchr/testify v1.8.0 h1:pSgiaMZlXftHpm5L7V1+rVB+AZJydKsMxsQBIJw4PKk=
 github.com/warthog618/gpiod v0.8.0 h1:qxH9XVvWHpTxzWFSndBcujFyNH5zVRzHM63tcmm85o4=
 github.com/warthog618/gpiod v0.8.0/go.mod h1:a7Csa+IJtDBZ39++zC/6Srjo01qWejt/5velrDWuNkY=
 golang.org/x/crypto v0.0.0-20220331220935-ae2d96664a29 h1:tkVvjkPTB7pnW3jnid7kNyAMPVWllTNOf/qKDze4p9o=
 golang.org/x/crypto v0.0.0-20220331220935-ae2d96664a29/go.mod h1:IxCIyHEi3zRg3s0A5j5BB6A9Jmi73HwBIUl50j+osU4=
-golang.org/x/sys v0.0.0-20200223170610-d5e6a3e2c0ae h1:/WDfKMnPU+m5M4xB+6x4kaepxRw6jWvR5iDRdvjHgy8=
+golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
-golang.org/x/sys v0.0.0-20200223170610-d5e6a3e2c0ae/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.8.0 h1:EBmGv8NaZBZTWvrbjNoL6HVt+IVy3QDQpJs7VRIw3tU=
-golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1 h1:SrN+KX8Art/Sf4HNj6Zcz06G7VEz+7w9tdXTPOZ7+l4=
+golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+google.golang.org/protobuf v1.26.0-rc.1/go.mod h1:jlhhOSvTdKEhbULTjvd4ARK9grFBp09yW+WbY/TyQbw=
+google.golang.org/protobuf v1.26.0/go.mod h1:9q0QmTI4eRPtz6boOQmLYwt+qCgq0jsYwAQnmE0givc=
+google.golang.org/protobuf v1.30.0 h1:kPPoIgf3TsEvrm0PFe15JQ+570QVxYzEvvHqChK+cng=
+google.golang.org/protobuf v1.30.0/go.mod h1:HV8QOd/L58Z+nl8r43ehVNZIU/HEI6OcFqwMG9pJV4I=
+gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=

godoor.go

@@ -6,25 +6,29 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
+	"github.com/joho/godotenv"
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promauto"
+	"github.com/prometheus/client_golang/prometheus/promhttp"
 	"io"
 	"log"
 	"net/http"
 	"os"
 	"os/signal"
+	"runtime/debug"
+	"strconv"
 	"strings"
 	"sync"
 	"syscall"
 	"time"
 
 	"godoor/hash"
-
-	"github.com/joho/godotenv"
 )
 
-const wiegand_a = 17
+const wiegand_a_default = 17
-const wiegand_b = 18
+const wiegand_b_default = 18
 const wiegand_bit_timeout = time.Millisecond * 8
-const solenoid = 21
+const solenoid_default = 21
 
 type card struct {
 	UidHash string `json:"uid_hash"`
@@ -42,7 +46,7 @@ type ValidUids map[string]bool // bool has no meaning
 type Config struct {
 	door         string
 	uidSalt      string
-	doorOpenTime string
+	doorOpenTime int
 	mock         bool
 	api          struct {
 		allowed  string
@@ -50,6 +54,12 @@ type Config struct {
 		swipe    string
 		key      string
 	}
+	pins struct {
+		wiegandA int
+		wiegandB int
+		solenoid int
+	}
+	prometheusMetricsBind string
 }
 
 type KeepDoorOpen struct {
@@ -62,30 +72,61 @@ type OpenedTimestamp struct {
 	Closed *time.Time
 }
 
+var Commit = func() string {
+	if info, ok := debug.ReadBuildInfo(); ok {
+		for _, setting := range info.Settings {
+			if setting.Key == "vcs.revision" {
+				return setting.Value
+			}
+		}
+	}
+
+	return ""
+}()
+
+var Version string
+
 var config Config
 var globalLock sync.Mutex
 var validUids ValidUids
 var wiegand Wiegand
 var keepDoorOpen KeepDoorOpen
 
-var lastSyncedTimestamp *time.Time
+var (
-var openDoorTimestamps []OpenedTimestamp
+	godoorBuildInfo = promauto.NewGaugeVec(prometheus.GaugeOpts{
+		Name: "godoor_build_info",
+		Help: "Build Information",
+	}, []string{"version", "revision"})
+	lastSyncTimestamp = promauto.NewGauge(prometheus.GaugeOpts{
+		Name: "godoor_last_allow_list_sync_timestamp_seconds",
+		Help: "Last time list of card hashes was pulled from the server",
+	})
+	apiFailuresCount = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "godoor_api_request_failures_total",
+		Help: "HTTP API request failures count",
+	}, []string{"api", "endpoint"})
+	nrCardsInAllowList = promauto.NewGauge(prometheus.GaugeOpts{
+		Name: "godoor_allowed_card_hashes_total",
+		Help: "Number of card hashes in memory that can open the door",
+	})
+	doorOpenedCount = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "godoor_door_opens_total",
+		Help: "Number of times door was opened",
+	}, []string{"source"})
+	cardSwipesCount = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "godoor_swipes_total",
+		Help: "Number of times a card has been swiped",
+	}, []string{"status"})
+)
 
 func main() {
-
+	log.Printf("GoDoor ver: %s (%s)", Version, Commit)
 	ctx, cancel := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM)
 	defer cancel()
 
-	godotenv.Load()
+	loadConfig()
 
-	config.door = os.Getenv("KDOORPI_DOOR")
+	godoorBuildInfo.WithLabelValues(Version, Commit).Set(1)
-	config.api.allowed = os.Getenv("KDOORPI_API_ALLOWED")
-	config.api.longpoll = os.Getenv("KDOORPI_API_LONGPOLL")
-	config.api.swipe = os.Getenv("KDOORPI_API_SWIPE")
-	config.api.key = os.Getenv("KDOORPI_API_KEY")
-	config.uidSalt = os.Getenv("KDOORPI_UID_SALT")
-	config.doorOpenTime = os.Getenv("KDOORPI_OPEN_TIME")
-	_, config.mock = os.LookupEnv("KDOORPI_MOCK_HW")
 
 	go func() {
 		setup()
@@ -97,6 +138,45 @@ func main() {
 	// cleanup
 }
 
+func loadConfig() {
+	var err error
+
+	log.Println("Loading .env config")
+	err = godotenv.Load()
+	if err != nil {
+		log.Println("Failed to load .env config, using internal defaults")
+	}
+
+	config.door = os.Getenv("KDOORPI_DOOR")
+	config.api.allowed = os.Getenv("KDOORPI_API_ALLOWED")
+	config.api.longpoll = os.Getenv("KDOORPI_API_LONGPOLL")
+	config.api.swipe = os.Getenv("KDOORPI_API_SWIPE")
+	config.api.key = os.Getenv("KDOORPI_API_KEY")
+	config.uidSalt = os.Getenv("KDOORPI_UID_SALT")
+	config.doorOpenTime, err = strconv.Atoi(os.Getenv("KDOORPI_OPEN_TIME"))
+	if err != nil {
+		config.doorOpenTime = 3
+	}
+	_, config.mock = os.LookupEnv("KDOORPI_MOCK_HW")
+	config.prometheusMetricsBind = os.Getenv("KDOORPI_PROMETHEUS_METRICS_BIND")
+	if config.prometheusMetricsBind == "" {
+		config.prometheusMetricsBind = ":3334"
+	}
+
+	config.pins.wiegandA, err = strconv.Atoi(os.Getenv("KDOORPI_PIN_WIEGAND_A"))
+	if err != nil {
+		config.pins.wiegandA = wiegand_a_default
+	}
+	config.pins.wiegandB, err = strconv.Atoi(os.Getenv("KDOORPI_PIN_WIEGAND_B"))
+	if err != nil {
+		config.pins.wiegandB = wiegand_b_default
+	}
+	config.pins.solenoid, err = strconv.Atoi(os.Getenv("KDOORPI_PIN_SOLENOID"))
+	if err != nil {
+		config.pins.solenoid = solenoid_default
+	}
+}
+
 func setup() {
 	log.Println("Started Setup")
 
@@ -107,68 +187,58 @@ func setup() {
 		}
 		wiegand = &WiegandMock{}
 	} else {
-		wiegand = WiegandSetup(wiegand_a, wiegand_b, wiegand_bit_timeout, solenoid)
+		wiegand = WiegandSetup(config.pins.wiegandA, config.pins.wiegandB, wiegand_bit_timeout, config.pins.solenoid)
 	}
 	log.Println("HW Setup done")
 
+	go runHttpServer()
+
 	http.DefaultClient.Timeout = 120 * time.Second
 
-	go func() {
-		for {
-			err := waitEvents()
-			if err != nil {
-				log.Printf("LongPoll for events failed: %v", err)
-				log.Println("Will try to LongPoll again in 120 seconds")
-				time.Sleep(120 * time.Second)
-				go reloadTokens()
-			}
-			time.Sleep(1 * time.Second)
-		}
-	}()
-
-	log.Println("Initialized longpoll event loop")
-
 	for {
 		log.Println("Start initial token population")
 		err := reloadTokens()
 		if err == nil {
 			break
 		}
+		apiFailuresCount.WithLabelValues("allowed", config.api.allowed).Inc()
 		log.Printf("Initial token population failed. err: %v", err)
 		log.Println("Retrying in 10 seconds...")
 		time.Sleep(10 * time.Second)
 	}
 
-	go runHttpServer()
-
 	log.Println("Initial token population success")
 
+	go func() {
+		for {
+			err := waitEvents()
+			if err != nil {
+				apiFailuresCount.WithLabelValues("longpoll", config.api.longpoll).Inc()
+				log.Printf("LongPoll for events failed: %v", err)
+				log.Println("Will try to LongPoll again soon")
+			}
+			time.Sleep(1 * time.Second)
+			go func() {
+				err := reloadTokens()
+				if err != nil {
+					log.Printf("ReloadTokens failed: %q", err)
+					apiFailuresCount.WithLabelValues("allowed", config.api.allowed).Inc()
+				}
+			}()
+		}
+	}()
+
+	log.Println("Initialized longpoll event loop")
+
 	go cardRunner(wiegand)
 
 	log.Println("Setup completed")
 }
 
 func runHttpServer() {
-	http.HandleFunc("/lastsync", func(w http.ResponseWriter, r *http.Request) {
+	http.Handle("/metrics", promhttp.Handler())
-		e := json.NewEncoder(w)
+	log.Printf("Running prometheus metrics on http://%s/metrics", config.prometheusMetricsBind)
-		e.Encode(map[string]any{
+	log.Fatal(http.ListenAndServe(config.prometheusMetricsBind, nil))
-			"last_synced": lastSyncedTimestamp,
-		})
-	})
-	http.HandleFunc("/opened", func(w http.ResponseWriter, r *http.Request) {
-		e := json.NewEncoder(w)
-		e.Encode(map[string]any{
-			"open_timestamps": openDoorTimestamps,
-		})
-	})
-	http.HandleFunc("/isopen", func(w http.ResponseWriter, r *http.Request) {
-		e := json.NewEncoder(w)
-		open, _ := wiegand.IsDoorOpen()
-		e.Encode(map[string]any{
-			"open": open,
-		})
-	})
-	http.ListenAndServe(":3334", nil)
 }
 
 func OpenAndCloseDoor(w Wiegand) error {
@@ -184,7 +254,7 @@ func OpenAndCloseDoor(w Wiegand) error {
 
 	fmt.Println("Door is now open")
 
-	time.Sleep(5 * time.Second)
+	time.Sleep(time.Duration(config.doorOpenTime) * time.Second)
 
 	err = CloseDoor(w)
 	if err != nil {
@@ -201,7 +271,6 @@ func OpenDoor(w Wiegand) error {
 		return nil
 	}
 	w.OpenDoor()
-	openDoorTimestamps = append(openDoorTimestamps, OpenedTimestamp{Opened: time.Now(), Closed: nil})
 	return nil
 }
 
@@ -211,8 +280,6 @@ func CloseDoor(w Wiegand) error {
 		return nil
 	}
 	w.CloseDoor()
-	t := time.Now()
-	openDoorTimestamps[len(openDoorTimestamps)-1].Closed = &t
 	return nil
 }
 
@@ -223,7 +290,7 @@ func cardRunner(w Wiegand) {
 			continue
 		}
 
-		printCardId(card)
+		//printCardId(card)
 		hashedHex := hash.HashCardUid(card)
 		log.Println(hashedHex)
 
@@ -234,6 +301,7 @@ func cardRunner(w Wiegand) {
 		go func() {
 			err := sendSwipeEvent(hashedHex, ok)
 			if err != nil {
+				apiFailuresCount.WithLabelValues("swipe", config.api.swipe).Inc()
 				log.Println("Failed to send swipe event: %v", err)
 			}
 		}()
@@ -241,10 +309,13 @@ func cardRunner(w Wiegand) {
 		if ok {
 			log.Println("Opening door")
 			err := OpenAndCloseDoor(w)
+			cardSwipesCount.WithLabelValues("accepted").Inc()
+			doorOpenedCount.WithLabelValues("card").Inc()
 			if err != nil {
 				log.Println("There was an error opening and closing the Door")
 			}
 		} else {
+			cardSwipesCount.WithLabelValues("denied").Inc()
 			log.Println("Unknown card")
 		}
 
@@ -291,6 +362,9 @@ func waitEvents() error {
 	for {
 		msg, err := ParseNextMessage(reader)
 		if err != nil {
+			if err == io.EOF {
+				return nil
+			}
 			return err
 		}
 
@@ -302,6 +376,7 @@ func waitEvents() error {
 			log.Printf("got server data: %q\n", data)
 			if strings.TrimSpace(data) == config.door {
 				err := OpenAndCloseDoor(wiegand)
+				doorOpenedCount.WithLabelValues("api").Inc()
 				if err != nil {
 					log.Println("There was an error opening and closing the Door")
 				}
@@ -350,13 +425,13 @@ func reloadTokens() error {
 		totalCardCount = i
 	}
 	log.Printf("Got %d cards from server", totalCardCount)
+	nrCardsInAllowList.Set(float64(totalCardCount))
 
 	if cl.KeepOpenUntil != nil {
 		updateKeepOpenDoor(*cl.KeepOpenUntil)
 	}
 
-	t := time.Now()
+	lastSyncTimestamp.SetToCurrentTime()
-	lastSyncedTimestamp = &t
 
 	return nil
 }
@@ -389,11 +464,11 @@ func handleKeepDoorOpenCloseCleanup() {
 }
 
 func sendSwipeEvent(cardUidHash string, success bool) error {
-	swipeEvent := map[string]string{
+	swipeEvent := map[string]any{
 		"uid_hash":  cardUidHash,
 		"door":      config.door,
-		"timestamp": time.Now().Format(time.DateTime),
+		"timestamp": time.Now().Format(time.RFC3339),
-		"success":   fmt.Sprint(success),
+		"success":   success,
 	}
 
 	data, err := json.Marshal(swipeEvent)
@@ -406,6 +481,7 @@ func sendSwipeEvent(cardUidHash string, success bool) error {
 		return err
 	}
 	req.Header.Add("KEY", config.api.key)
+	req.Header.Add("Content-Type", "application/json")
 	resp, err := http.DefaultClient.Do(req)
 	if err != nil {
 		return err

wiegand.go

@@ -103,6 +103,7 @@ func (w *WiegandHW) wiegandBEvent(evt gpiod.LineEvent) {
 
 func WiegandSetup(a int, b int, bitTimeout time.Duration, solenoid int) *WiegandHW {
 
+	log.Printf("Wiegand GPIO-s: A:%d B:%d Solenoid:%d", a, b, solenoid)
 	var wiegand WiegandHW
 	wiegand.bitTimeout = bitTimeout