Merge branch 'release-2.10.0'

Wercker fixes
Fixing tests with a small sleep to sync state
Add release pipeline (let's see if it works)
Fixed some whitespace and names
Prometheus metrics for some level of stat tracking (needs more work)
UUID implementation and fallback upon ratelimt

AUTHORS

@@ -2,5 +2,5 @@ If you've made a contribution, please feel free to add your name below:
 
 Luke Strickland (clone1018) <luke@axxim.net>
 Luke Granger-Brown (lukegb) <minotar@lukegb.com>
-Luke Handle (LukeHandle) <luke.handle@googlemail.com>
+Luke Hanley (LukeHandle) <luke.handle@googlemail.com>
 Connor Peet (connor4312) <connor@peet.io>

Dockerfile

@@ -12,5 +12,5 @@ RUN apk --no-cache add ca-certificates
 COPY --from=builder /go/bin/imgd /imgd
 COPY config.example.gcfg /config.gcfg
 ENTRYPOINT ./imgd
-LABEL Name=imgd Version=2.9.5
+LABEL Name=imgd Version=2.10.0
 EXPOSE 8000

cache_off.go

@@ -18,7 +18,7 @@ func (c *CacheOff) has(username string) bool {
 
 // Should never be called.
 func (c *CacheOff) pull(username string) minecraft.Skin {
-	char, _ := minecraft.FetchSkinForChar()
+	char, _ := minecraft.FetchSkinForSteve()
 	return char
 }
 

cache_redis.go

@@ -89,7 +89,7 @@ func (c *CacheRedis) has(username string) bool {
 // What to do when failing to pull a skin from redis
 func (c *CacheRedis) pullFailed(username string) minecraft.Skin {
 	c.remove(username)
-	char, _ := minecraft.FetchSkinForChar()
+	char, _ := minecraft.FetchSkinForSteve()
 	return char
 }
 
@@ -174,19 +174,20 @@ func (c *CacheRedis) memory() uint64 {
 }
 
 func getSkinFromReply(resp *redis.Reply) (minecraft.Skin, error) {
+	skin := &minecraft.Skin{}
 	respBytes, respErr := resp.Bytes()
 	if respErr != nil {
 		return minecraft.Skin{}, respErr
 	}
 
 	imgBuf := bytes.NewReader(respBytes)
 
-	skin, skinErr := minecraft.DecodeSkin(imgBuf)
+	skinErr := skin.Decode(imgBuf)
 	if skinErr != nil {
 		return minecraft.Skin{}, skinErr
 	}
 
-	return skin, nil
+	return *skin, nil
 }
 
 // Parses a reply from redis INFO into a nice map.

http.go

@@ -6,6 +6,9 @@ import (
 	"strconv"
 	"strings"
 
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promhttp"
+
 	"github.com/gorilla/mux"
 	"github.com/minotar/minecraft"
 )
@@ -16,12 +19,20 @@ type Router struct {
 
 // Middleware function to manipulate our request and response.
 func imgdHandler(router http.Handler) http.Handler {
-	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+	return metricChain(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		w.Header().Set("Access-Control-Allow-Origin", "*")
 		w.Header().Set("Access-Control-Allow-Methods", "GET")
 		w.Header().Set("Access-Control-Allow-Headers", "Accept, Content-Type, Content-Length, Accept-Encoding")
 		router.ServeHTTP(w, r)
-	})
+	}))
+}
+
+func metricChain(router http.Handler) http.Handler {
+	return promhttp.InstrumentHandlerInFlight(inFlightGauge,
+		promhttp.InstrumentHandlerDuration(requestDuration,
+			promhttp.InstrumentHandlerResponseSize(responseSize, router),
+		),
+	)
 }
 
 type NotFoundHandler struct{}
@@ -138,7 +149,9 @@ func (router *Router) Serve(resource string) {
 			return
 		}
 
+		processingTimer := prometheus.NewTimer(processingDuration.WithLabelValues(resource))
 		err := router.ResolveMethod(skin, resource)(int(width))
+		processingTimer.ObserveDuration()
 		if err != nil {
 			w.WriteHeader(http.StatusInternalServerError)
 			fmt.Fprintf(w, "500 internal server error")
@@ -177,6 +190,8 @@ func (router *Router) Bind() {
 		log.Infof("%s %s 200", r.RemoteAddr, r.RequestURI)
 	})
 
