changeset 5495:0766dcb7e7f8

Merged logging branch into default.
author Sascha L. Teichmann <sascha.teichmann@intevation.de>
date Tue, 21 Sep 2021 12:49:30 +0200
parents a726a92ea5c9 (current diff) fb532459eb2e (diff)
children 8797274e2739 6738655809eb
files
diffstat 54 files changed, 573 insertions(+), 316 deletions(-) [+]
line wrap: on
line diff
--- a/cmd/gemma/main.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/cmd/gemma/main.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,7 +18,7 @@
 import (
 	"context"
 	"fmt"
-	"log"
+	lg "log"
 	"net/http"
 	"os"
 	"os/signal"
@@ -34,6 +34,7 @@
 	"gemma.intevation.de/gemma/pkg/controllers"
 	"gemma.intevation.de/gemma/pkg/geoserver"
 	"gemma.intevation.de/gemma/pkg/imports"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/middleware"
 	"gemma.intevation.de/gemma/pkg/scheduler"
 )
@@ -49,11 +50,18 @@
 
 func start(cmd *cobra.Command, args []string) {
 
+	if lf := config.LogFile(); lf != "" {
+		log.SetupLog(lf, 0666)
+		defer log.ShutdownLog()
+	}
+
+	log.SetLogLevel(config.LogLevel())
+
 	config.Ready()
 
 	web, err := filepath.Abs(config.Web())
 	if err != nil {
-		log.Fatalf("error: %v\n", err)
+		log.Fatalf("%v\n", err)
 	}
 
 	prepareSessionStore()
@@ -73,7 +81,7 @@
 	m.PathPrefix("/").Handler(dir)
 
 	addr := fmt.Sprintf("%s:%d", config.WebHost(), config.WebPort())
-	log.Printf("info: listen on %s\n", addr)
+	log.Infof("listen on %s\n", addr)
 
 	var h http.Handler
 
@@ -102,7 +110,7 @@
 	select {
 	case err := <-done:
 		if err != nil && err != http.ErrServerClosed {
-			log.Fatalf("error: %v\n", err)
+			log.Fatalf("%v\n", err)
 		}
 	case <-sigChan:
 	}
@@ -112,14 +120,13 @@
 	<-done
 
 	if err := auth.Sessions.Shutdown(); err != nil {
-		log.Fatalf("error: %v\n", err)
+		log.Fatalf("%v\n", err)
 	}
 }
 
 func main() {
 	config.RootCmd.Run = start
-	log.SetFlags(log.LstdFlags | log.Lshortfile)
 	if err := config.RootCmd.Execute(); err != nil {
-		log.Fatalln(err)
+		lg.Fatalln(err)
 	}
 }
--- a/example_conf.toml	Sat Aug 21 15:01:52 2021 +0200
+++ b/example_conf.toml	Tue Sep 21 12:49:30 2021 +0200
@@ -89,3 +89,8 @@
 # schema-dirs = "$PATH_TO_SCHEMATA"
 # published-config ="$PATH/pub-config.json"
 # report-path = "$PATH_TO_XSLX_AND_YAML_PAIRS"
+
+# File to log to. Default empty -> stderr
+# log-file = ""
+# Level of logging. Possible values: trace, debug, info, warn, error, fatal.
+# log-level = "info"
--- a/pkg/auth/store.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/auth/store.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,11 +16,12 @@
 import (
 	"bytes"
 	"errors"
-	"log"
 	"time"
 
+	bolt "go.etcd.io/bbolt"
+
 	"gemma.intevation.de/gemma/pkg/config"
-	bolt "go.etcd.io/bbolt"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // ErrNoSuchToken is returned if a given token does not
@@ -130,7 +131,7 @@
 		return b.Delete([]byte(token))
 	})
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
 
@@ -163,7 +164,7 @@
 		return b.Put([]byte(token), buf.Bytes())
 	})
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
 
@@ -252,10 +253,10 @@
 // If using the persistent mode the backing session database is closed.
 func (ss *SessionStore) Shutdown() error {
 	if db := ss.storage; db != nil {
-		log.Println("info: shutdown persistent session store.")
+		log.Infof("shutdown persistent session store.")
 		ss.storage = nil
 		return db.Close()
 	}
-	log.Println("info: shutdown in-memory session store.")
+	log.Infof("shutdown in-memory session store.")
 	return nil
 }
--- a/pkg/common/attributes.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/common/attributes.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,10 +15,11 @@
 package common
 
 import (
-	"log"
 	"strconv"
 	"strings"
 	"time"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 type (
@@ -126,7 +127,7 @@
 	}
 	d, err := time.Parse(DateFormat, s)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return time.Time{}, false
 	}
 	return d, true
@@ -147,7 +148,7 @@
 	}
 	t, err := time.Parse(TimeFormat, s)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return time.Time{}, false
 	}
 	return t, true
@@ -171,7 +172,7 @@
 	}
 	i, err := strconv.Atoi(s)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return 0, false
 	}
 	return i, true
@@ -194,7 +195,7 @@
 	}
 	f, err := strconv.ParseFloat(s, 64)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return 0, false
 	}
 	return f, true
@@ -217,7 +218,7 @@
 	}
 	d, err := time.ParseDuration(s)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return 0, false
 	}
 	return d, true
--- a/pkg/common/random.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/common/random.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,11 +17,12 @@
 	"bytes"
 	"crypto/rand"
 	"io"
-	"log"
 	"math"
 	"math/big"
 	mrand "math/rand"
 	"time"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // GenerateRandomKey generates a cryptographically secure random key
@@ -54,7 +55,7 @@
 		for i := range out {
 			v, err := rand.Int(rand.Reader, max)
 			if err != nil {
-				log.Panicf("error: %v\n", err)
+				log.Panicf("%v\n", err)
 			}
 			out[i] = alphabet[v.Int64()]
 		}
@@ -63,7 +64,7 @@
 			return string(out)
 		}
 	}
-	log.Println("warn: Your random generator may be broken.")
+	log.Warnf("Your random generator may be broken.")
 	out[0] = special[0]
 	return string(out)
 }
@@ -77,7 +78,7 @@
 
 	var seed int64
 	if seedInt, err := rand.Int(rand.Reader, big.NewInt(math.MaxInt64)); err != nil {
-		log.Printf("warn: Generating good random seed failed: %v\n", err)
+		log.Warnf("Generating good random seed failed: %v\n", err)
 		seed = time.Now().Unix()
 	} else {
 		seed = seedInt.Int64()
--- a/pkg/config/config.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/config/config.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,7 +17,7 @@
 import (
 	"crypto/sha256"
 	"fmt"
-	"log"
+	lg "log"
 	"sync"
 	"time"
 
@@ -27,6 +27,7 @@
 	"github.com/spf13/viper"
 
 	"gemma.intevation.de/gemma/pkg/common"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // This is not part of the persistent config.
@@ -125,6 +126,12 @@
 // ReportPath is a path where report templates are stored.
 func ReportPath() string { return viper.GetString("report-path") }
 
+// LogFile is the path to the log file.
+func LogFile() string { return viper.GetString("log-file") }
+
+// LogLevel is the log level of the application.
+func LogLevel() log.LogLevel { return log.ParseLogLevel(viper.GetString("log-level")) }
+
 var (
 	proxyKeyOnce       sync.Once
 	proxyKey           []byte
@@ -192,7 +199,7 @@
 		if sessionTimeout == 0 {
 			sessionTimeout = viper.GetDuration("session-timeout")
 			if sessionTimeout <= 0 {
-				log.Println("warn: non-positive session-timeout configured.")
+				lg.Println("warn: non-positive session-timeout configured.")
 			}
 		}
 	}
@@ -296,6 +303,10 @@
 	str("report-path", "", "path to a report templates.")
 
 	d("soap-timeout", 3*time.Minute, "Timeout till a SOAP request is canceled.")
+
+	str("log-file", "", "path to a file to log to.")
+	str("log-level", log.InfoLogLevel.String(), "path to a file to log to.")
+
 }
 
 var (
@@ -332,7 +343,7 @@
 		// Find home directory.
 		home, err := homedir.Dir()
 		if err != nil {
-			log.Fatalf("error: %v\n", err)
+			lg.Fatalf("error: %v\n", err)
 		}
 
 		// Search config in home directory with name ".cobra" (without extension).
@@ -344,6 +355,6 @@
 			// Don't bother if not found.
 			return
 		}
-		log.Fatalf("Can't read config: %v\n", err)
+		lg.Fatalf("Can't read config: %v\n", err)
 	}
 }
--- a/pkg/controllers/common.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/common.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,11 +15,12 @@
 
 import (
 	"fmt"
-	"log"
 	"strconv"
 	"strings"
 
 	"github.com/jackc/pgx/pgtype"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 type (
@@ -94,7 +95,7 @@
 	}
 	var ia pgtype.Int8Array
 	if err := ia.Set(ints); err != nil {
-		log.Printf("warn: %v\n", err)
+		log.Warnf("%v\n", err)
 		return nil
 	}
 	return &ia
@@ -106,7 +107,7 @@
 	}
 	var ta pgtype.TextArray
 	if err := ta.Set(s); err != nil {
-		log.Printf("warn: %v\n", err)
+		log.Warnf("%v\n", err)
 		return nil
 	}
 	return &ta
--- a/pkg/controllers/cross.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/cross.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,10 +17,10 @@
 	"context"
 	"database/sql"
 	"fmt"
-	"log"
 	"net/http"
 	"time"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/mesh"
 	"gemma.intevation.de/gemma/pkg/models"
 
@@ -78,7 +78,7 @@
 		ctx, conn,
 		csi.Properties.Bottleneck, csi.Properties.Date.Time)
 
-	log.Printf("info: loading mesh took %s\n", time.Since(start))
+	log.Infof("loading mesh took %s\n", time.Since(start))
 	if err != nil {
 		return
 	}
@@ -110,7 +110,7 @@
 
 	coords, err := reproject(ctx, rp, csi.Geometry.Coordinates)
 
-	log.Printf("info: transforming input coords took %s\n", time.Since(start))
+	log.Infof("transforming input coords took %s\n", time.Since(start))
 	if err != nil {
 		return
 	}
@@ -133,16 +133,16 @@
 		})
 
 		if len(line) > 0 {
-			log.Printf("info: line length: %d\n", len(line))
+			log.Infof("line length: %d\n", len(line))
 			// They are all on the segment (c1.Lat, c1.Lon) - (c2.Lat, c2.Lon).
 			// Sort them by project them on this line.
 			joined := line.JoinOnLine(c1.Lat, c1.Lon, c2.Lat, c2.Lon)
-			log.Printf("info: joined length: %d\n", len(joined))
+			log.Infof("joined length: %d\n", len(joined))
 			segments = append(segments, joined...)
 		}
 
 	}
-	log.Printf("info: mesh traversal took %s\n", time.Since(start))
+	log.Infof("mesh traversal took %s\n", time.Since(start))
 
 	start = time.Now()
 
@@ -153,7 +153,7 @@
 		conn,
 	)
 
-	log.Printf("info: projecting back took %s\n", time.Since(start))
+	log.Infof("projecting back took %s\n", time.Since(start))
 	if err != nil {
 		return
 	}
