Add structured logging

.gitignore

@@ -1 +1,2 @@
 config/config.go
+.vscode

color/color.go

@@ -0,0 +1,49 @@
+package color
+
+import "runtime"
+
+// See this file for a good color reference:
+// https://github.com/fatih/color/blob/master/color.go
+
+var Reset = "\033[0m"
+var Bold = "\033[1m"
+var Faint = "\033[2m"
+var Italic = "\033[3m"
+var Underline = "\033[4m"
+var BlinkSlow = "\033[5m"
+var BlinkRapid = "\033[6m"
+var ReverseVideo = "\033[7m"
+var Concealed = "\033[8m"
+var CrossedOut = "\033[9m"
+
+var Red = "\033[31m"
+var Green = "\033[32m"
+var Yellow = "\033[33m"
+var Blue = "\033[34m"
+var Purple = "\033[35m"
+var Cyan = "\033[36m"
+var Gray = "\033[37m"
+var White = "\033[97m"
+
+var BgBlack = "\033[40m"
+var BgRed = "\033[41m"
+var BgGreen = "\033[42m"
+var BgYellow = "\033[43m"
+var BgBlue = "\033[44m"
+var BgMagenta = "\033[45m"
+var BgCyan = "\033[46m"
+var BgWhite = "\033[47m"
+
+func init() {
+	if runtime.GOOS == "windows" {
+		Reset = ""
+		Red = ""
+		Green = ""
+		Yellow = ""
+		Blue = ""
+		Purple = ""
+		Cyan = ""
+		Gray = ""
+		White = ""
+	}
+}

config/types.go

