Refactored logging; Syslog support

README.md

@@ -70,6 +70,7 @@ Massive processing of remote images is a potentially dangerous thing, security-w
    * [New Relic metrics](./docs/configuration.md#new-relic-metrics)
    * [Prometheus metrics](./docs/configuration.md#prometheus-metrics)
    * [Error reporting](./docs/configuration.md#error-reporting)
+   * [Syslog](./docs/configuration.md#syslog)
    * [Miscellaneous](./docs/configuration.md#miscellaneous)
 4. [Generating the URL](./docs/generating_the_url_basic.md)
    * [Basic](./docs/generating_the_url_basic.md)

cmyk_profile.go

@@ -3,7 +3,6 @@ package main
 import (
 	"encoding/base64"
 	"io/ioutil"
-	"log"
 	"strings"
 )
 
@@ -20059,7 +20058,7 @@ func cmykProfilePath() (string, error) {
 		f.Close()
 
 		_cmykProfilePath = f.Name()
-		log.Printf("CMYK profile was written to %v", _cmykProfilePath)
+		logNotice("CMYK profile was written to %v", _cmykProfilePath)
 	}
 
 	return _cmykProfilePath, nil

config.go

@@ -5,7 +5,6 @@ import (
 	"encoding/hex"
 	"flag"
 	"fmt"
-	"log"
 	"os"
 	"runtime"
 	"strconv"
@@ -53,7 +52,7 @@ func hexEnvConfig(b *[]securityKey, name string) {
 
 		for i, part := range parts {
 			if keys[i], err = hex.DecodeString(part); err != nil {
-				log.Fatalf("%s expected to be hex-encoded strings. Invalid: %s\n", name, part)
+				logFatal("%s expected to be hex-encoded strings. Invalid: %s\n", name, part)
 			}
 		}
 
@@ -68,7 +67,7 @@ func hexFileConfig(b *[]securityKey, filepath string) {
 
 	f, err := os.Open(filepath)
 	if err != nil {
-		log.Fatalf("Can't open file %s\n", filepath)
+		logFatal("Can't open file %s\n", filepath)
 	}
 
 	keys := []securityKey{}
@@ -84,12 +83,12 @@ func hexFileConfig(b *[]securityKey, filepath string) {
 		if key, err := hex.DecodeString(part); err == nil {
 			keys = append(keys, key)
 		} else {
-			log.Fatalf("%s expected to contain hex-encoded strings. Invalid: %s\n", filepath, part)
+			logFatal("%s expected to contain hex-encoded strings. Invalid: %s\n", filepath, part)
 		}
 	}
 
 	if err := scanner.Err(); err != nil {
-		log.Fatalf("Failed to read file %s: %s", filepath, err)
+		logFatal("Failed to read file %s: %s", filepath, err)
 	}
 
 	*b = keys
@@ -101,7 +100,7 @@ func presetEnvConfig(p presets, name string) {
 
 		for _, presetStr := range presetStrings {
 			if err := parsePreset(p, presetStr); err != nil {
-				log.Fatalln(err)
+				logFatal(err.Error())
 			}
 		}
 	}
@@ -114,18 +113,18 @@ func presetFileConfig(p presets, filepath string) {
 
 	f, err := os.Open(filepath)
 	if err != nil {
-		log.Fatalf("Can't open file %s\n", filepath)
+		logFatal("Can't open file %s\n", filepath)
 	}
 
 	scanner := bufio.NewScanner(f)
 	for scanner.Scan() {
 		if err := parsePreset(p, scanner.Text()); err != nil {
-			log.Fatalln(err)
+			logFatal(err.Error())
 		}
 	}
 
 	if err := scanner.Err(); err != nil {
-		log.Fatalf("Failed to read presets file: %s", err)
+		logFatal("Failed to read presets file: %s", err)
 	}
 }
 
@@ -221,6 +220,8 @@ var conf = config{
 }
 
 func init() {
+	initSyslog()
+
 	keyPath := flag.String("keypath", "", "path of the file with hex-encoded key")
 	saltPath := flag.String("saltpath", "", "path of the file with hex-encoded salt")
 	presetsPath := flag.String("presets", "", "path of the file with presets")
@@ -308,39 +309,39 @@ func init() {
 	strEnvConfig(&conf.SentryRelease, "IMGPROXY_SENTRY_RELEASE")
 
 	if len(conf.Keys) != len(conf.Salts) {
-		log.Fatalf("Number of keys and number of salts should be equal. Keys: %d, salts: %d", len(conf.Keys), len(conf.Salts))
+		logFatal("Number of keys and number of salts should be equal. Keys: %d, salts: %d", len(conf.Keys), len(conf.Salts))
 	}
 	if len(conf.Keys) == 0 {
-		warning("No keys defined, so signature checking is disabled")
+		logWarning("No keys defined, so signature checking is disabled")
 		conf.AllowInsecure = true
 	}
 	if len(conf.Salts) == 0 {
-		warning("No salts defined, so signature checking is disabled")
+		logWarning("No salts defined, so signature checking is disabled")
 		conf.AllowInsecure = true
 	}
 
 	if conf.SignatureSize < 1 || conf.SignatureSize > 32 {
-		log.Fatalf("Signature size should be within 1 and 32, now - %d\n", conf.SignatureSize)
+		logFatal("Signature size should be within 1 and 32, now - %d\n", conf.SignatureSize)
 	}
 
 	if len(conf.Bind) == 0 {
-		log.Fatalln("Bind address is not defined")
+		logFatal("Bind address is not defined")
 	}
 
 	if conf.ReadTimeout <= 0 {
-		log.Fatalf("Read timeout should be greater than 0, now - %d\n", conf.ReadTimeout)
+		logFatal("Read timeout should be greater than 0, now - %d\n", conf.ReadTimeout)
 	}
 
 	if conf.WriteTimeout <= 0 {
-		log.Fatalf("Write timeout should be greater than 0, now - %d\n", conf.WriteTimeout)
+		logFatal("Write timeout should be greater than 0, now - %d\n", conf.WriteTimeout)
 	}
 
 	if conf.DownloadTimeout <= 0 {
-		log.Fatalf("Download timeout should be greater than 0, now - %d\n", conf.DownloadTimeout)
+		logFatal("Download timeout should be greater than 0, now - %d\n", conf.DownloadTimeout)
 	}
 
 	if conf.Concurrency <= 0 {
-		log.Fatalf("Concurrency should be greater than 0, now - %d\n", conf.Concurrency)
+		logFatal("Concurrency should be greater than 0, now - %d\n", conf.Concurrency)
 	}
 
 	if conf.MaxClients <= 0 {
@@ -348,65 +349,65 @@ func init() {
 	}
 
 	if conf.TTL <= 0 {
-		log.Fatalf("TTL should be greater than 0, now - %d\n", conf.TTL)
+		logFatal("TTL should be greater than 0, now - %d\n", conf.TTL)
 	}
 
 	if conf.MaxSrcDimension < 0 {
-		log.Fatalf("Max src dimension should be greater than or equal to 0, now - %d\n", conf.MaxSrcDimension)
+		logFatal("Max src dimension should be greater than or equal to 0, now - %d\n", conf.MaxSrcDimension)
 	} else if conf.MaxSrcDimension > 0 {
-		warning("IMGPROXY_MAX_SRC_DIMENSION is deprecated and can be removed in future versions. Use IMGPROXY_MAX_SRC_RESOLUTION")
+		logWarning("IMGPROXY_MAX_SRC_DIMENSION is deprecated and can be removed in future versions. Use IMGPROXY_MAX_SRC_RESOLUTION")
 	}
 
 	if conf.MaxSrcResolution <= 0 {
-		log.Fatalf("Max src resolution should be greater than 0, now - %d\n", conf.MaxSrcResolution)
+		logFatal("Max src resolution should be greater than 0, now - %d\n", conf.MaxSrcResolution)
 	}
 
 	if conf.MaxGifFrames <= 0 {
-		log.Fatalf("Max GIF frames should be greater than 0, now - %d\n", conf.MaxGifFrames)
+		logFatal("Max GIF frames should be greater than 0, now - %d\n", conf.MaxGifFrames)
 	}
 
 	if conf.Quality <= 0 {
-		log.Fatalf("Quality should be greater than 0, now - %d\n", conf.Quality)
+		logFatal("Quality should be greater than 0, now - %d\n", conf.Quality)
 	} else if conf.Quality > 100 {
-		log.Fatalf("Quality can't be greater than 100, now - %d\n", conf.Quality)
+		logFatal("Quality can't be greater than 100, now - %d\n", conf.Quality)
 	}
 
 	if conf.GZipCompression < 0 {
-		log.Fatalf("GZip compression should be greater than or quual to 0, now - %d\n", conf.GZipCompression)
+		logFatal("GZip compression should be greater than or quual to 0, now - %d\n", conf.GZipCompression)
 	} else if conf.GZipCompression > 9 {
-		log.Fatalf("GZip compression can't be greater than 9, now - %d\n", conf.GZipCompression)
+		logFatal("GZip compression can't be greater than 9, now - %d\n", conf.GZipCompression)
 	}
 
 	if conf.IgnoreSslVerification {
-		warning("Ignoring SSL verification is very unsafe")
+		logWarning("Ignoring SSL verification is very unsafe")
 	}
 
 	if conf.LocalFileSystemRoot != "" {
 		stat, err := os.Stat(conf.LocalFileSystemRoot)
 		if err != nil {
-			log.Fatalf("Cannot use local directory: %s", err)
+			logFatal("Cannot use local directory: %s", err)
 		} else {
 			if !stat.IsDir() {
-				log.Fatalf("Cannot use local directory: not a directory")
+				logFatal("Cannot use local directory: not a directory")
 			}
 		}
 		if conf.LocalFileSystemRoot == "/" {
-			log.Print("Exposing root via IMGPROXY_LOCAL_FILESYSTEM_ROOT is unsafe")
+			logNotice("Exposing root via IMGPROXY_LOCAL_FILESYSTEM_ROOT is unsafe")
 		}
 	}
 
 	if err := checkPresets(conf.Presets); err != nil {
-		log.Fatalln(err)
+		logFatal(err.Error())
 	}
 
 	if conf.WatermarkOpacity <= 0 {
-		log.Fatalln("Watermark opacity should be greater than 0")
+		logFatal("Watermark opacity should be greater than 0")
 	} else if conf.WatermarkOpacity > 1 {
-		log.Fatalln("Watermark opacity should be less than or equal to 1")
+		logFatal("Watermark opacity should be less than or equal to 1")
 	}
 
 	if len(conf.PrometheusBind) > 0 && conf.PrometheusBind == conf.Bind {
-		log.Fatalln("Can't use the same binding for the main server and Prometheus")
+		logFatal("Can't use the same binding for the main server and Prometheus")
 	}
 
 	initDownloading()

docs/configuration.md

@@ -177,6 +177,15 @@ imgproxy can report occurred errors to Bugsnag, Honeybadger and Sentry:
 * `IMGPROXY_SENTRY_ENVIRONMENT`: Sentry environment to report to. Default: `production`.
 * `IMGPROXY_SENTRY_RELEASE`: Sentry release to report to. Default: `imgproxy/{imgproxy version}`.
 
+### Syslog
+
+imgproxy can send logs to syslog, but this feature is disabled by default. To enable it, set `IMGPROXY_SYSLOG_ENABLE` to `true`:
+
+* `IMGPROXY_SYSLOG_ENABLE`: when `true`, enables sending logs to syslog;
+* `IMGPROXY_SYSLOG_LEVEL`: maximum log level to send to syslog. Known levels are: `crit`, `error`, `warning` and `notice`. Default: `notice`;
+* `IMGPROXY_SYSLOG_NETWORK`: network that will be used to connect to syslog. When blank, the local syslog server will be used. Known networks are `tcp`, `tcp4`, `tcp6`, `udp`, `udp4`, `udp6`, `ip`, `ip4`, `ip6`, `unix`, `unixgram` and `unixpacket`. Default: blank;
+* `IMGPROXY_SYSLOG_ADDRESS`: address of the syslog service. Not used if `IMGPROXY_SYSLOG_NETWORK` is blank. Default: blank;
+
 ### Miscellaneous
 
 * `IMGPROXY_BASE_URL`: base URL prefix that will be added to every requested image URL. For example, if the base URL is `http://example.com/images` and `/path/to/image.png` is requested, imgproxy will download the source image from `http://example.com/images/path/to/image.png`. Default: blank.

errors.go

@@ -2,7 +2,6 @@ package main
 
 import (
 	"fmt"
-	"log"
 	"runtime"
 	"strings"
 )
@@ -39,7 +38,3 @@ func stacktrace(skip int) string {
 
 	return strings.Join(lines, "\n")
 }
-
-func warning(f string, args ...interface{}) {
-	log.Printf("\033[1;33m[WARNING]\033[0m %s", fmt.Sprintf(f, args...))
-}

examples/signature.go

@@ -6,7 +6,6 @@ import (
 	"encoding/base64"
 	"encoding/hex"
 	"fmt"
-	"log"
 )
 
 func main() {
@@ -17,11 +16,11 @@ func main() {
 	var err error
 
 	if keyBin, err = hex.DecodeString(key); err != nil {
-		log.Fatalln("Key expected to be hex-encoded string")
+		logFatal("Key expected to be hex-encoded string")
 	}
 
 	if saltBin, err = hex.DecodeString(salt); err != nil {
-		log.Fatalf("Salt expected to be hex-encoded string")
+		logFatal("Salt expected to be hex-encoded string")
 	}
 
 	resize := "fill"

gcs_transport.go

@@ -2,7 +2,6 @@ package main
 
 import (
 	"context"
-	"log"
 	"net/http"
 	"strconv"
 	"strings"
@@ -19,7 +18,7 @@ func newGCSTransport() http.RoundTripper {
 	client, err := storage.NewClient(context.Background(), option.WithCredentialsJSON([]byte(conf.GCSKey)))
 
 	if err != nil {
-		log.Fatalf("Can't create GCS client: %s", err)
+		logFatal("Can't create GCS client: %s", err)
 	}
 
 	return gcsTransport{client}

log.go

@@ -0,0 +1,90 @@
+package main
+
+import (
+	"fmt"
+	"log"
+	"log/syslog"
+	"net/http"
+)
+
+const (
+	logRequestFmt        = "[%s] %s: %s"
+	logRequestSyslogFmt  = "REQUEST [%s] %s: %s"
+	logResponseFmt       = "[%s] |\033[7;%dm %d \033[0m| %s"
+	logResponseSyslogFmt = "RESPONSE [%s] | %d | %s"
+	logWarningFmt        = "\033[1;33m[WARNING]\033[0m %s"
+	logWarningSyslogFmt  = "WARNING %s"
+	logFatalSyslogFmt    = "FATAL %s"
+)
+
+func logRequest(reqID string, r *http.Request) {
+	path := r.URL.RequestURI()
+
+	log.Printf(logRequestFmt, reqID, r.Method, path)
+
+	if syslogWriter != nil {
+		syslogWriter.Notice(fmt.Sprintf(logRequestSyslogFmt, reqID, r.Method, path))
+	}
+}
+
+func logResponse(reqID string, status int, msg string) {
+	var color int
+
+	if status >= 500 {
+		color = 31
+	} else if status >= 400 {
+		color = 33
+	} else {
+		color = 32
+	}
+
+	log.Printf(logResponseFmt, reqID, color, status, msg)
+
+	if syslogWriter != nil {
+		msg := fmt.Sprintf(logResponseSyslogFmt, reqID, status, msg)
+
+		if status >= 500 {
+			if syslogLevel >= syslog.LOG_ERR {
+				syslogWriter.Err(msg)
+			}
+		} else if status >= 400 {
+			if syslogLevel >= syslog.LOG_WARNING {
+				syslogWriter.Warning(msg)
+			}
+		} else {
+			if syslogLevel >= syslog.LOG_NOTICE {
+				syslogWriter.Notice(msg)
+			}
+		}
+	}
+}
+
+func logNotice(f string, args ...interface{}) {
+	msg := fmt.Sprintf(f, args...)
+
+	log.Print(msg)
+
+	if syslogWriter != nil && syslogLevel >= syslog.LOG_NOTICE {
+		syslogWriter.Notice(msg)
+	}
+}
+
+func logWarning(f string, args ...interface{}) {
+	msg := fmt.Sprintf(f, args...)
+
+	log.Printf(logWarningFmt, msg)
+
+	if syslogWriter != nil && syslogLevel >= syslog.LOG_WARNING {
+		syslogWriter.Warning(fmt.Sprintf(logWarningSyslogFmt, msg))
+	}
+}
+
+func logFatal(f string, args ...interface{}) {
+	msg := fmt.Sprintf(f, args...)
+
+	if syslogWriter != nil {
+		syslogWriter.Crit(fmt.Sprintf(logFatalSyslogFmt, msg))
+	}
+
+	log.Fatal(msg)
+}

newrelic.go

@@ -2,7 +2,6 @@ package main
 
 import (
 	"context"
-	"log"
 	"net/http"
 	"time"
 
@@ -33,7 +32,7 @@ func initNewrelic() {
 	newRelicApp, err = newrelic.NewApplication(config)
 
 	if err != nil {
-		log.Fatalf("Can't init New Relic agent: %s", err)
+		logFatal("Can't init New Relic agent: %s", err)
 	}
 
 	newRelicEnabled = true

process.go

@@ -10,7 +10,6 @@ import "C"
 import (
 	"context"
 	"errors"
-	"log"
 	"math"
 	"os"
 	"runtime"
@@ -43,7 +42,7 @@ func initVips() {
 
 	if err := C.vips_initialize(); err != 0 {
 		C.vips_shutdown()
-		log.Fatalln("unable to start vips!")
+		logFatal("unable to start vips!")
 	}
 
 	// Disable libvips cache. Since processing pipeline is fine tuned, we won't get much profit from it.
@@ -109,7 +108,7 @@ func initVips() {
 	cConf.WatermarkOpacity = C.double(conf.WatermarkOpacity)
 
 	if err := vipsPrepareWatermark(); err != nil {
-		log.Fatal(err)
+		logFatal(err.Error())
 	}
 }
 
@@ -659,7 +658,7 @@ func vipsSaveImage(img *C.struct__VipsImage, imgtype imageType, quality int) ([]
 		err = C.vips_jpegsave_go(img, &ptr, &imgsize, 1, C.int(quality), cConf.JpegProgressive)
 	case imageTypePNG:
 		if err = C.vips_pngsave_go(img, &ptr, &imgsize, cConf.PngInterlaced, 1); err != 0 {
-			warning("Failed to save PNG; Trying not to embed icc profile")
+			logWarning("Failed to save PNG; Trying not to embed icc profile")
 			err = C.vips_pngsave_go(img, &ptr, &imgsize, cConf.PngInterlaced, 0)
 		}
 	case imageTypeWEBP:

prometheus.go

@@ -1,7 +1,6 @@
 package main
 
 import (
-	"log"
 	"net/http"
 	"time"
 
@@ -65,9 +64,9 @@ func initPrometheus() {
 	}
 
 	go func() {
-		log.Printf("Starting Prometheus server at %s\n", s.Addr)
+		logNotice("Starting Prometheus server at %s\n", s.Addr)
 		if err := s.ListenAndServe(); err != nil && err != http.ErrServerClosed {
-			log.Fatalln(err)
+			logFatal(err.Error())
 		}
 	}()
 }

server.go

@@ -5,7 +5,6 @@ import (
 	"context"
 	"crypto/subtle"
 	"fmt"
-	"log"
 	"net"
 	"net/http"
 	"net/url"
@@ -66,7 +65,7 @@ func newHTTPHandler() *httpHandler {
 func startServer() *http.Server {
 	l, err := net.Listen("tcp", conf.Bind)
 	if err != nil {
-		log.Fatal(err)
+		logFatal(err.Error())
 	}
 	s := &http.Server{
 		Handler:        newHTTPHandler(),
@@ -75,9 +74,9 @@ func startServer() *http.Server {
 	}
 
 	go func() {
-		log.Printf("Starting server at %s\n", conf.Bind)
+		logNotice("Starting server at %s", conf.Bind)
 		if err := s.Serve(netutil.LimitListener(l, conf.MaxClients)); err != nil && err != http.ErrServerClosed {
-			log.Fatalln(err)
+			logFatal(err.Error())
 		}
 	}()
 
@@ -85,7 +84,7 @@ func startServer() *http.Server {
 }
 
 func shutdownServer(s *http.Server) {
-	log.Println("Shutting down the server...")
+	logNotice("Shutting down the server...")
 
 	ctx, close := context.WithTimeout(context.Background(), 5*time.Second)
 	defer close()
@@ -93,20 +92,6 @@ func shutdownServer(s *http.Server) {
 	s.Shutdown(ctx)
 }
 
-func logResponse(status int, msg string) {
-	var color int
-
-	if status >= 500 {
-		color = 31
-	} else if status >= 400 {
-		color = 33
-	} else {
-		color = 32
-	}
-
-	log.Printf("|\033[7;%dm %d \033[0m| %s\n", color, status, msg)
-}
-
 func writeCORS(rw http.ResponseWriter) {
 	if len(conf.AllowOrigin) > 0 {
 		rw.Header().Set("Access-Control-Allow-Origin", conf.AllowOrigin)
@@ -155,23 +140,23 @@ func respondWithImage(ctx context.Context, reqID string, r *http.Request, rw htt
 		rw.Write(data)
 	}
 
-	logResponse(200, fmt.Sprintf("[%s] Processed in %s: %s; %+v", reqID, getTimerSince(ctx), getImageURL(ctx), po))
+	logResponse(reqID, 200, fmt.Sprintf("Processed in %s: %s; %+v", getTimerSince(ctx), getImageURL(ctx), po))
 }
 
 func respondWithError(reqID string, rw http.ResponseWriter, err *imgproxyError) {
-	logResponse(err.StatusCode, fmt.Sprintf("[%s] %s", reqID, err.Message))
+	logResponse(reqID, err.StatusCode, err.Message)
 
 	rw.WriteHeader(err.StatusCode)
 	rw.Write([]byte(err.PublicMessage))
 }
 
 func respondWithOptions(reqID string, rw http.ResponseWriter) {
-	logResponse(200, fmt.Sprintf("[%s] Respond with options", reqID))
+	logResponse(reqID, 200, "Respond with options")
 	rw.WriteHeader(200)
 }
 
 func respondWithNotModified(reqID string, rw http.ResponseWriter) {
-	logResponse(200, fmt.Sprintf("[%s] Not modified", reqID))
+	logResponse(reqID, 200, "Not modified")
 	rw.WriteHeader(304)
 }
 
@@ -221,7 +206,7 @@ func (h *httpHandler) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
 		}
 	}()
 
-	log.Printf("[%s] %s: %s\n", reqID, r.Method, r.URL.RequestURI())
+	logRequest(reqID, r)
 
 	writeCORS(rw)
 

syslog.go

@@ -0,0 +1,52 @@
+package main
+
+import (
+	"log"
+	"log/syslog"
+)
+
+var (
+	syslogWriter *syslog.Writer
+	syslogLevel  syslog.Priority
+)
+
+var syslogLevels = map[string]syslog.Priority{
+	"crit":    syslog.LOG_CRIT,
+	"error":   syslog.LOG_ERR,
+	"warning": syslog.LOG_WARNING,
+	"notice":  syslog.LOG_NOTICE,
+}
+
+func initSyslog() {
+	var (
+		err error
+
+		enabled       bool
+		network, addr string
+	)
+
+	boolEnvConfig(&enabled, "IMGPROXY_SYSLOG_ENABLE")
+
+	if !enabled {
+		return
+	}
+
+	strEnvConfig(&network, "IMGPROXY_SYSLOG_NETWORK")
+	strEnvConfig(&addr, "IMGPROXY_SYSLOG_ADDRESS")
+
+	syslogWriter, err = syslog.Dial(network, addr, syslog.LOG_NOTICE, "imgproxy")
+
+	if err != nil {
+		log.Fatalf("Can't connect to syslog: %s", err)
+	}
+
+	levelStr := "notice"
+	strEnvConfig(&levelStr, "IMGPROXY_SYSLOG_LEVEL")
+
+	if l, ok := syslogLevels[levelStr]; ok {
+		syslogLevel = l
+	} else {
+		syslogLevel = syslog.LOG_NOTICE
+		logWarning("Syslog level '%s' is invalid, 'notice' is used", levelStr)
+	}
+}