--- a/pkg/controllers/diff.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/diff.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,13 +18,13 @@
 	"database/sql"
 	"errors"
 	"fmt"
-	"log"
 	"net/http"
 	"runtime"
 	"time"
 
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/common"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/mesh"
 	"gemma.intevation.de/gemma/pkg/models"
 
@@ -166,7 +166,7 @@
 		ctx, conn,
 		dci.Bottleneck, dci.Minuend.Time)
 
-	log.Printf("info: loading minuend mesh took %s\n", time.Since(start))
+	log.Infof("loading minuend mesh took %s\n", time.Since(start))
 	if err != nil {
 		return 0, err
 	}
@@ -199,13 +199,13 @@
 		return 0, errors.New("intersection is empty")
 	}
 
-	log.Printf("info: bbox of intersection: (%.2f, %.2f) - (%.2f, %.2f)\n",
+	log.Infof("bbox of intersection: (%.2f, %.2f) - (%.2f, %.2f)\n",
 		box.X1, box.Y1, box.X2, box.Y2)
 
 	start = time.Now()
 	raster := mesh.NewRaster(box, isoCellSize)
 	raster.Rasterize(minuendTree.Value)
-	log.Printf("info: rasterizing minuend took %v\n", time.Since(start))
+	log.Infof("rasterizing minuend took %v\n", time.Since(start))
 
 	minuendTree = nil
 
@@ -215,7 +215,7 @@
 		ctx, conn,
 		dci.Bottleneck, dci.Subtrahend.Time)
 
-	log.Printf("info: loading subtrahend mesh took %s\n", time.Since(start))
+	log.Infof("loading subtrahend mesh took %s\n", time.Since(start))
 	if err != nil {
 		return 0, err
 	}
@@ -234,7 +234,7 @@
 
 	start = time.Now()
 	raster.Diff(subtrahendTree.Value)
-	log.Printf("info: A - B took %v\n", time.Since(start))
+	log.Infof("A - B took %v\n", time.Since(start))
 	subtrahendTree = nil
 
 	// XXX: Maybe we should start this transaction earlier!?
@@ -249,7 +249,7 @@
 		return 0, errors.New("scans do not have common points")
 	}
 
-	log.Printf("info: z range: %.3f - %.3f\n", zMin, zMax)
+	log.Infof("z range: %.3f - %.3f\n", zMin, zMax)
 
 	var heights mesh.ClassBreaks
 
@@ -257,7 +257,7 @@
 		ctx, tx,
 		"morphology_classbreaks_compare")
 	if err != nil {
-		log.Printf("warn: Loading class breaks failed: %v\n", err)
+		log.Warnf("Loading class breaks failed: %v\n", err)
 		err = nil
 		heights = mesh.SampleDiffHeights(zMin, zMax, contourStep)
 	} else {
@@ -266,7 +266,7 @@
 
 	heights = common.DedupFloat64s(heights)
 
-	log.Printf("info: num heights: %d\n", len(heights))
+	log.Infof("num heights: %d\n", len(heights))
 
 	var isoStmt *sql.Stmt
 	if isoStmt, err = tx.PrepareContext(ctx, insertDiffIsoAreasQL); err != nil {
@@ -308,18 +308,18 @@
 		}
 	}
 
-	log.Printf("info: Transferred WKB size: %.2fMB.\n",
+	log.Infof("Transferred WKB size: %.2fMB.\n",
 		float64(size)/(1024*1024))
 
-	log.Printf("info: calculating and storing iso areas took %v\n",
+	log.Infof("calculating and storing iso areas took %v\n",
 		time.Since(start))
 
 	if err = tx.Commit(); err != nil {
-		log.Printf("info: difference calculation failed after %v\n",
+		log.Infof("difference calculation failed after %v\n",
 			time.Since(begin))
 		return 0, err
 	}
-	log.Printf("info: difference calculation succeed after %v\n",
+	log.Infof("difference calculation succeed after %v\n",
 		time.Since(begin))
 
 	return id, nil
@@ -443,7 +443,7 @@
 			}
 		}
 	case <-ctx.Done():
-		log.Println("request canceled")
+		log.Infoln("request canceled")
 	}
 
 	return
--- a/pkg/controllers/fwa.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/fwa.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,7 +18,6 @@
 	"database/sql"
 	"encoding/csv"
 	"fmt"
-	"log"
 	"net/http"
 	"sort"
 	"strconv"
@@ -28,6 +27,7 @@
 	"github.com/gorilla/mux"
 
 	"gemma.intevation.de/gemma/pkg/common"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/middleware"
 )
 
@@ -219,7 +219,7 @@
 	}
 
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "cannot extract bottlenecks", http.StatusBadRequest)
 		return
 	}
@@ -233,19 +233,19 @@
 	// load validities and limiting factors
 	for i := range bns {
 		if err := bns[i].loadLimitingValidities(ctx, conn, from, to); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "cannot load validities", http.StatusInternalServerError)
 			return
 		}
 		// load LCDs
 		if err := bns[i].loadLDCs(ctx, conn, from, to); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "cannot load LDCs", http.StatusInternalServerError)
 			return
 		}
 		// load values
 		if err := bns[i].loadValues(ctx, conn, from, to, los); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "cannot load values", http.StatusInternalServerError)
 			return
 		}
@@ -300,7 +300,7 @@
 
 	if err := out.Write(record); err != nil {
 		// Too late for HTTP status message.
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 
@@ -417,7 +417,7 @@
 		if finish(next) {
 			if err := write(); err != nil {
 				// Too late for HTTP status message.
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 				return
 			}
 
@@ -435,14 +435,14 @@
 	if totalDays > 0 {
 		if err := write(); err != nil {
 			// Too late for HTTP status message.
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return
 		}
 	}
 
 	for i, days := range missingLDCs {
 		if missingLDCs[i] > 0 {
-			log.Printf("warn: Missing LDCs for %s on %d days.\n",
+			log.Warnf("warn: Missing LDCs for %s on %d days.\n",
 				bns[i].id, days)
 		}
 	}
@@ -450,7 +450,7 @@
 	out.Flush()
 	if err := out.Error(); err != nil {
 		// Too late for HTTP status message.
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
 
@@ -526,7 +526,7 @@
 	defaults, err := breaksToReferenceValue(breaks)
 	if err != nil {
 		msg := fmt.Sprintf("Parameter '%s' is invalid: %s.", parameter, err)
-		log.Printf("error: %s\n", msg)
+		log.Errorf("%s\n", msg)
 		http.Error(rw, msg, http.StatusBadRequest)
 		return nil, false
 	}
@@ -586,7 +586,7 @@
 	case "width":
 		return limitingWidth
 	default:
-		log.Printf("warn: unknown limitation '%s'. default to 'depth'\n", limiting)
+		log.Warnf("unknown limitation '%s'. default to 'depth'\n", limiting)
 		return limitingDepth
 	}
 }
--- a/pkg/controllers/gauges.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/gauges.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,7 +18,6 @@
 	"database/sql"
 	"encoding/csv"
 	"fmt"
-	"log"
 	"math"
 	"net/http"
 	"sort"
@@ -31,6 +30,7 @@
 	"gonum.org/v1/gonum/stat"
 
 	"gemma.intevation.de/gemma/pkg/common"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 
 	mw "gemma.intevation.de/gemma/pkg/middleware"
@@ -193,8 +193,8 @@
 	begin := time.Date(year, time.January, 1, 0, 0, 0, 0, time.UTC)
 	end := time.Date(year+1, time.January, 1, 0, 0, 0, 0, time.UTC).Add(-time.Microsecond)
 
-	log.Printf("info: begin %s\n", begin)
-	log.Printf("info: end   %s\n", end)
+	log.Infof("begin %s\n", begin)
+	log.Infof("end   %s\n", end)
 
 	rows, err := conn.QueryContext(
 		ctx,
@@ -235,7 +235,7 @@
 		var when time.Time
 		var value float64
 		if err := rows.Scan(&when, &value); err != nil {
-			log.Printf("error: %v", err)
+			log.Errorf("%v", err)
 			// Too late for an HTTP error code.
 			return
 		}
@@ -243,7 +243,7 @@
 		day, month := when.Day(), int(when.Month())
 		if day != lastDay || month != lastMonth {
 			if err := write(); err != nil {
-				log.Printf("error: %v", err)
+				log.Errorf("%v", err)
 				// Too late for an HTTP error code.
 				return
 			}
@@ -253,13 +253,13 @@
 	}
 
 	if err := rows.Err(); err != nil {
-		log.Printf("error: %v", err)
+		log.Errorf("%v", err)
 		// Too late for an HTTP error code.
 		return
 	}
 
 	if err := write(); err != nil {
-		log.Printf("error: %v", err)
+		log.Errorf("%v", err)
 		// Too late for an HTTP error code.
 	}
 }
@@ -364,9 +364,9 @@
 		return
 	}
 
-	log.Printf("info: loading entries took %s\n", time.Since(start))
+	log.Infof("loading entries took %s\n", time.Since(start))
 
-	log.Printf("info: days found: %d\n", len(results))
+	log.Infof("days found: %d\n", len(results))
 
 	sort.Slice(results, func(i, j int) bool {
 		if d := results[i].month - results[j].month; d != 0 {
@@ -392,7 +392,7 @@
 	}
 
 	if err := out.Write(record); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		// Too late for an HTTP error code.
 		return
 	}
@@ -408,7 +408,7 @@
 	}
 
 	if err := out.Write(record); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		// Too late for an HTTP error code.
 		return
 	}
@@ -423,7 +423,7 @@
 		record[5] = float64format(r.q25)
 		record[6] = float64format(r.q75)
 		if err := out.Write(record); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			// Too late for an HTTP error code.
 			return
 		}
@@ -431,7 +431,7 @@
 
 	out.Flush()
 	if err := out.Error(); err != nil {
-		log.Printf("error: %v", err)
+		log.Errorf("%v", err)
 		// Too late for an HTTP error code.
 		return
 	}
@@ -557,10 +557,10 @@
 	}
 
 	// for i := range values {
-	// 	log.Printf("%v %f %d\n", values[i].when, values[i].observed, len(values[i].predicted))
+	// 	log.Debugf("%v %f %d\n", values[i].when, values[i].observed, len(values[i].predicted))
 	// 	if len(values[i].predicted) > 0 {
 	// 		for j := range values[i].predicted {
-	// 			log.Printf("\t%v %f\n", values[i].predicted[j].When, values[i].predicted[j].Value)
+	// 			log.Debugf("\t%v %f\n", values[i].predicted[j].When, values[i].predicted[j].Value)
 	// 		}
 	// 	}
 	// }
@@ -599,7 +599,7 @@
 		return
 	}
 
-	log.Printf("info: found %d value(s) for Nash Sutcliffe.\n", len(values))
+	log.Infof("found %d value(s) for Nash Sutcliffe.\n", len(values))
 
 	type coeff struct {
 		Value   float64 `json:"value"`
@@ -746,7 +746,7 @@
 	}
 
 	if err := out.Write(record); err != nil {
-		log.Printf("error: %v", err)
+		log.Errorf("%v", err)
 		// Too late for an HTTP error code.
 		return
 	}
@@ -766,7 +766,7 @@
 			&valueMax,
 			&predicted,
 		); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			// Too late for an HTTP error code.
 			return
 		}
