Add basic logging and convert from fmt.Fprint*

cmd/appview/main.go

···
 package main
 
 import (
-	"fmt"
+	"log/slog"
 	"net/http"
-	"os"
 
+	"atyo.app/internal/logging"
 	appview "atyo.app/internal/server"
 )
 
 func main() {
+	logging.Level.Set(slog.LevelDebug) // for active development
+
 	server := appview.NewServer()
 	mux := server.InitializeRoutes()
 
 	// TODO configurable listen address, TLS, etc
 	listenAddr := "127.0.0.1:3000"
-	fmt.Fprintln(os.Stderr, "Starting server on http://"+listenAddr)
+	slog.Info("Starting server on http://" + listenAddr)
 	http.ListenAndServe(listenAddr, mux)
 }

go.mod

···
 	github.com/ipfs/go-log v1.0.5 // indirect
 	github.com/ipfs/go-log/v2 v2.5.1 // indirect
 	github.com/ipfs/go-metrics-interface v0.0.1 // indirect
+	github.com/jba/slog v0.2.0 // indirect
 	github.com/jbenet/goprocess v0.1.4 // indirect
 	github.com/klauspost/cpuid/v2 v2.2.7 // indirect
 	github.com/mattn/go-isatty v0.0.20 // indirect
···
 	github.com/multiformats/go-multihash v0.2.3 // indirect
 	github.com/multiformats/go-varint v0.0.7 // indirect
 	github.com/opentracing/opentracing-go v1.2.0 // indirect
+	github.com/phsym/console-slog v0.3.1 // indirect
 	github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect
 	github.com/polydawn/refmt v0.89.1-0.20221221234430-40501e09de1f // indirect
 	github.com/prometheus/client_golang v1.17.0 // indirect

go.sum

···
 github.com/ipfs/go-log/v2 v2.5.1/go.mod h1:prSpmC1Gpllc9UYWxDiZDreBYw7zp4Iqp1kOLU9U5UI=
 github.com/ipfs/go-metrics-interface v0.0.1 h1:j+cpbjYvu4R8zbleSs36gvB7jR+wsL2fGD6n0jO4kdg=
 github.com/ipfs/go-metrics-interface v0.0.1/go.mod h1:6s6euYU4zowdslK0GKHmqaIZ3j/b/tL7HTWtJ4VPgWY=
+github.com/jba/slog v0.2.0 h1:jI0U5NRR3EJKGsbeEVpItJNogk0c4RMeCl7vJmogCJI=
+github.com/jba/slog v0.2.0/go.mod h1:0Dh7Vyz3Td68Z1OwzadfincHwr7v+PpzadrS2Jua338=
 github.com/jbenet/go-cienv v0.1.0/go.mod h1:TqNnHUmJgXau0nCzC7kXWeotg3J9W34CUv5Djy1+FlA=
 github.com/jbenet/goprocess v0.1.4 h1:DRGOFReOMqqDNXwW70QkacFW0YN9QnwLV0Vqk+3oU0o=
 github.com/jbenet/goprocess v0.1.4/go.mod h1:5yspPrukOVuOLORacaBi858NqyClJPQxYZlqdZVfqY4=
···
 github.com/multiformats/go-varint v0.0.7/go.mod h1:r8PUYw/fD/SjBCiKOoDlGF6QawOELpZAu9eioSos/OU=
 github.com/opentracing/opentracing-go v1.2.0 h1:uEJPy/1a5RIPAJ0Ov+OIO8OxWu77jEv+1B0VhjKrZUs=
 github.com/opentracing/opentracing-go v1.2.0/go.mod h1:GxEUsuufX4nBwe+T+Wl9TAgYrxe9dPLANfrWvHYVTgc=
+github.com/phsym/console-slog v0.3.1 h1:Fuzcrjr40xTc004S9Kni8XfNsk+qrptQmyR+wZw9/7A=
+github.com/phsym/console-slog v0.3.1/go.mod h1:oJskjp/X6e6c0mGpfP8ELkfKUsrkDifYRAqJQgmdDS0=
 github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 h1:Jamvg5psRIccs7FGNTlIRMkT8wgtp5eCXdBlqhYGL6U=

internal/auth/auth.go

···
 
 import (
 	"context"
-	"fmt"
-	"os"
+	"log/slog"
 
 	"atyo.app/internal/lookup"
 	"github.com/bluesky-social/indigo/api/atproto"
···
 		Rkey:       rkey,
 	})
 
-	fmt.Fprintln(os.Stderr, "Created record: "+output.Uri)
+	slog.Info("Created ping record", "uri", output.Uri)
 
 	return err
 }