+	router.Mux.Handle("/metrics", promhttp.Handler())
+
 	router.Mux.HandleFunc("/stats", func(w http.ResponseWriter, r *http.Request) {
 		w.Header().Set("Content-Type", "application/json")
 		w.Write(stats.ToJSON())
@@ -191,32 +206,70 @@ func (router *Router) Bind() {
 
 func fetchSkin(username string) *mcSkin {
 	if username == "char" || username == "MHF_Steve" {
-		skin, _ := minecraft.FetchSkinForChar()
+		skin, _ := minecraft.FetchSkinForSteve()
 		return &mcSkin{Skin: skin}
 	}
 
+	hasTimer := prometheus.NewTimer(cacheDuration.WithLabelValues("has"))
 	if cache.has(strings.ToLower(username)) {
+		hasTimer.ObserveDuration()
+		pullTimer := prometheus.NewTimer(cacheDuration.WithLabelValues("pull"))
+		defer pullTimer.ObserveDuration()
 		stats.HitCache()
 		return &mcSkin{Processed: nil, Skin: cache.pull(strings.ToLower(username))}
 	}
+	hasTimer.ObserveDuration()
+	stats.MissCache()
 
-	skin, err := minecraft.FetchSkinFromMojang(username)
-	if err != nil {
-		log.Debugf("Failed Skin Mojang: %s (%s)", username, err.Error())
-		// Let's fallback to S3 and try and serve at least an old skin...
-		skin, err = minecraft.FetchSkinFromS3(username)
-		if err != nil {
-			log.Debugf("Failed Skin S3: %s (%s)", username, err.Error())
-			// Well, looks like they don't exist after all.
-			skin, _ = minecraft.FetchSkinForChar()
-			stats.Errored("FallbackSteve")
+	// Everyone loves nested if statements, right?
+	var skin minecraft.Skin
+	stats.APIRequested("GetUUID")
+	uuid, err := minecraft.NormalizePlayerForUUID(username)
+	if err != nil && err.Error() == "unable to GetAPIProfile: user not found" {
+		log.Debugf("Failed UUID lookup: %s (%s)", username, err.Error())
+		skin, _ = minecraft.FetchSkinForSteve()
+		stats.Errored("UnknownUser")
+		// Don't return yet to ensure we cache the failure
+	} else {
+		var catchErr error
+		// Either no error, or there is one (eg. rate limit or network etc.), but they do possibly still exist
+		if err != nil && err.Error() == "unable to GetAPIProfile: rate limited" {
+			log.Noticef("Failed UUID lookup: %s (%s)", username, err.Error())
+			stats.Errored("LookupUUIDRateLimit")
+			catchErr = err
+		} else if err != nil {
+			// Other generic issues with looking up UUID, but still worth trying S3
+			log.Infof("Failed UUID lookup: %s (%s)", username, err.Error())
+			stats.Errored("LookupUUID")
+			catchErr = err
 		} else {
-			stats.Errored("FallbackUsernameS3")
+			// We have a UUID, so let's get a skin!
+			sPTimer := prometheus.NewTimer(getDuration.WithLabelValues("SessionProfile"))
+			skin, catchErr = minecraft.FetchSkinUUID(uuid)
+			sPTimer.ObserveDuration()
+			if catchErr != nil {
+				log.Noticef("Failed Skin SessionProfile: %s (%s)", username, catchErr.Error())
+				stats.Errored("SkinSessionProfile")
+			}
+		}
+		if catchErr != nil {
+			// Let's fallback to S3 and try and serve at least an old skin...
+			s3Timer := prometheus.NewTimer(getDuration.WithLabelValues("S3"))
+			skin, err = minecraft.FetchSkinUsernameS3(username)
+			s3Timer.ObserveDuration()
+			if err != nil {
+				log.Debugf("Failed Skin S3: %s (%s)", username, err.Error())
+				// Well, looks like they don't exist after all.
+				skin, _ = minecraft.FetchSkinForSteve()
+				stats.Errored("FallbackSteve")
+			} else {
+				stats.Errored("FallbackUsernameS3")
+			}
 		}
 	}
 
-	stats.MissCache()
+	addTimer := prometheus.NewTimer(cacheDuration.WithLabelValues("add"))
 	cache.add(strings.ToLower(username), skin)
-
+	addTimer.ObserveDuration()
 	return &mcSkin{Processed: nil, Skin: skin}
 }

main.go

@@ -16,7 +16,7 @@ const (
 	MinWidth     = uint(8)
 	MaxWidth     = uint(300)
 
-	ImgdVersion = "2.9.5"
+	ImgdVersion = "2.10.0"
 )
 
 var (

metrics.go

@@ -0,0 +1,114 @@
+package main
+
+import "github.com/prometheus/client_golang/prometheus"
+
+const namespace = "imgd"
+
+var (
+	inFlightGauge = prometheus.NewGauge(prometheus.GaugeOpts{
+		Namespace: namespace,
+		Subsystem: "http",
+		Name:      "in_flight_requests",
+		Help:      "A gauge of requests currently being served.",
+	})
+
+	requestDuration = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: namespace,
+		Subsystem: "http",
+		Name:      "request_duration_seconds",
+		Help:      "Histogram of the time (in seconds) each HTTP request took.",
+		Buckets:   []float64{.001, .005, 0.0075, .01, .025, .1, .5, 1, 5},
+	}, []string{"code"})
+
+	responseSize = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: namespace,
+		Subsystem: "http",
+		Name:      "response_size_bytes",
+		Help:      "A histogram of response sizes (in bytes) for requests.",
+		Buckets:   []float64{100, 500, 1000, 2500, 5000},
+	}, []string{})
+
+	processingDuration = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: namespace,
+		Subsystem: "image",
+		Name:      "processing_duration_seconds",
+		Help:      "Histogram of the time (in seconds) image processing took.",
+		Buckets:   []float64{.00025, .0005, 0.001, 0.0025, .005},
+	}, []string{"resource"})
+
+	getDuration = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: namespace,
+		Subsystem: "texture",
+		Name:      "get_duration_seconds",
+		Help:      "Histogram of the time (in seconds) each texture GET took.",
+		Buckets:   []float64{.1, .25, .5, 1},
+	}, []string{"source"})
+
+	cacheDuration = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: namespace,
+		Subsystem: "cache",
+		Name:      "operation_duration_seconds",
+		Help:      "Histogram of the time (in seconds) each cache operation took.",
+		Buckets:   []float64{.0005, .001, 0.0025, .005, 0.0075, 0.01, 0.1},
+	}, []string{"operation"})
+
+	errorCounter = prometheus.NewCounterVec(
+		prometheus.CounterOpts{
+			Namespace: namespace,
+			Subsystem: "status",
+			Name:      "errors",
+			Help:      "Error events",
+		},
+		[]string{"event"},
+	)
+
+	cacheCounter = prometheus.NewCounterVec(
+		prometheus.CounterOpts{
+			Namespace: namespace,
+			Subsystem: "status",
+			Name:      "cache",
+			Help:      "Cache status",
+		},
+		[]string{"status"},
+	)
+
+	requestCounter = prometheus.NewCounterVec(
+		prometheus.CounterOpts{
+			Namespace: namespace,
+			Subsystem: "status",
+			Name:      "requests",
+			Help:      "Resource requests",
+		},
+		[]string{"resource"},
+	)
+
+	apiCounter = prometheus.NewCounterVec(
+		prometheus.CounterOpts{
+			Namespace: namespace,
+			Subsystem: "status",
+			Name:      "apirequests",
+			Help:      "Requests to external APIs",
+		},
+		[]string{"call"},
+	)
+
+	// Latency on Get (source of skin) :tick:
+	// Total latency for HTTP request (response code) :tick:
+	// Latency on cache  (has, puul or add) :tick:
+	// Gauge for cache hit, miss :tick:
+	// Gauge for request (type) :tick:
+	// Latency for processing (type) :tick:
+)
+
+func init() {
+	prometheus.MustRegister(inFlightGauge)
+	prometheus.MustRegister(requestDuration)
+	prometheus.MustRegister(responseSize)
+	prometheus.MustRegister(processingDuration)
+	prometheus.MustRegister(getDuration)
+	prometheus.MustRegister(cacheDuration)
+	prometheus.MustRegister(errorCounter)
+	prometheus.MustRegister(cacheCounter)
+	prometheus.MustRegister(requestCounter)
+	prometheus.MustRegister(apiCounter)
+}