@@ -777,21 +777,21 @@
 		record[4] = boolFormat(predicted)
 
 		if err := out.Write(record); err != nil {
-			log.Printf("error: %v", err)
+			log.Errorf("%v", err)
 			// Too late for an HTTP error code.
 			return
 		}
 	}
 
 	if err := rows.Err(); err != nil {
-		log.Printf("error: %v", err)
+		log.Errorf("%v", err)
 		// Too late for an HTTP error code.
 		return
 	}
 
 	out.Flush()
 	if err := out.Error(); err != nil {
-		log.Printf("error: %v", err)
+		log.Errorf("%v", err)
 		// Too late for an HTTP error code.
 		return
 	}
--- a/pkg/controllers/geostyling.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/geostyling.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,12 +17,12 @@
 	"bytes"
 	"fmt"
 	"io"
-	"log"
 	"net/http"
 
 	"github.com/gorilla/mux"
 
 	"gemma.intevation.de/gemma/pkg/geoserver"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 )
 
@@ -68,15 +68,15 @@
 
 	style, err := extractStyle(req)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusBadRequest)
 		return
 	}
 
-	log.Printf("info: uploaded file length: %d\n", len(style))
+	log.Infof("uploaded file length: %d\n", len(style))
 
 	if err := models.UpdateInternalStyle(req, feature, style); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
--- a/pkg/controllers/importqueue.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/importqueue.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,7 +19,6 @@
 	"encoding/csv"
 	"encoding/json"
 	"fmt"
-	"log"
 	"net/http"
 	"strconv"
 	"strings"
@@ -31,6 +30,7 @@
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/imports"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 
 	mw "gemma.intevation.de/gemma/pkg/middleware"
@@ -251,7 +251,7 @@
 	case err == sql.ErrNoRows:
 		return nil
 	case err != nil:
-		log.Printf("warn: %v\n", err)
+		log.Warnf("%v\n", err)
 		return nil
 	}
 	return &models.ImportTime{Time: when.UTC()}
@@ -283,7 +283,7 @@
 
 	if err := out.Write(record); err != nil {
 		// Too late for HTTP status message.
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 
@@ -291,7 +291,7 @@
 	ctx := req.Context()
 	var rows *sql.Rows
 	if rows, err = conn.QueryContext(ctx, list.stmt.String(), list.args...); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 	defer rows.Close()
@@ -341,10 +341,10 @@
 		if jc := imports.FindJobCreator(imports.JobKind(kind)); jc != nil {
 			job := jc.Create()
 			if err := common.FromJSONString(data, job); err != nil {
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 			} else if desc, ok := job.(Description); ok {
 				if description, err = desc.Description(); err != nil {
-					log.Printf("error: %v\n", err)
+					log.Errorf("%v\n", err)
 				}
 			}
 		}
@@ -361,18 +361,18 @@
 		record[9] = strings.Replace(description, ",", "|", -1)
 
 		if err := out.Write(record); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return
 		}
 	}
 
 	out.Flush()
 	if err := out.Error(); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 
 	if err = rows.Err(); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 }
--- a/pkg/controllers/manualimports.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/manualimports.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,7 +15,6 @@
 package controllers
 
 import (
-	"log"
 	"net/http"
 	"time"
 
@@ -24,6 +23,7 @@
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/imports"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 
 	mw "gemma.intevation.de/gemma/pkg/middleware"
@@ -33,7 +33,7 @@
 	kind := mux.Vars(req)["kind"]
 	ctor := imports.ImportModelForJobKind(imports.JobKind(kind))
 	if ctor == nil {
-		log.Printf("error: Unknown job kind '%s'.\n", kind)
+		log.Errorf("unknown job kind '%s'.\n", kind)
 		panic(http.ErrAbortHandler)
 	}
 	return ctor()
@@ -94,7 +94,7 @@
 		return
 	}
 
-	log.Printf("info: added import #%d to queue\n", jobID)
+	log.Infof("added import #%d to queue\n", jobID)
 
 	result := struct {
 		ID int64 `json:"id"`
--- a/pkg/controllers/proxy.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/proxy.go	Tue Sep 21 12:49:30 2021 +0200
@@ -22,7 +22,6 @@
 	"encoding/xml"
 	"io"
 	"io/ioutil"
-	"log"
 	"net/http"
 	"net/url"
 	"regexp"
@@ -32,6 +31,7 @@
 	"golang.org/x/net/html/charset"
 
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/middleware"
 )
 
@@ -53,10 +53,10 @@
 
 	return func(req *http.Request) {
 
-		//log.Printf("proxyDirector: %s\n", req.RequestURI)
+		//log.Debugf("proxyDirector: %s\n", req.RequestURI)
 
 		abort := func(format string, args ...interface{}) {
-			log.Printf(format, args...)
+			log.Errorf(format, args...)
 			panic(http.ErrAbortHandler)
 		}
 
@@ -66,7 +66,7 @@
 
 		if entry, found := vars["entry"]; found {
 			if s, found = lookup(entry); !found {
-				log.Printf("warn: cannot find entry '%s'\n", entry)
+				log.Warnf("cannot find entry '%s'\n", entry)
 				panic(middleware.ErrNotFound)
 			}
 		} else {
@@ -91,7 +91,7 @@
 		}
 
 		nURL := s + "?" + req.URL.RawQuery
-		//log.Printf("%v\n", nURL)
+		//log.Debugf("%v\n", nURL)
 
 		u, err := url.Parse(nURL)
 		if err != nil {
@@ -101,7 +101,7 @@
 
 		req.Host = u.Host
 		//req.Header.Del("If-None-Match")
-		//log.Printf("headers: %v\n", req.Header)
+		//log.Debugf("headers: %v\n", req.Header)
 	}
 }
 
@@ -117,7 +117,7 @@
 ) {
 	switch enc := h.Get("Content-Encoding"); {
 	case strings.Contains(enc, "gzip"):
-		//log.Println("info: gzip compression")
+		//log.Debugf("gzip compression")
 		return func(r io.Reader) (io.ReadCloser, error) {
 				return gzip.NewReader(r)
 			},
@@ -125,7 +125,7 @@
 				return gzip.NewWriter(w), nil
 			}
 	case strings.Contains(enc, "deflate"):
-		//log.Println("info: deflate compression")
+		//log.Debugf("deflate compression")
 		return func(r io.Reader) (io.ReadCloser, error) {
 				return flate.NewReader(r), nil
 			},
@@ -133,7 +133,7 @@
 				return flate.NewWriter(w, flate.DefaultCompression)
 			}
 	default:
-		//log.Println("info: no content compression")
+		//log.Debugf("no content compression")
 		return func(r io.Reader) (io.ReadCloser, error) {
 				if r2, ok := r.(io.ReadCloser); ok {
 					return r2, nil
@@ -184,10 +184,10 @@
 				w.Close()
 				pw.Close()
 				force.Close()
-				//log.Printf("info: rewrite took %s\n", time.Since(start))
+				//log.Debugf("rewrite took %s\n", time.Since(start))
 			}()
 			if err := rewrite(suffix, w, r); err != nil {
-				log.Printf("error: rewrite failed: %v\n", err)
+				log.Errorf("rewrite failed: %v\n", err)
 				return
 			}
 		}(resp.Body)
--- a/pkg/controllers/pwreset.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/pwreset.go	Tue Sep 21 12:49:30 2021 +0200
@@ -22,7 +22,6 @@
 	"encoding/hex"
 	"errors"
 	"io"
-	"log"
 	"net/http"
 	"os/exec"
 	"strconv"
@@ -40,6 +39,7 @@
 	"gemma.intevation.de/gemma/pkg/misc"
 	"gemma.intevation.de/gemma/pkg/models"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	mw "gemma.intevation.de/gemma/pkg/middleware"
 )
 
@@ -142,7 +142,7 @@
 				return err
 			})
 		if err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 		}
 	}
 }
@@ -159,7 +159,7 @@
 	}
 	var buf bytes.Buffer
 	if err := passwordResetRequestMailTmpl.Execute(&buf, &content); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 	return buf.String()
 }
@@ -245,7 +245,7 @@
 		config.WaitReady()
 		host := config.ExternalURL()
 		if err := backgroundRequest(host, user); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 		}
 	}(mw.JSONInput(req).(*models.PWResetUser))
 
@@ -312,7 +312,7 @@
 	}
 
 	if err := changedMessageBody(rw, user, password); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
 
@@ -326,6 +326,6 @@
 			return err
 		},
 	); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
--- a/pkg/controllers/report.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/report.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,7 +16,6 @@
 import (
 	"database/sql"
 	"fmt"
-	"log"
 	"net/http"
 	"os"
 	"path/filepath"
@@ -27,6 +26,7 @@
 	"gemma.intevation.de/gemma/pkg/middleware"
 	"gemma.intevation.de/gemma/pkg/xlsx"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	mw "gemma.intevation.de/gemma/pkg/middleware"
 
 	"github.com/gorilla/mux"
@@ -47,7 +47,7 @@
 
 	dir, err := os.Open(path)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		err = mw.JSONError{
 			Code:    http.StatusInternalServerError,
 			Message: "Listing report templates failed.",
@@ -57,7 +57,7 @@
 	defer dir.Close()
 	files, err := dir.Readdirnames(-1)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		err = mw.JSONError{
 			Code:    http.StatusInternalServerError,
 			Message: "Listing report templates failed.",
@@ -110,15 +110,15 @@
 
 	if stat, err := os.Stat(path); err != nil {
 		if os.IsNotExist(err) {
-			log.Printf("error: report dir '%s' does not exists.\n", path)
+			log.Errorf("report dir '%s' does not exists.\n", path)
 			http.NotFound(rw, req)
 		} else {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "Error: "+err.Error(), http.StatusInternalServerError)
 		}
 		return
 	} else if !stat.Mode().IsDir() {
-		log.Printf("error: report dir '%s' is not a directory.\n", path)
+		log.Errorf("report dir '%s' is not a directory.\n", path)
 		http.NotFound(rw, req)
 		return
 	}
@@ -134,7 +134,7 @@
 			if os.IsNotExist(err) {
 				http.NotFound(rw, req)
 			} else {
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 				http.Error(rw, "Error: "+err.Error(), http.StatusInternalServerError)
 			}
 			return
@@ -143,7 +143,7 @@
 
 	template, err := excelize.OpenFile(xlsxFilename)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "Error: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
@@ -151,7 +151,7 @@
 	action, err := xlsx.ActionFromFile(yamlFilename)
 	if err != nil {
 		http.Error(rw, "Error: "+err.Error(), http.StatusInternalServerError)
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 
@@ -162,7 +162,7 @@
 	defer tx.Rollback()
 
 	if err := action.Execute(ctx, tx, template); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "Error: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
@@ -174,6 +174,6 @@
 		"application/vnd.openxmlformats-officedocument.spreadsheetml.sheet")
 
 	if _, err := template.WriteTo(rw); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
--- a/pkg/controllers/shapestretches.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/shapestretches.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,7 +19,6 @@
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"net/http"
 	"os"
 	"path/filepath"
@@ -30,6 +29,7 @@
 	"github.com/jonas-p/go-shp"
 
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/middleware"
 	"gemma.intevation.de/gemma/pkg/wkb"
 )
@@ -305,7 +305,7 @@
 			_, err = io.Copy(out, srcFile)
 			return err
 		}(); err != nil {
-			log.Printf("error: cannot write file: %v\n", err)
+			log.Errorf("cannot write file: %v\n", err)
 			return
 		}
 	}