internal/auth/basic.go

···
 import (
 	"context"
 	"fmt"
-	"os"
+	"log/slog"
 
 	"github.com/bluesky-social/indigo/api/atproto"
 	"github.com/bluesky-social/indigo/atproto/identity"
···
 		return nil, fmt.Errorf("failed to retrieve account PDS")
 	}
 
-	fmt.Fprintln(os.Stderr, "sending login request to "+pds)
+	slog.Info("sending login request", "pds", pds)
 
 	// clear out existing auth first
 	// TODO: use refresh token etc instead of this

internal/logging/logging.go

···
+// Package log provides a simple facade for [log/slog] to write text logs to
+// stderr. TODO: access logs to stdout.
+
+package logging
+
+import (
+	"log/slog"
+	"os"
+
+	"github.com/phsym/console-slog"
+)
+
+const rfc3339Millis = "2006-01-02 15:04:05.000Z07:00"
+
+var Level = new(slog.LevelVar) // Info by default
+
+func init() {
+	logger := slog.New(console.NewHandler(os.Stderr, &console.HandlerOptions{
+		AddSource:  true,
+		TimeFormat: rfc3339Millis,
+	}))
+
+	slog.SetDefault(logger)
+}

internal/lookup/identity.go

···
 
 import (
 	"context"
-	"fmt"
+	"log/slog"
 	"net/http"
-	"os"
 	"strings"
 
 	"atyo.app/internal/errs"
···
 		}
 	}
 
-	fmt.Fprintln(
-		os.Stderr,
-		"resolved to `"+targetId.Handle.String()+"` ("+targetId.DID.String()+")",
-	)
+	slog.Debug("resolved identity", "did", targetId.DID, "handle", targetId.Handle)
 
 	return targetId, nil
 }

internal/ping/ingest_pings.go

···
 	"encoding/hex"
 	"errors"
 	"fmt"
+	"log/slog"
 	"net/http"
-	"os"
 	"slices"
 
 	"atyo.app/api"
···
 	for _, repo := range response.Repos {
 		id, lookupErr := c.directory.LookupID(ctx, repo.Did)
 		if lookupErr != nil {
-			fmt.Fprintf(os.Stderr, "failed to resolve id %s: %s\n", repo.Did, lookupErr)
+			slog.Warn("failed to resolve identity", "did", repo.Did, "err", lookupErr)
 			continue
 		}
 
···
 		)
 
 		if err != nil {
-			fmt.Fprintf(os.Stderr, "failed to fetch from %s: %s\n", repo.Did, err)
+			slog.Warn("failed to fetch repo", "did", repo.Did, "err", err)
 			continue
 		}
-		fmt.Fprintf(os.Stderr, "got %d records for %s\n", len(records.Records), repo.Did)
+		slog.Debug("got repo records", "did", repo.Did, "count", len(records.Records))
 
 		for _, record := range records.Records {
 			ping, ok := record.Value.Val.(*atyo.Ping)
 			if !ok {
-				fmt.Fprintf(os.Stderr, "failed to convert %s to ping", record.Uri)
+				slog.Warn("failed to convert to ping", "uri", record.Uri)
 				continue
 			}
 
 			contents, err := decodePingContents(ping, key)
 			if err != nil {
-				fmt.Fprintln(os.Stderr, "failed to decode ping ", record.Uri, " - ", err)
+				slog.Warn("failed to decode ping", "uri", record.Uri, "err", err)
 				continue
 			}
-			if contents != nil {
-				from, _ := c.directory.LookupID(ctx, repo.Did)
-				var fromHandle *string
-				if from != nil {
-					handle := from.Handle.String()
-					fromHandle = &handle
-				}
 
-				result = append(result, Ping{
-					FromDID:    repo.Did,
-					FromHandle: fromHandle,
-					Contents:   contents,
-				})
-			} else {
-				fmt.Fprintln(os.Stderr, "ping ", record.Uri, "not targeted to self")
+			if contents == nil {
+				slog.Debug("ping not targeted to self", "uri", record.Uri)
+				continue
+			}
+
+			from, _ := c.directory.LookupID(ctx, repo.Did)
+			var fromHandle *string
+			if from != nil {
+				handle := from.Handle.String()
+				fromHandle = &handle
 			}
+
+			result = append(result, Ping{
+				FromDID:    repo.Did,
+				FromHandle: fromHandle,
+				Contents:   contents,
+			})
 		}
 	}
 