@@ -12,6 +12,7 @@ const (
 
 type HMNConfig struct {
 	Env      Environment
+	Addr     string
 	Postgres PostgresConfig
 }
 

db/db.go

@@ -2,9 +2,9 @@ package db
 
 import (
 	"context"
-	"fmt"
 
 	"git.handmade.network/hmn/hmn/config"
+	"git.handmade.network/hmn/hmn/oops"
 	"github.com/jackc/pgx/v4"
 	"github.com/jackc/pgx/v4/pgxpool"
 )
@@ -12,7 +12,7 @@ import (
 func NewConn() *pgx.Conn {
 	conn, err := pgx.Connect(context.Background(), config.Config.Postgres.DSN())
 	if err != nil {
-		panic(fmt.Errorf("failed to create database connection: %w", err))
+		panic(oops.New(err, "failed to connect to database"))
 	}
 
 	return conn
@@ -26,7 +26,7 @@ func NewConnPool(minConns, maxConns int32) *pgxpool.Pool {
 
 	conn, err := pgxpool.ConnectConfig(context.Background(), config)
 	if err != nil {
-		panic(fmt.Errorf("failed to create database connection pool: %w", err))
+		panic(oops.New(err, "failed to create database connection pool"))
 	}
 
 	return conn

logging/logging.go

@@ -0,0 +1,158 @@
+package logging
+
+import (
+	"encoding/json"
+	"os"
+	"sort"
+	"strconv"
+	"strings"
+
+	"git.handmade.network/hmn/hmn/color"
+	"git.handmade.network/hmn/hmn/oops"
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/log"
+)
+
+func init() {
+	zerolog.ErrorStackMarshaler = oops.ZerologStackMarshaler
+	log.Logger = log.Output(NewPrettyZerologWriter())
+}
+
+func Trace() *zerolog.Event {
+	return log.Trace().Timestamp().Stack()
+}
+
+func Debug() *zerolog.Event {
+	return log.Debug().Timestamp().Stack()
+}
+
+func Info() *zerolog.Event {
+	return log.Info().Timestamp().Stack()
+}
+
+func Warn() *zerolog.Event {
+	return log.Warn().Timestamp().Stack()
+}
+
+func Error() *zerolog.Event {
+	return log.Error().Timestamp().Stack()
+}
+
+type PrettyZerologWriter struct {
+	wd string
+}
+
+type PrettyLogEntry struct {
+	Timestamp  string
+	Level      string
+	Message    string
+	Error      string
+	StackTrace []interface{}
+
+	OtherFields []PrettyField
+}
+
+type PrettyField struct {
+	Name  string
+	Value interface{}
+}
+
+var ColorFromLevel = map[string]string{
+	"trace": color.Gray,
+	"debug": color.Gray,
+	"info":  color.BgBlue,
+	"warn":  color.BgYellow,
+	"error": color.BgRed,
+	"fatal": color.BgRed,
+	"panic": color.BgRed,
+}
+
+func NewPrettyZerologWriter() *PrettyZerologWriter {
+	wd, _ := os.Getwd()
+	return &PrettyZerologWriter{
+		wd: wd,
+	}
+}
+
+func (w *PrettyZerologWriter) Write(p []byte) (int, error) {
+	// TODO: panic recovery so we log _something_
+
+	var fields map[string]interface{}
+	err := json.Unmarshal(p, &fields)
+	if err != nil {
+		return os.Stderr.Write(p)
+	}
+
+	var pretty PrettyLogEntry
+	for name, val := range fields {
+		switch name {
+		case zerolog.TimestampFieldName:
+			pretty.Timestamp = val.(string)
+		case zerolog.LevelFieldName:
+			pretty.Level = val.(string)
+		case zerolog.MessageFieldName:
+			pretty.Message = val.(string)
+		case zerolog.ErrorFieldName:
+			pretty.Error = val.(string)
+		case zerolog.ErrorStackFieldName:
+			pretty.StackTrace = val.([]interface{})
+		default:
+			pretty.OtherFields = append(pretty.OtherFields, PrettyField{
+				Name:  name,
+				Value: val,
+			})
+		}
+	}
+
+	sort.Slice(pretty.OtherFields, func(i, j int) bool {
+		return strings.Compare(pretty.OtherFields[i].Name, pretty.OtherFields[j].Name) < 0
+	})
+
+	var b strings.Builder
+	b.WriteString("---------------------------------------\n")
+	b.WriteString(pretty.Timestamp)
+	b.WriteString(" ")
+	if pretty.Level != "" {
+		b.WriteString(ColorFromLevel[pretty.Level])
+		b.WriteString(color.Bold)
+		b.WriteString(strings.ToUpper(pretty.Level))
+		b.WriteString(color.Reset)
+		b.WriteString(": ")
+	}
+	b.WriteString(pretty.Message)
+	b.WriteString("\n")
+	if pretty.Error != "" {
+		b.WriteString("  " + color.Bold + color.Red + "ERROR:" + color.Reset + " ")
+		b.WriteString(pretty.Error)
+		b.WriteString("\n")
+	}
+	if len(pretty.OtherFields) > 0 {
+		b.WriteString("  " + color.Bold + color.Blue + "Fields:" + color.Reset + "\n")
+		for _, field := range pretty.OtherFields {
+			valuePretty, _ := json.MarshalIndent(field.Value, "    ", "  ")
+			b.WriteString("    ")
+			b.WriteString(field.Name)
+			b.WriteString(": ")
+			b.WriteString(string(valuePretty))
+			b.WriteString("\n")
+		}
+	}
+	if pretty.StackTrace != nil {
+		b.WriteString("  " + color.Bold + color.Blue + "Stack trace:" + color.Reset + "\n")
+		for _, frame := range pretty.StackTrace {
+			frameMap := frame.(map[string]interface{})
+			file := frameMap["file"].(string)
+			file = strings.Replace(file, w.wd, ".", 1)
+
+			b.WriteString("    ")
+			b.WriteString(frameMap["function"].(string))
+			b.WriteString(" (")
+			b.WriteString(file)
+			b.WriteString(":")
+			b.WriteString(strconv.Itoa(int(frameMap["line"].(float64))))
+			b.WriteString(")\n")
+		}
+	}
+
+	return os.Stderr.Write([]byte(b.String()))
+}

oops/oops.go

@@ -4,12 +4,13 @@ import (
 	"fmt"
 
 	"github.com/go-stack/stack"
+	"github.com/rs/zerolog"
 )
 
 type Error struct {
 	Message string
 	Wrapped error
-	Stack   []StackFrame
+	Stack   CallStack
 }
 
 func (e *Error) Error() string {
@@ -20,12 +21,27 @@ func (e *Error) Unwrap() error {
 	return e.Wrapped
 }
 
+type CallStack []StackFrame
+
+func (s CallStack) MarshalZerologArray(a *zerolog.Array) {
+	for _, frame := range s {
+		a.Object(frame)
+	}
+}
+
 type StackFrame struct {
 	File     string `json:"file"`
 	Line     int    `json:"line"`
 	Function string `json:"function"`
 }
 
+func (f StackFrame) MarshalZerologObject(e *zerolog.Event) {
+	e.
+		Str("file", f.File).
+		Int("line", f.Line).
+		Str("function", f.Function)
+}
+
 var ZerologStackMarshaler = func(err error) interface{} {
 	if asOops, ok := err.(*Error); ok {
 		return asOops.Stack
@@ -35,7 +51,7 @@ var ZerologStackMarshaler = func(err error) interface{} {
 
 func New(wrapped error, format string, args ...interface{}) error {
 	trace := stack.Trace().TrimRuntime()
-	frames := make([]StackFrame, len(trace))
+	frames := make(CallStack, len(trace))
 	for i, call := range trace {
 		callFrame := call.Frame()
 		frames[i] = StackFrame{

website/website.go

@@ -3,10 +3,11 @@ package website
 import (
 	"context"
 	"fmt"
-	"log"
 	"net/http"
 
+	"git.handmade.network/hmn/hmn/config"
 	"git.handmade.network/hmn/hmn/db"
+	"git.handmade.network/hmn/hmn/logging"
 	"github.com/julienschmidt/httprouter"
 	"github.com/spf13/cobra"
 )
@@ -14,7 +15,17 @@ import (
 var WebsiteCommand = &cobra.Command{
 	Short: "Run the HMN website",
 	Run: func(cmd *cobra.Command, args []string) {
-		fmt.Println("Hello, HMN!")
+		defer func() {
+			if r := recover(); r != nil {
+				if err, ok := r.(error); ok {
+					logging.Error().Err(err).Msg("recovered from panic")
+				} else {
+					logging.Error().Interface("recovered", r).Msg("recovered from panic")
+				}
+			}
+		}()
+
+		logging.Info().Msg("Hello, HMN!")
 
 		conn := db.NewConnPool(4, 8)
 
@@ -33,7 +44,7 @@ var WebsiteCommand = &cobra.Command{
 
 			rw.Write([]byte(fmt.Sprintf("(%s) %s\n", id, name)))
 		})
-		log.Print("serving stuff")
-		http.ListenAndServe(":9001", router)
+		logging.Info().Str("addr", config.Config.Addr).Msg("Serving the website")
+		http.ListenAndServe(config.Config.Addr, router)
 	},
 }