--- a/pkg/controllers/srimports.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/srimports.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,7 +17,6 @@
 	"archive/zip"
 	"encoding/hex"
 	"fmt"
-	"log"
 	"net/http"
 	"os"
 	"path/filepath"
@@ -32,6 +31,7 @@
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/config"
 	"gemma.intevation.de/gemma/pkg/imports"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/misc"
 	"gemma.intevation.de/gemma/pkg/models"
 
@@ -149,14 +149,14 @@
 	sr := new(imports.SoundingResult)
 
 	if err := fetchSoundingResultMetaOverrides(sr, req); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusBadRequest)
 		return
 	}
 
 	dir, err := fetchSoundingResult(req)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
@@ -164,7 +164,7 @@
 
 	serialized, err := common.ToJSONString(sr)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
@@ -183,12 +183,12 @@
 		serialized)
 
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
 
-	log.Printf("info: added import #%d to queue\n", jobID)
+	log.Infof("added import #%d to queue\n", jobID)
 
 	result := struct {
 		ID int64 `json:"id"`
@@ -283,11 +283,11 @@
 	if noXYZ {
 		code = http.StatusBadRequest
 		if err2 := os.RemoveAll(dir); err2 != nil {
-			log.Printf("error: %v\n", err2)
+			log.Errorf("%v\n", err2)
 		}
 	} else if result.Token, err = misc.MakeTempFile(dir); err != nil {
 		if err2 := os.RemoveAll(dir); err2 != nil {
-			log.Printf("error: %v\n", err2)
+			log.Errorf("%v\n", err2)
 		}
 		return
 	}
--- a/pkg/controllers/statsupdates.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/statsupdates.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,11 +15,12 @@
 
 import (
 	"database/sql"
-	"log"
 	"net/http"
 
+	"github.com/gorilla/mux"
+
+	"gemma.intevation.de/gemma/pkg/log"
 	mw "gemma.intevation.de/gemma/pkg/middleware"
-	"github.com/gorilla/mux"
 )
 
 const (
@@ -34,7 +35,7 @@
 
 	rows, err2 := conn.QueryContext(ctx, listStatsUpdatesSQL)
 	if err2 != nil {
-		log.Printf("error: %v\n", err2)
+		log.Errorf("%v\n", err2)
 		err = mw.JSONError{
 			Code:    http.StatusInternalServerError,
 			Message: "Listing stats update failed.",
@@ -48,7 +49,7 @@
 	for rows.Next() {
 		var name string
 		if err2 := rows.Scan(&name); err2 != nil {
-			log.Printf("error: %v\n", err2)
+			log.Errorf("%v\n", err2)
 			err = mw.JSONError{
 				Code:    http.StatusInternalServerError,
 				Message: "Fetching stats update names failed.",
@@ -59,7 +60,7 @@
 	}
 
 	if err2 := rows.Err(); err2 != nil {
-		log.Printf("error: %v\n", err2)
+		log.Errorf("%v\n", err2)
 		err = mw.JSONError{
 			Code:    http.StatusInternalServerError,
 			Message: "Fetching stats update names failed.",
@@ -92,7 +93,7 @@
 		}
 		return
 	case err2 != nil:
-		log.Printf("error: %v\n", err2)
+		log.Errorf("%v\n", err2)
 		err = mw.JSONError{
 			Code:    http.StatusInternalServerError,
 			Message: "Loading update script failed.",
@@ -101,7 +102,7 @@
 	}
 
 	if _, err2 := conn.ExecContext(ctx, script); err2 != nil {
-		log.Printf("error: %v\n", err2)
+		log.Errorf("%v\n", err2)
 		err = mw.JSONError{
 			Code:    http.StatusInternalServerError,
 			Message: "Loading update script failed.",
--- a/pkg/controllers/system.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/system.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,7 +19,6 @@
 	"database/sql"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"net/http"
 	"regexp"
 	"strings"
@@ -33,6 +32,7 @@
 	"gemma.intevation.de/gemma/pkg/config"
 	"gemma.intevation.de/gemma/pkg/geoserver"
 	"gemma.intevation.de/gemma/pkg/imports"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 
 	mw "gemma.intevation.de/gemma/pkg/middleware"
@@ -197,7 +197,7 @@
 	styles := strings.Split(which, ",")
 
 	doBoth := func(req *http.Request) {
-		log.Printf("info: Trigger re-calculation of %s.", which)
+		log.Infof("trigger re-calculation of %s.", which)
 		for _, style := range styles {
 			geoserver.ReconfigureStyle(style)
 		}
@@ -210,7 +210,7 @@
 
 	oldCVs, err := models.ParseColorValues(old.String)
 	if err != nil {
-		log.Printf("warn: old config value is broken: %v\n", err)
+		log.Warnf("old config value is broken: %v\n", err)
 		return doBoth, nil
 	}
 
@@ -231,7 +231,7 @@
 
 	// Only the color changed -> no expensive recalc needed.
 	if colorChanged {
-		log.Println("info: Only colors changed.")
+		log.Infof("only colors changed.")
 		return func(*http.Request) {
 			for _, style := range styles {
 				geoserver.ReconfigureStyle(style)
@@ -287,7 +287,7 @@
 	job := &imports.IsoRefresh{ClassBreaks: breaks}
 	serialized, err := common.ToJSONString(job)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 	var jobID int64
@@ -300,11 +300,11 @@
 		false,
 		serialized,
 	); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
-	log.Printf(
-		"info: Recalculate sounding results contours in job %d.\n",
+	log.Infof(
+		"recalculate sounding results contours in job %d.\n",
 		jobID)
 
 }
@@ -319,7 +319,7 @@
 			return err
 		},
 	); err != nil {
-		log.Printf("error: Cleaning sounding diffs cache failed: %v\n", err)
+		log.Errorf("cleaning sounding diffs cache failed: %v\n", err)
 	}
 }
 
--- a/pkg/controllers/token.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/token.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,12 +16,12 @@
 import (
 	"encoding/json"
 	"fmt"
-	"log"
 	"net/http"
 
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/models"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	mw "gemma.intevation.de/gemma/pkg/middleware"
 )
 
@@ -33,7 +33,7 @@
 		http.NotFound(rw, req)
 		return
 	case err != nil:
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, fmt.Sprintf("error: %v", err), http.StatusInternalServerError)
 		return
 	}
@@ -73,7 +73,7 @@
 	}
 	defer req.Body.Close()
 	if err := json.NewDecoder(req.Body).Decode(&input); err != nil {
-		log.Printf("%v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, "error: "+err.Error(), http.StatusBadRequest)
 		return
 	}
@@ -87,7 +87,7 @@
 		string(input.User),
 		input.Password)
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		http.Error(rw, http.StatusText(http.StatusUnauthorized), http.StatusUnauthorized)
 		return
 	}
--- a/pkg/controllers/uploadedimports.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/uploadedimports.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,7 +15,6 @@
 
 import (
 	"fmt"
-	"log"
 	"net/http"
 	"os"
 	"strconv"
@@ -24,6 +23,7 @@
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/imports"
+	"gemma.intevation.de/gemma/pkg/log"
 	mw "gemma.intevation.de/gemma/pkg/middleware"
 	"gemma.intevation.de/gemma/pkg/misc"
 )
@@ -162,7 +162,7 @@
 			fname,
 			maxUploadSize)
 		if err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 			return
 		}
@@ -170,20 +170,20 @@
 		job, err := create(req, dir)
 		if err != nil {
 			if err2 := os.RemoveAll(dir); err2 != nil {
-				log.Printf("warn: %v\n", err2)
+				log.Warnf("%v\n", err2)
 			}
 			if err2, ok := err.(badUploadParameterError); ok {
 				http.Error(rw, string(err2), http.StatusBadRequest)
 				return
 			}
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 			return
 		}
 
 		serialized, err := common.ToJSONString(job)
 		if err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 			return
 		}
@@ -202,12 +202,12 @@
 			serialized)
 
 		if err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, "error: "+err.Error(), http.StatusInternalServerError)
 			return
 		}
 
-		log.Printf("info: added import #%d to queue\n", jobID)
+		log.Infof("added import #%d to queue\n", jobID)
 
 		result := struct {
 			ID int64 `json:"id"`
--- a/pkg/controllers/user.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/controllers/user.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,7 +19,6 @@
 	"bytes"
 	"database/sql"
 	"fmt"
-	"log"
 	"net/http"
 	"strconv"
 	"strings"
@@ -29,6 +28,7 @@
 	"github.com/gorilla/mux"
 
 	"gemma.intevation.de/gemma/pkg/auth"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/misc"
 	"gemma.intevation.de/gemma/pkg/models"
 	"gemma.intevation.de/gemma/pkg/pgxutils"
@@ -141,7 +141,7 @@
 			go func() { scheduler.UnbindByIDs(ids) }()
 		}
 	} else {
-		log.Printf("error: %v\n", err2)
+		log.Errorf("%v\n", err2)
 	}
 
 	var res sql.Result
@@ -571,7 +571,7 @@
 
 	var buf bytes.Buffer
 	if err := bodyTmpl.Execute(&buf, &tmplVars); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 
 	err = misc.SendMail(string(userData.Email), subject, buf.String())
--- a/pkg/geoserver/boot.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/geoserver/boot.go	Tue Sep 21 12:49:30 2021 +0200
@@ -20,7 +20,6 @@
 	"encoding/xml"
 	"fmt"
 	"io"
-	"log"
 	"net/http"
 	"net/url"
 	"strings"
@@ -29,6 +28,7 @@
 	"golang.org/x/net/html/charset"
 
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 )
 
@@ -55,7 +55,7 @@
 
 	if err := json.NewEncoder(&buf).Encode(x); err != nil {
 		// Should not happen
-		log.Printf("warn: bad JSON: %v\n", err)
+		log.Warnf("bad JSON: %v\n", err)
 	}
 	return bytes.NewReader(buf.Bytes())
 }
@@ -66,7 +66,7 @@
 	buf := bytes.NewBufferString(xml.Header)
 	if err := xml.NewEncoder(buf).Encode(x); err != nil {
 		// Should not happen
-		log.Printf("warn: bad XML: %v\n", err)
+		log.Warnf("bad XML: %v\n", err)
 	}
 	return bytes.NewReader(buf.Bytes())
 }
@@ -102,13 +102,13 @@
 	}
 
 	if resp.StatusCode != http.StatusNotFound {
-		log.Println("info: workspace " + workspaceName + " already exists.")
+		log.Infof("workspace " + workspaceName + " already exists.")
 		return nil
 	}
 
 	// Create workspace
 
-	log.Println("info: creating workspace " + workspaceName)
+	log.Infof("creating workspace " + workspaceName)
 
 	const createJSON = `{"workspace":{"name":"` + workspaceName + `"}}`
 