···
 	var sharedKey *[sharedKeyLen]byte
 
 	for len(contents) > encryptedHeaderLen {
-		fmt.Fprintf(
-			os.Stderr,
-			"attempting to decode header bytes %s\n",
-			hex.EncodeToString(contents[:encryptedHeaderLen]),
+		slog.Debug(
+			"attempting to decode header",
+			"bytes", hex.EncodeToString(contents[:encryptedHeaderLen]),
 		)
 		header, ok := box.Open(
 			nil,
···
 		)
 
 		if ok {
-			fmt.Fprintln(os.Stderr, "Success! found shared key for ping")
+			slog.Info("found shared key for ping")
 
 			numRecipients := int(header[0])
 			sharedKey = new([sharedKeyLen]byte)
···
 
 		contents = contents[encryptedHeaderLen:]
 
-		fmt.Fprintf(
-			os.Stderr,
-			"failed to decode header, %d bytes remain\n",
-			len(contents),
-		)
+		slog.Debug("failed to decode header", "remaining", len(contents))
 	}
 
 	if sharedKey == nil {
···
 		return nil, fmt.Errorf("unexpected type %T decoded", val)
 	}
 
-	fmt.Fprintf(
-		os.Stderr,
-		"Decoded contents: %s\nCBOR: %+v\n",
-		hex.EncodeToString(decryptedContents), pingContents,
-	)
+	slog.Debug("decoded ping", "contents", pingContents)
 
 	return pingContents, nil
 }

internal/ping/keys.go

···
 import (
 	"context"
 	"crypto/rand"
+	"encoding/hex"
 	"fmt"
-	"os"
+	"log/slog"
 
 	"atyo.app/api"
 	"atyo.app/api/atyo"
···
 		return err
 	}
 
-	fmt.Fprintln(os.Stderr, "created pubkey record")
+	slog.Info("created pubkey record", "public_key", hex.EncodeToString(selfPubKey[:]))
 
 	k.selfPrivateKey = selfPrivKey
 	return nil

internal/ping/send_ping.go

···
 	"encoding/hex"
 	"errors"
 	"fmt"
-	"os"
+	"log/slog"
 
 	"atyo.app/api"
 	"atyo.app/api/atyo"
···
 // Basic ping functionality.
 // - `target` should be a DID or handle
 func (c *Client) SendPing(ctx context.Context, target string) error {
-	fmt.Fprintln(os.Stderr, "got request for ping to `"+target+"`")
+	slog.Info("Got ping request", "target", target)
 
 	targetId, err := c.directory.LookupID(ctx, target)
 	if err != nil {
···
 	// CBOR/JSON encoding, or a schema version? idk if that's really useful for any reason
 	contents := append(encHeader, encryptedMessage...)
 
-	fmt.Fprintf(
-		os.Stderr,
-		"Targeting ping to pubkey %s\nHeader bytes: %s\n",
-		hex.EncodeToString(targetPubkey[:]),
-		hex.EncodeToString(encHeader[:]),
+	slog.Debug(
+		"built ping",
+		"target_pubkey", hex.EncodeToString(targetPubkey[:]),
+		"len", len(contents),
 	)
-
-	fmt.Fprintln(os.Stderr, "contents total len: ", len(contents))
 
 	return &atyo.Ping{
 		Contents:  contents,

internal/server/router.go

···
 import (
 	"encoding/json"
 	"errors"
-	"fmt"
+	"log/slog"
 	"net/http"
-	"os"
 
 	"atyo.app/internal/auth"
 	"atyo.app/internal/errs"
···
 
 	_, err = w.Write(bytes)
 	if err != nil {
-		fmt.Fprintln(os.Stderr, "failed to write response: "+err.Error())
+		slog.Error("failed to write response", "err", err)
 	}
 }
 
···
 	user := req.FormValue("username")
 	pass := req.FormValue("password")
 
-	fmt.Fprintln(os.Stderr, "Attempting login as `"+user+"`")
+	slog.Info("Attempting login", "user", user)
 
 	var authFactorToken *string
 	if req.Form.Has("authFactorToken") {
···
 
 	_, err = w.Write(bytes)
 	if err != nil {
-		fmt.Fprintln(os.Stderr, "failed to write JSON response: "+err.Error())
+		slog.Warn("failed to write JSON response", "err", err)
 	}
 }
 
 func handleErr(w http.ResponseWriter, err error) {
+	slog.Info("sending error response", "err", err)
+
 	var xErr *xrpc.Error
 	if errors.As(err, &xErr) {
 		// Hmm maybe this should be a 50x or certain codes should translate...