@@ -158,12 +158,12 @@
 	}
 
 	if resp.StatusCode != http.StatusNotFound {
-		log.Println("info: datastore " + datastoreName + " already exists.")
+		log.Infof("datastore " + datastoreName + " already exists.")
 		return nil
 	}
 
 	// Create datastore.
-	log.Println("info: creating datastore " + datastoreName)
+	log.Infoln("creating datastore " + datastoreName)
 
 	type entry struct {
 		Key   interface{} `json:"@key"`
@@ -221,11 +221,11 @@
 func ensureFeatures() error {
 	tables := models.InternalServices.Filter(models.IntWFS)
 	if len(tables) == 0 {
-		log.Println("info: no tables to publish")
+		log.Infoln("no tables to publish")
 		return nil
 	}
 
-	log.Printf("info: number of tables to publish %d\n", len(tables))
+	log.Infof("number of tables to publish %d\n", len(tables))
 
 	var (
 		geoURL   = config.GeoServerURL()
@@ -283,7 +283,7 @@
 
 	defer func() {
 		if len(already) > 0 {
-			log.Printf("info: already having featuretypes: %s\n",
+			log.Infof("already having featuretypes: %s\n",
 				strings.Join(already, ", "))
 		}
 	}()
@@ -297,7 +297,7 @@
 		}
 
 		// Create featuretype.
-		log.Printf("info: creating featuretype %s.\n", table)
+		log.Infof("creating featuretype %s.\n", table)
 
 		var req *http.Request
 
@@ -400,11 +400,11 @@
 
 	groups := models.InternalServices.LayerGroups()
 	if len(groups) == 0 {
-		log.Println("info: no groups layers to publish")
+		log.Infoln("info: no groups layers to publish")
 		return nil
 	}
 
-	log.Printf("info: number of layer groups to publish %d\n", len(groups))
+	log.Infof("number of layer groups to publish %d\n", len(groups))
 
 	var (
 		geoURL   = config.GeoServerURL()
@@ -457,7 +457,7 @@
 
 	defer func() {
 		if len(already) > 0 {
-			log.Printf("info: already having layer groups: %s\n",
+			log.Infof("already having layer groups: %s\n",
 				strings.Join(already, ", "))
 		}
 	}()
@@ -468,7 +468,7 @@
 			continue
 		}
 
-		log.Printf("info: creating layer group %s.\n", groups[i].Name)
+		log.Infof("creating layer group %s.\n", groups[i].Name)
 
 		type (
 			Layers struct {
@@ -529,7 +529,7 @@
 		return nil
 	}
 
-	log.Println("info: delete workspace " + workspaceName)
+	log.Infoln("info: delete workspace " + workspaceName)
 	var (
 		geoURL   = config.GeoServerURL()
 		user     = config.GeoServerUser()
@@ -626,7 +626,7 @@
 
 func updateStyle(entry *models.IntEntry, create bool) error {
 
-	log.Printf("info: creating style %s\n", entry.Name)
+	log.Infof("creating style %s\n", entry.Name)
 
 	// Try to load the style data.
 	binary, err := entry.LoadStyle()
@@ -761,7 +761,7 @@
 		case tok == nil && err == io.EOF:
 			return false
 		case err != nil:
-			log.Printf("warn: invalid XML: %v\n", err)
+			log.Warnf("invalid XML: %v\n", err)
 			return false
 		}
 		if t, ok := tok.(xml.StartElement); ok &&
@@ -772,7 +772,7 @@
 }
 
 func ensureStyles() error {
-	log.Println("info: creating styles")
+	log.Infoln("creating styles")
 
 	var stls styles
 	if err := stls.load(); err != nil {
@@ -788,7 +788,7 @@
 
 	defer func() {
 		if len(already) > 0 {
-			log.Printf("info: already having styles: %s\n",
+			log.Infof("already having styles: %s\n",
 				strings.Join(already, ", "))
 		}
 	}()
@@ -812,12 +812,12 @@
 func PrepareGeoServer() error {
 
 	if config.DBUser() == "" {
-		log.Println("info: Need metamorphic db user to configure GeoServer")
+		log.Infoln("need metamorphic db user to configure GeoServer")
 		return nil
 	}
 
 	if config.GeoServerURL() == "" {
-		log.Println("info: No URL to GeoServer configured")
+		log.Infoln("no URL to GeoServer configured")
 		return nil
 	}
 
--- a/pkg/geoserver/reconf.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/geoserver/reconf.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,12 +15,12 @@
 
 import (
 	"container/list"
-	"log"
 	"net"
 	"net/url"
 	"sync"
 	"time"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 )
 
@@ -43,13 +43,13 @@
 		fn = confQueue.Remove(confQueue.Front()).(func() error)
 		confQueueCond.L.Unlock()
 		if err := reconfigure(fn); err != nil {
-			log.Printf("warn: configure GeoServer failed: %v\n", err)
+			log.Warnf("configure GeoServer failed: %v\n", err)
 		}
 	}
 }
 
 func reconfigure(fn func() error) error {
-	log.Println("info: configure GeoServer...")
+	log.Infof("configure GeoServer...")
 	const (
 		maxTries = 10
 		sleep    = time.Second * 5
@@ -62,7 +62,7 @@
 		if try < maxTries {
 			if uerr, ok := err.(*url.Error); ok {
 				if oerr, ok := uerr.Err.(*net.OpError); ok && oerr.Op == "dial" {
-					log.Printf("warn: failed attempt %d of %d to configure GeoServer. "+
+					log.Warnf("failed attempt %d of %d to configure GeoServer. "+
 						"Will try again in %s...\n", try, maxTries, sleep)
 					time.Sleep(sleep)
 					continue
--- a/pkg/imports/dsec.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/dsec.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,7 +18,8 @@
 	"database/sql"
 	"errors"
 	"fmt"
-	"log"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // DeleteSection is a Job to delete a section from the database.
@@ -71,8 +72,8 @@
 	}
 	n, err := res.RowsAffected()
 	if err != nil {
-		log.Println(
-			"error: RowsAffected returned an error. Missing driver support?")
+		log.Errorf(
+			"RowsAffected returned an error. Missing driver support?")
 		return nil
 	}
 	if n == 0 {
--- a/pkg/imports/email.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/email.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,12 +16,12 @@
 import (
 	"context"
 	"database/sql"
-	"log"
 	"strings"
 	"text/template"
 
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/misc"
 )
 
@@ -62,7 +62,7 @@
 			return conn.QueryRowContext(ctx, selectEmailSQL, user).Scan(&email)
 		},
 	); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 
@@ -82,11 +82,11 @@
 
 	var body strings.Builder
 	if err := importNotificationMailTmpl.Execute(&body, &data); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return
 	}
 
 	if err := misc.SendMail(email, importNotificationMailSubject, body.String()); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
--- a/pkg/imports/erdms.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/erdms.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,9 +18,9 @@
 	"context"
 	"database/sql"
 	"fmt"
-	"log"
 	"strings"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/soap"
 	"gemma.intevation.de/gemma/pkg/soap/erdms"
 )
@@ -102,7 +102,7 @@
 		data, err := client.GetRisDataXML(request)
 		if err != nil {
 			if t, ok := err.(interface{ Timeout() bool }); ok && t.Timeout() && tries < maxTries {
-				log.Println("warn: ERDMS SOAP request timed out. Trying again.")
+				log.Warnln("warn: ERDMS SOAP request timed out. Trying again.")
 				tries++
 				goto again
 			}
--- a/pkg/imports/gm.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/gm.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,15 +19,16 @@
 	"context"
 	"database/sql"
 	"fmt"
-	"log"
 	"sort"
 	"strings"
 	"time"
 
+	"github.com/jackc/pgx/pgtype"
+
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 	"gemma.intevation.de/gemma/pkg/pgxutils"
 	"gemma.intevation.de/gemma/pkg/soap/nts"
-	"github.com/jackc/pgx/pgtype"
 )
 
 // GaugeMeasurement is an import job to import
@@ -185,7 +186,7 @@
 
 		if err != nil {
 			if t, ok := err.(interface{ Timeout() bool }); ok && t.Timeout() && tries < maxTries {
-				log.Println("warn: NtS SOAP request timed out. Trying again.")
+				log.Warnln("NtS SOAP request timed out. Trying again.")
 				tries++
 				goto again
 			}
--- a/pkg/imports/isr.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/isr.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,9 +16,9 @@
 import (
 	"context"
 	"database/sql"
-	"log"
 	"time"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/mesh"
 	"gemma.intevation.de/gemma/pkg/models"
 )
@@ -341,7 +341,7 @@
 				}
 			}
 		default:
-			log.Printf("error: unknown survey type '%s'\n", sr.surveyType)
+			log.Errorf("unknown survey type '%s'\n", sr.surveyType)
 		}
 	}
 	feedback.Info("Scan types: Single/Multi: %d Marking: %d", beams, markings)
--- a/pkg/imports/queue.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/queue.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,7 +19,6 @@
 	"encoding/json"
 	"errors"
 	"fmt"
-	"log"
 	"runtime/debug"
 	"sort"
 	"strings"
@@ -31,6 +30,7 @@
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/pgxutils"
 )
 
@@ -381,7 +381,7 @@
 func LogImportKindNames() {
 	kinds := ImportKindNames()
 	sort.Strings(kinds)
-	log.Printf("info: registered import kinds: %s",
+	log.Infof("registered import kinds: %s",
 		strings.Join(kinds, ", "))
 }
 
@@ -440,7 +440,7 @@
 	if idj.waitRetry.Status == pgtype.Present {
 		var d time.Duration
 		if err := idj.waitRetry.AssignTo(&d); err != nil {
-			log.Printf("error: converting waitRetry failed: %v\n", err)
+			log.Errorf("converting waitRetry failed: %v\n", err)
 		} else {
 			now = now.Add(d)
 		}
@@ -462,7 +462,7 @@
 	}
 	d := new(time.Duration)
 	if err := idj.waitRetry.AssignTo(d); err != nil {
-		log.Printf("error: converting waitRetry failed: %v\n", err)
+		log.Errorf("converting waitRetry failed: %v\n", err)
 		return nil
 	}
 	return d
@@ -560,7 +560,7 @@
 				data).Scan(&id)
 
 			if err == nil && sync {
-				log.Printf("info: register wait for %d\n", id)
+				log.Infof("register wait for %d\n", id)
 				done = make(chan struct{})
 				q.waiting[id] = done
 			}
@@ -675,7 +675,7 @@
 	if err != nil {
 		return nil, err
 	}
-	log.Printf("info: add review job %d\n", rID)
+	log.Infof("add review job %d\n", rID)
 	_, err = tx.ExecContext(ctx, updateStateSQL, "reviewed", id)
 	if err != nil && done != nil {
 		go func() {
@@ -741,7 +741,7 @@
 		return err
 	})
 	if err != nil {
-		log.Printf("error: logging failed: %v\n", err)
+		log.Errorf("logging failed: %v\n", err)
 	}
 }
 
@@ -868,7 +868,7 @@
 		if err = auth.RunAs(ctx, queueUser, fn); err == nil || try == maxTries {
 			return err
 		}
-		log.Printf("warn: [try %d/%d] Storing state failed: %v (try again in %s).\n",
+		log.Warnf("[try %d/%d] Storing state failed: %v (try again in %s).\n",
 			try, maxTries, err, sleep)
 
 		time.Sleep(sleep)
@@ -935,7 +935,7 @@
 	// re-enqueue the jobs that are in state running.
 	// They where in progess when the server went down.
 	if err := reEnqueueRunning(); err != nil {
-		log.Printf("error: re-enqueuing failed: %v", err)
+		log.Errorf("re-enqueuing failed: %v", err)
 	}
 
 	for {
@@ -944,7 +944,7 @@
 
 		for {
 			if idj, err = q.fetchJob(); err != nil && err != sql.ErrNoRows {
-				log.Printf("error: db: %v\n", err)
+				log.Errorf("error: db: %v\n", err)
 			}
 			if idj != nil {
 				break
@@ -957,7 +957,7 @@
 			}
 		}
 
-		log.Printf("info: starting import #%d\n", idj.id)
+		log.Infof("starting import #%d\n", idj.id)
 
 		jc := q.jobCreator(idj.kind)
 		if jc == nil {
@@ -978,7 +978,7 @@
 				// Unlock waiting.
 				q.cmdCh <- func(q *importQueue) {
 					if w := q.waiting[idj.id]; w != nil {
-						log.Printf("info: unlock waiting %d\n", idj.id)
+						log.Infof("unlock waiting %d\n", idj.id)
 						if retry {
 							w <- struct{}{}
 						} else {
@@ -1050,9 +1050,9 @@
 			}
 			if !remove {
 				if err := updateStateSummary(ctx, idj.id, state, summary); err != nil {
-					log.Printf("error: setting state of job %d failed: %v\n", idj.id, err)
+					log.Errorf("setting state of job %d failed: %v\n", idj.id, err)
 				}
-				log.Printf("info: import #%d finished: %s\n", idj.id, state)
+				log.Infof("info: import #%d finished: %s\n", idj.id, state)
 			}
 			if idj.sendEmail {
 				go sendNotificationMail(idj.user, jc.Description(), state, idj.id)
@@ -1068,14 +1068,14 @@
 					idj.data,
 					false)
 				if err != nil {
-					log.Printf("error: retry enqueue failed: %v\n", err)
+					log.Errorf("retry enqueue failed: %v\n", err)
 				} else {
-					log.Printf("info: re-enqueued job with id %d\n", nid)
+					log.Infof("re-enqueued job with id %d\n", nid)
 				}
 			}
 			if remove {
 				if err := deleteJob(ctx, idj.id); err != nil {
-					log.Printf("error: deleting job %d failed: %v\n", idj.id, err)
+					log.Errorf("deleting job %d failed: %v\n", idj.id, err)
 				}
 			}
 		}(jc, idj)
--- a/pkg/imports/report.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/report.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,7 +19,6 @@
 	"database/sql"
 	"errors"
 	"fmt"
-	"log"
 	"os"
 	"path/filepath"
 	"strings"
@@ -29,6 +28,7 @@
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/misc"
 	"gemma.intevation.de/gemma/pkg/models"
 	"gemma.intevation.de/gemma/pkg/xlsx"
@@ -207,19 +207,19 @@
 	var admin misc.EmailReceiver
 	if err := tx.QueryRowContext(
 		ctx, selectCurrentUserSQL).Scan(&admin.Name, &admin.Address); err != nil {
-		log.Printf("error: Cannot find sender: %v\n")
+		log.Errorf("cannot find sender: %v\n")
 		return nil, fmt.Errorf("cannot find sender: %v", err)
 	}
 
 	// Generate the actual report.
 	if err := action.Execute(ctx, tx, template); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return nil, fmt.Errorf("Generating report failed: %v", err)
 	}
 
 	var buf bytes.Buffer
 	if _, err := template.WriteTo(&buf); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		return nil, fmt.Errorf("generating report failed: %v", err)
 	}
 
--- a/pkg/imports/scheduled.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/imports/scheduled.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,10 +17,10 @@
 	"context"
 	"database/sql"
 	"fmt"
-	"log"
 	"time"
 
 	"gemma.intevation.de/gemma/pkg/common"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 	"gemma.intevation.de/gemma/pkg/scheduler"
 )
@@ -29,10 +29,10 @@
 	run := func(cfgID int64) {
 		jobID, err := RunConfiguredImport(cfgID)
 		if err != nil {
-			log.Printf("error: running scheduled import failed: %v\n", err)
+			log.Errorf("running scheduled import failed: %v\n", err)
 			return
 		}
-		log.Printf("info: added import #%d to queue\n", jobID)
+		log.Infof("added import #%d to queue\n", jobID)
 	}
 
 	for kind := range kindToImportModel {
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/pkg/log/log.go	Tue Sep 21 12:49:30 2021 +0200
@@ -0,0 +1,208 @@
+// This is Free Software under GNU Affero General Public License v >= 3.0
+// without warranty, see README.md and license for details.
+//
+// SPDX-License-Identifier: AGPL-3.0-or-later
+// License-Filename: LICENSES/AGPL-3.0.txt
+//
+// Copyright (C) 2021 by via donau
+//   – Österreichische Wasserstraßen-Gesellschaft mbH
+// Software engineering by Intevation GmbH
+//
+// Author(s):
+//  * Sascha L. Teichmann <sascha.teichmann@intevation.de>
+
+package log
+
+import (
+	"fmt"
+	lg "log"
+	"os"
+	"strings"
+	"sync"
+	"sync/atomic"
+)
+
+type LogLevel uint32
+
+const (
+	TraceLogLevel = LogLevel(iota)
+	DebugLogLevel
+	InfoLogLevel
+	WarnLogLevel
+	ErrorLogLevel
+	FatalLogLevel
+)
+
+var (
+	logLevel  = uint32(InfoLogLevel)
+	logFileMu sync.Mutex
+	logFile   *os.File
+)
+
+func init() {
+	lg.SetFlags(lg.LstdFlags | lg.Lshortfile)
+}
+
+const callDepth = 2
+
+func SetupLog(filename string, perm os.FileMode) error {
+	f, err := os.OpenFile(filename, os.O_APPEND|os.O_CREATE|os.O_WRONLY, perm)
+	if err != nil {
+		return err
+	}
+	logFileMu.Lock()
+	defer logFileMu.Unlock()
+	if logFile != nil {
+		logFile.Close()
+	}
+	logFile = f
+	lg.SetOutput(logFile)
+	return nil
+}
+
+func ShutdownLog() {
+	logFileMu.Lock()
+	defer logFileMu.Unlock()
+	if logFile != nil {
+		logFile.Close()
+		logFile = nil
+	}
+	lg.SetOutput(os.Stderr)
+}
+
+func ParseLogLevel(s string) LogLevel {
+	switch strings.ToLower(s) {
+	case "trace":
+		return TraceLogLevel
+	case "debug":
+		return DebugLogLevel
+	case "info":
+		return InfoLogLevel
+	case "warn":
+		return WarnLogLevel
+	case "error":
+		return ErrorLogLevel
+	case "fatal":
+		return FatalLogLevel
+	default:
+		return InfoLogLevel
+	}
+}
+
+func (level LogLevel) String() string {
+	switch level {
+	case TraceLogLevel:
+		return "trace"
+	case DebugLogLevel:
+		return "debug"
+	case InfoLogLevel:
+		return "info"
+	case WarnLogLevel:
+		return "warn"
+	case ErrorLogLevel:
+		return "error"
+	case FatalLogLevel:
+		return "fatal"
+	default:
+		return "unknown"
+	}
+}
+
+func GetLogLevel() LogLevel {
+	return LogLevel(atomic.LoadUint32(&logLevel))
+}
+
+func SetLogLevel(level LogLevel) {
+	atomic.StoreUint32(&logLevel, uint32(level))
+}
+
+func Tracef(f string, args ...interface{}) {
+	if TraceLogLevel >= GetLogLevel() {
+		s := fmt.Sprintf(f, args...)
+		lg.Output(callDepth, "[TRACE] "+s)
+	}
+}
+
+func Traceln(s string) {
+	if TraceLogLevel >= GetLogLevel() {
+		lg.Output(callDepth, "[TRACE] "+s)
+	}
+}
+
+func Debugf(f string, args ...interface{}) {
+	if DebugLogLevel >= GetLogLevel() {
+		s := fmt.Sprintf(f, args...)
+		lg.Output(callDepth, "[DEBUG] "+s)
+	}
+}
+
+func Debugln(s string) {
+	if DebugLogLevel >= GetLogLevel() {
+		lg.Output(callDepth, "[DEBUG] "+s)
+	}
+}
+
+func Infof(f string, args ...interface{}) {
+	if InfoLogLevel >= GetLogLevel() {
+		s := fmt.Sprintf(f, args...)
+		lg.Output(callDepth, "[INFO] "+s)
+	}
+}
+
+func Infoln(s string) {
+	if InfoLogLevel >= GetLogLevel() {
+		lg.Output(callDepth, "[INFO] "+s)
+	}
+}
+
+func Warnf(f string, args ...interface{}) {
+	if WarnLogLevel >= GetLogLevel() {
+		s := fmt.Sprintf(f, args...)
+		lg.Output(callDepth, "[WARN] "+s)
+	}
+}
+
+func Warnln(s string) {
+	if WarnLogLevel >= GetLogLevel() {
+		lg.Output(callDepth, "[WARN] "+s)
+	}
+}
+
+func Errorf(f string, args ...interface{}) {
+	if ErrorLogLevel >= GetLogLevel() {
+		s := fmt.Sprintf(f, args...)
+		lg.Output(callDepth, "[ERROR] "+s)
+	}
+}
+
+func Errorln(s string) {
+	if ErrorLogLevel >= GetLogLevel() {
+		lg.Output(callDepth, "[ERROR] "+s)
+	}
+}
+
+func Fatalf(f string, args ...interface{}) {
+	if FatalLogLevel >= GetLogLevel() {
+		s := fmt.Sprintf(f, args...)
+		lg.Output(callDepth, "[FATAL] "+s)
+		os.Exit(1)
+	}
+}
+
+func Fatalln(s string) {
+	if FatalLogLevel >= GetLogLevel() {
+		lg.Output(callDepth, "[FATAL] "+s)
+		os.Exit(1)
+	}
+}
+
+func Panicf(f string, args ...interface{}) {
+	s := fmt.Sprintf(f, args...)
+	lg.Output(callDepth, "[PANIC] "+s)
+	panic(s)
+}
+
+func Panicln(s string) {
+	lg.Output(callDepth, "[PANIC] "+s)
+	panic(s)
+}
--- a/pkg/mesh/loader.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/loader.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,7 +18,8 @@
 	"bytes"
 	"compress/gzip"
 	"encoding/binary"
-	"log"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 func (s *STRTree) deserializeIndex(r *bufio.Reader) error {
@@ -104,7 +105,7 @@
 		return err
 	}
 
-	log.Printf("info: EPSG: %d\n", t.EPSG)
+	log.Infof("EPSG: %d\n", t.EPSG)
 
 	if err := t.Min.Read(r); err != nil {
 		return err
@@ -114,7 +115,7 @@
 		return err
 	}
 
-	log.Printf("info: BBOX: [[%f, %f, %f], [%f, %f, %f]]\n",
+	log.Infof("BBOX: [[%f, %f, %f], [%f, %f, %f]]\n",
 		t.Min.X, t.Min.Y, t.Min.Z,
 		t.Max.X, t.Max.Y, t.Max.Z)
 
@@ -123,7 +124,7 @@
 		return err
 	}
 
-	log.Printf("info: vertices: %d\n", numVertices)
+	log.Infof("vertices: %d\n", numVertices)
 
 	vertices := make([]Vertex, numVertices)
 	t.Vertices = vertices
@@ -139,7 +140,7 @@
 		return err
 	}
 
-	log.Printf("info: triangles: %d\n", numTriangles)
+	log.Infof("triangles: %d\n", numTriangles)
 
 	indices := make([]int32, 3*numTriangles)
 	triangles := make([][]int32, numTriangles)
--- a/pkg/mesh/polygon.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/polygon.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,11 +17,11 @@
 	"bytes"
 	"encoding/binary"
 	"fmt"
-	"log"
 	"math"
 
 	"github.com/tidwall/rtree"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/wkb"
 )
 
@@ -464,7 +464,7 @@
 
 	rngs := make([]ring, numRings)
 
-	log.Printf("info: Number of rings: %d\n", len(rngs))
+	log.Infof("number of rings: %d\n", len(rngs))
 
 	for rng := uint32(0); rng < numRings; rng++ {
 		var numVertices uint32
@@ -472,7 +472,7 @@
 			return err
 		}
 
-		log.Printf("info: Number of vertices in ring %d: %d\n", rng, numVertices)
+		log.Infof("number of vertices in ring %d: %d\n", rng, numVertices)
 
 		numVertices *= 2
 		vertices := make([]float64, numVertices)
--- a/pkg/mesh/raster.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/raster.go	Tue Sep 21 12:49:30 2021 +0200
@@ -14,7 +14,6 @@
 package mesh
 
 import (
-	"log"
 	"math"
 	"runtime"
 	"sync"
@@ -23,6 +22,7 @@
 	"github.com/fogleman/contourmap"
 
 	"gemma.intevation.de/gemma/pkg/common"
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/wkb"
 )
 
@@ -40,12 +40,12 @@
 
 	width, height := bbox.Size()
 
-	log.Printf("info raster extent: %.2f / %.2f", width, height)
+	log.Infof("raster extent: %.2f / %.2f", width, height)
 
 	xCells := int(math.Ceil(width / cellSize))
 	yCells := int(math.Ceil(height / cellSize))
 
-	log.Printf("info raster size: %d / %d\n", xCells, yCells)
+	log.Infof("raster size: %d / %d\n", xCells, yCells)
 
 	size := (xCells + 2) * (yCells + 2)
 	cells := make([]float64, size)
@@ -231,7 +231,7 @@
 	close(cnts)
 
 	wg.Wait()
-	log.Printf("info: Tracing areas took %v\n", time.Since(start))
+	log.Infof("Tracing areas took %v\n", time.Since(start))
 
 	return areas
 }
@@ -362,7 +362,7 @@
 		forest.insertRoot(contour(cnt))
 	}
 
-	//log.Printf("cnts: %d roots: %d\n", len(cnts), len(bf.roots))
+	//log.Debugf("cnts: %d roots: %d\n", len(cnts), len(bf.roots))
 
 	var mp wkb.MultiPolygonGeom
 
--- a/pkg/mesh/strtree.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/strtree.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,9 +18,10 @@
 	"compress/gzip"
 	"encoding/binary"
 	"io"
-	"log"
 	"math"
 	"sort"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // STRTreeDefaultEntries is the default number of children per node and leaf.
@@ -275,7 +276,7 @@
 		last = x
 	}
 
-	log.Printf("info: compressed index in bytes: %d %.2f (%d %.2f)\n",
+	log.Infof("compressed index in bytes: %d %.2f (%d %.2f)\n",
 		written,
 		float64(written)/(1024*1024),
 		4*len(s.index),
--- a/pkg/mesh/tin.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/tin.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,9 +19,9 @@
 	"errors"
 	"fmt"
 	"io"
-	"log"
 	"math"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/models"
 	"gemma.intevation.de/gemma/pkg/wkb"
 )
@@ -56,7 +56,7 @@
 // Shared vertices are identified and referenced by the
 // same index.
 func (t *Tin) FromWKB(data []byte) error {
-	log.Printf("info: data length %d\n", len(data))
+	log.Infof("data length %d\n", len(data))
 
 	r := bytes.NewReader(data)
 
@@ -180,7 +180,7 @@
 		triangles = append(triangles, triangle)
 	}
 
-	log.Printf("info: bbox: [[%f, %f], [%f, %f]]\n",
+	log.Infof("bbox: [[%f, %f], [%f, %f]]\n",
 		min.X, min.Y, max.X, max.Y)
 
 	*t = Tin{
@@ -240,7 +240,7 @@
 	if err != nil {
 		return err
 	}
-	log.Printf("info: vertices %d (%d)\n", len(t.Vertices), len(t.Vertices)*3*8)
+	log.Infof("vertices %d (%d)\n", len(t.Vertices), len(t.Vertices)*3*8)
 
 	if err := binary.Write(
 		w, binary.LittleEndian, uint32(len(t.Triangles))); err != nil {
@@ -264,7 +264,7 @@
 			last = idx
 		}
 	}
-	log.Printf("info: compressed tin indices in bytes: %d (%d)\n",
+	log.Infof("compressed tin indices in bytes: %d (%d)\n",
 		written, 3*4*len(t.Triangles))
 
 	return nil
--- a/pkg/mesh/triangulation.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/triangulation.go	Tue Sep 21 12:49:30 2021 +0200
@@ -20,9 +20,9 @@
 package mesh
 
 import (
-	"log"
 	"math"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gonum.org/v1/gonum/stat"
 )
 
@@ -115,7 +115,7 @@
 
 	var newCandidates []int32
 
-	log.Printf("info: candidates: %d\n", len(candidates))
+	log.Infof("candidates: %d\n", len(candidates))
 	for len(candidates) > 0 {
 
 		oldRemoved := len(removed)
@@ -137,9 +137,9 @@
 		newCandidates = newCandidates[:0]
 	}
 
-	log.Printf("info: candidates left: %d\n", len(candidates))
-	log.Printf("info: triangles: %d\n", len(t.Triangles)/3)
-	log.Printf("info: triangles to remove: %d\n", len(removed))
+	log.Infof("candidates left: %d\n", len(candidates))
+	log.Infof("triangles: %d\n", len(t.Triangles)/3)
+	log.Infof("info: triangles to remove: %d\n", len(removed))
 
 	type edge struct {
 		a, b       int32
@@ -213,11 +213,11 @@
 	}
 
 	if len(open) > 0 {
-		log.Printf("warn: open vertices left: %d\n", len(open))
+		log.Warnf("open vertices left: %d\n", len(open))
 	}
 
 	if len(rings) == 0 {
-		log.Println("warn: no ring found")
+		log.Warnln("no ring found")
 		return nil, removed
 	}
 
@@ -234,7 +234,7 @@
 
 	polygon = append(polygon, t.Points[rings[0].a])
 
-	log.Printf("length of boundary: %d\n", len(polygon))
+	log.Infof("length of boundary: %d\n", len(polygon))
 
 	return polygon, removed
 }
--- a/pkg/mesh/vertex.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/mesh/vertex.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,10 +18,10 @@
 	"encoding/binary"
 	"fmt"
 	"io"
-	"log"
 	"math"
 	"sort"
 
+	"gemma.intevation.de/gemma/pkg/log"
 	"gemma.intevation.de/gemma/pkg/wkb"
 )
 
@@ -571,7 +571,7 @@
 		out = append(out, curr)
 	}
 
-	log.Printf("info: ignored parts: %d\n", ignored)
+	log.Infof("ignored parts: %d\n", ignored)
 
 	return out
 }
@@ -787,7 +787,7 @@
 		}
 	}
 
-	// log.Printf("segments before/after merge: %d/%d (%d rings)\n",
+	// log.Debugf("segments before/after merge: %d/%d (%d rings)\n",
 	// len(mls), len(out), rings)
 
 	return out
--- a/pkg/middleware/dbconn.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/middleware/dbconn.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,10 +17,10 @@
 	"context"
 	"database/sql"
 	"fmt"
-	"log"
 	"net/http"
 
 	"gemma.intevation.de/gemma/pkg/auth"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 type wrapDBKeyType int
@@ -61,7 +61,7 @@
 			next.ServeHTTP(rw, req)
 			return nil
 		}); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			http.Error(rw, fmt.Sprintf("error: %v", err), http.StatusInternalServerError)
 		}
 	})
--- a/pkg/middleware/jsonhandler.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/middleware/jsonhandler.go	Tue Sep 21 12:49:30 2021 +0200
@@ -19,12 +19,12 @@
 	"encoding/json"
 	"fmt"
 	"io"
-	"log"
 	"net/http"
 
 	"github.com/jackc/pgx"
 
 	"gemma.intevation.de/gemma/pkg/auth"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // JSONResult defines the return type of JSONHandler handler function.
@@ -137,7 +137,7 @@
 	}
 
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 		switch e := err.(type) {
 		case pgx.PgError:
 			var res = struct {
@@ -152,7 +152,7 @@
 			rw.Header().Set("Content-Type", "application/json")
 			rw.WriteHeader(http.StatusInternalServerError)
 			if err := json.NewEncoder(rw).Encode(&res); err != nil {
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 			}
 		case JSONError:
 			rw.Header().Set("Content-Type", "application/json")
@@ -166,7 +166,7 @@
 				Message: e.Message,
 			}
 			if err := json.NewEncoder(rw).Encode(&res); err != nil {
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 			}
 		default:
 			http.Error(rw,
@@ -194,7 +194,7 @@
 			err = json.NewEncoder(rw).Encode(jr.Result)
 		}
 		if err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 		}
 	}
 }
@@ -206,6 +206,6 @@
 	rw.Header().Set("X-Content-Type-Options", "nosniff")
 	rw.WriteHeader(code)
 	if err := json.NewEncoder(rw).Encode(data); err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
--- a/pkg/middleware/modifyquery.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/middleware/modifyquery.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,12 +15,12 @@
 
 import (
 	"encoding/hex"
-	"log"
 	"net/http"
 	"net/url"
 	"strings"
 
 	"gemma.intevation.de/gemma/pkg/auth"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // ParseQuery is a modified version of the internal query
@@ -76,13 +76,13 @@
 		parameters := make(url.Values)
 
 		if err := ParseQuery(parameters, req.URL.RawQuery, "&", "=", nil); err != nil {
-			log.Printf("parsing query failed: %v\n", err)
+			log.Errorf("parsing query failed: %v\n", err)
 			http.Error(rw, http.StatusText(http.StatusBadRequest), http.StatusBadRequest)
 			return
 		}
 
 		if err := modify(req, parameters); err != nil {
-			log.Printf("modifying query parameters failed: %v\n", err)
+			log.Errorf("modifying query parameters failed: %v\n", err)
 			http.Error(rw, http.StatusText(http.StatusBadRequest), http.StatusBadRequest)
 		}
 
@@ -101,7 +101,7 @@
 	parameters.Del("env")
 
 	if session, ok := auth.GetSession(req); ok {
-		// log.Printf("info: injecting user %s\n", session.User)
+		// log.Infof("injecting user %s\n", session.User)
 		parameters.Set("env", "user:"+hex.EncodeToString([]byte(session.User)))
 	}
 	return nil
--- a/pkg/misc/tmpfiles.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/misc/tmpfiles.go	Tue Sep 21 12:49:30 2021 +0200
@@ -15,7 +15,6 @@
 
 import (
 	"encoding/hex"
-	"log"
 	"os"
 	"path/filepath"
 	"sort"
@@ -24,6 +23,7 @@
 
 	"gemma.intevation.de/gemma/pkg/common"
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 const (
@@ -40,7 +40,7 @@
 		config.WaitReady()
 		for {
 			if err := cleanupTmpFiles(); err != nil {
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 			}
 			time.Sleep(tmpfilesCleanUp)
 		}
--- a/pkg/models/extservices.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/models/extservices.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,11 +16,11 @@
 import (
 	"context"
 	"database/sql"
-	"log"
 	"sort"
 	"sync"
 
 	"gemma.intevation.de/gemma/pkg/auth"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 type ExtEntry struct {
@@ -45,7 +45,7 @@
 
 	if es.entries == nil {
 		if err := es.load(); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return "", false
 		}
 	}
@@ -99,7 +99,7 @@
 	defer es.mu.Unlock()
 	if es.entries == nil {
 		if err := es.load(); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return nil
 		}
 	}
--- a/pkg/models/intservices.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/models/intservices.go	Tue Sep 21 12:49:30 2021 +0200
@@ -17,12 +17,12 @@
 import (
 	"context"
 	"database/sql"
-	"log"
 	"net/http"
 	"sync"
 
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 const DatabaseScheme = "waterway"
@@ -120,7 +120,7 @@
 
 	if ps.entries == nil {
 		if err := ps.load(); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return nil
 		}
 	}
@@ -142,7 +142,7 @@
 
 	if ps.entries == nil {
 		if err := ps.load(); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return "", false
 		}
 	}
@@ -261,7 +261,7 @@
 	defer ps.mu.Unlock()
 	if ps.entries == nil {
 		if err := ps.load(); err != nil {
-			log.Printf("error: %v\n", err)
+			log.Errorf("%v\n", err)
 			return nil
 		}
 	}
--- a/pkg/scheduler/boot.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/scheduler/boot.go	Tue Sep 21 12:49:30 2021 +0200
@@ -16,10 +16,10 @@
 import (
 	"context"
 	"database/sql"
-	"log"
 
 	"gemma.intevation.de/gemma/pkg/auth"
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 const (
@@ -50,7 +50,7 @@
 // the database which have a schedule.
 func boot() {
 	config.WaitReady()
-	log.Println("info: booting scheduler from database.")
+	log.Infoln("booting scheduler from database.")
 	ctx := context.Background()
 	err := auth.RunAs(
 		ctx, bootRole,
@@ -84,7 +84,7 @@
 			return rows.Err()
 		})
 	if err != nil {
-		log.Printf("error: %v\n", err)
+		log.Errorf("%v\n", err)
 	}
 }
 
--- a/pkg/scheduler/scheduler.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/scheduler/scheduler.go	Tue Sep 21 12:49:30 2021 +0200
@@ -14,12 +14,13 @@
 package scheduler
 
 import (
-	"log"
 	"sort"
 	"strings"
 	"sync"
 
 	cron "gopkg.in/robfig/cron.v1"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 // Action is called with a configuration id.
@@ -42,7 +43,7 @@
 	if a := ua.scheduler.action(ua.name); a != nil {
 		a(ua.cfgID)
 	} else {
-		log.Printf("warn: scheduled action '%s' not found.", ua.name)
+		log.Warnf("scheduled action '%s' not found.", ua.name)
 	}
 }
 
@@ -104,7 +105,7 @@
 		numJobs++
 	}
 
-	log.Printf("info: booting %d scheduler jobs from database.\n", numJobs)
+	log.Infof("booting %d scheduler jobs from database.\n", numJobs)
 
 	s.mu.Lock()
 	defer s.mu.Unlock()
@@ -299,7 +300,7 @@
 func LogActionNames() {
 	names := global.actionNames()
 	sort.Strings(names)
-	log.Printf("info: actions registered to scheduler: %s\n",
+	log.Infof("actions registered to scheduler: %s\n",
 		strings.Join(names, ", "))
 }
 
--- a/pkg/soap/soap.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/soap/soap.go	Tue Sep 21 12:49:30 2021 +0200
@@ -20,7 +20,6 @@
 	"encoding/xml"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"math/rand"
 	"net"
 	"net/http"
@@ -28,6 +27,7 @@
 	"time"
 
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 type SOAPEnvelope struct {
@@ -312,11 +312,11 @@
 		return err
 	}
 	if len(rawbody) == 0 {
-		log.Println("warn: empty response")
+		log.Warnln("empty response")
 		return nil
 	}
 
-	//log.Println(string(rawbody))
+	//log.Debugln(string(rawbody))
 	respEnvelope := new(SOAPEnvelope)
 	respEnvelope.Body = SOAPBody{Content: response}
 	err = xml.Unmarshal(rawbody, respEnvelope)
--- a/pkg/wfs/download.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/wfs/download.go	Tue Sep 21 12:49:30 2021 +0200
@@ -20,13 +20,14 @@
 	"errors"
 	"fmt"
 	"io"
-	"log"
 	"net/http"
 	"net/url"
 	"strconv"
 	"strings"
 
 	"golang.org/x/net/html/charset"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 var (
@@ -155,7 +156,7 @@
 	var numFeatures int
 
 	if supportsPaging {
-		log.Printf("info: Paging supported with %d feature per page.\n",
+		log.Infof("Paging supported with %d feature per page.\n",
 			featuresPerPage)
 
 		if !op.SupportsHits() {
@@ -163,12 +164,12 @@
 		} else {
 			numFeatures, err = numberFeaturesGET(getU, featureTypeName, wfsVersion)
 			if err != nil {
-				log.Printf("error: %v\n", err)
+				log.Errorf("%v\n", err)
 				supportsPaging = false
 			} else if numFeatures == 0 {
 				return nil, nil
 			} else {
-				log.Printf("info: Number of features: %d\n", numFeatures)
+				log.Infof("Number of features: %d\n", numFeatures)
 			}
 		}
 	}
@@ -224,10 +225,10 @@
 		}
 		if numFeatures > 0 {
 			if numFeatures <= featuresPerPage {
-				log.Println("info: All features can be fetched in one page.")
+				log.Infof("all features can be fetched in one page.")
 				downloadURLs = []string{pagedURL(0, numFeatures)}
 			} else {
-				log.Println("info: Features need to be downloaded in pages.")
+				log.Infof("features need to be downloaded in pages.")
 				for pos := 0; pos < numFeatures; {
 					var count int
 					if rest := numFeatures - pos; rest >= numFeatures {
--- a/pkg/wfs/global.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/wfs/global.go	Tue Sep 21 12:49:30 2021 +0200
@@ -18,12 +18,13 @@
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"os"
 	"os/exec"
 	"path/filepath"
+	"sync"
 
 	"gemma.intevation.de/gemma/pkg/config"
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 var (
@@ -53,17 +54,30 @@
 	GMLDownloader []string
 )
 
-// GetFeatures is the default Downloader in this Gemma server.
-var GetFeatures = setup()
+var (
+	getFeaturesOnce sync.Once
+	getFeatures     func(*Capabilities, string, string) (Downloader, error)
+)
 
-func setup() func(*Capabilities, string, string) (Downloader, error) {
+func getFeaturesOnceFunc() {
 	path, err := exec.LookPath("ogr2ogr")
 	if err != nil {
-		log.Println("info: ogr2ogr not installed. Using direct GeoJSON WFS download.")
-		return getFeaturesGeoJSON
+		log.Infoln("ogr2ogr not installed. Using direct GeoJSON WFS download.")
+		getFeatures = getFeaturesGeoJSON
+	} else {
+		log.Infof("ogr2ogr found at %s. Using GML WFS download.\n", path)
+		getFeatures = getFeaturesGML
 	}
-	log.Printf("info: ogr2ogr found at %s. Using GML WFS download.\n", path)
-	return getFeaturesGML
+}
+
+// GetFeatures is the default Downloader in this Gemma server.
+func GetFeatures(
+	caps *Capabilities,
+	featureTypeName string,
+	sortBy string,
+) (Downloader, error) {
+	getFeaturesOnce.Do(getFeaturesOnceFunc)
+	return getFeatures(caps, featureTypeName, sortBy)
 }
 
 func getFeaturesGeoJSON(
--- a/pkg/xlsx/templater.go	Sat Aug 21 15:01:52 2021 +0200
+++ b/pkg/xlsx/templater.go	Tue Sep 21 12:49:30 2021 +0200
@@ -20,7 +20,6 @@
 	"errors"
 	"fmt"
 	"io"
-	"log"
 	"os"
 	"strconv"
 	"strings"
@@ -29,6 +28,8 @@
 	"gopkg.in/yaml.v2"
 
 	"github.com/PaesslerAG/gval"
+
+	"gemma.intevation.de/gemma/pkg/log"
 )
 
 type Action struct {
@@ -291,7 +292,7 @@
 
 	var areas []area
 
-	//log.Println("merged cells")
+	//log.Debugln("merged cells")
 	if mcs, err := e.template.GetMergeCells(e.sourceSheet); err == nil {
 		areas = make([]area, 0, len(mcs))
 		for _, mc := range mcs {
@@ -522,7 +523,7 @@
 	}
 	num, err := excelize.ColumnNameToNumber(name)
 	if err != nil {
-		log.Printf("error: invalid column name '%v'\n", col)
+		log.Errorf("invalid column name '%v'\n", col)
 		return 1
 	}
 	return num
@@ -554,18 +555,18 @@
 func coord2cell(ix, iy interface{}) interface{} {
 	x, err := asInt(ix)
 	if err != nil {
-		log.Printf("error: invalid x value: %v\n", err)
+		log.Errorf("invalid x value: %v\n", err)
 		return "A1"
 	}
 	y, err := asInt(iy)
 	if err != nil {
-		log.Printf("error: invalid y value: %v\n", err)
+		log.Errorf("invalid y value: %v\n", err)
 		return "A1"
 	}
 
 	cell, err := excelize.CoordinatesToCellName(x, y)
 	if err != nil {
-		log.Printf("error: invalid cell coord (%d, %d)\n", x, y)
+		log.Errorf("invalid cell coord (%d, %d)\n", x, y)
 		return "A1"
 	}
 	return cell
@@ -621,7 +622,7 @@
 		}
 		s, err = eval.EvalString(e.ctx, vars)
 		if err != nil {
-			log.Printf("error: '%s' '%s' %v\n", str, s, err)
+			log.Errorf("'%s' '%s' %v\n", str, s, err)
 		}
 		return s
 	}
@@ -652,7 +653,7 @@
 		repCount++
 		last, err = eval(e.ctx, vars)
 		if err != nil {
-			log.Printf("error: '%s' '%s' %v\n", str, s, err)
+			log.Errorf("'%s' '%s' %v\n", str, s, err)
 		}
 		return fmt.Sprintf("%v", last)
 	}