add metrics, cleanup logger usages (#51)

* cleanup logger usages and add some metrics

* add some basic metrics

cmd/cocoon/main.go

···
 	"os"
 	"time"
 
+	"github.com/bluesky-social/go-util/pkg/telemetry"
 	"github.com/bluesky-social/indigo/atproto/atcrypto"
 	"github.com/bluesky-social/indigo/atproto/syntax"
 	"github.com/haileyok/cocoon/internal/helpers"
···
 				Name:    "fallback-proxy",
 				EnvVars: []string{"COCOON_FALLBACK_PROXY"},
 			},
+			telemetry.CLIFlagDebug,
+			telemetry.CLIFlagMetricsListenAddress,
 		},
 		Commands: []*cli.Command{
 			runServe,
···
 	Flags: []cli.Flag{},
 	Action: func(cmd *cli.Context) error {
 
+		logger := telemetry.StartLogger(cmd)
+		telemetry.StartMetrics(cmd)
+
 		s, err := server.New(&server.Args{
+			Logger:          logger,
 			Addr:            cmd.String("addr"),
 			DbName:          cmd.String("db-name"),
 			DbType:          cmd.String("db-type"),

metrics/metrics.go

···
+package metrics
+
+import (
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promauto"
+)
+
+const (
+	NAMESPACE = "cocoon"
+)
+
+var (
+	RelaysConnected = promauto.NewGaugeVec(prometheus.GaugeOpts{
+		Namespace: NAMESPACE,
+		Name:      "relays_connected",
+		Help:      "number of connected relays, by host",
+	}, []string{"host"})
+
+	RelaySends = promauto.NewCounterVec(prometheus.CounterOpts{
+		Namespace: NAMESPACE,
+		Name:      "relay_sends",
+		Help:      "number of events sent to a relay, by host",
+	}, []string{"host"})
+
+	RepoOperations = promauto.NewCounterVec(prometheus.CounterOpts{
+		Namespace: NAMESPACE,
+		Name:      "repo_operations",
+		Help:      "number of operations made against repos",
+	}, []string{"kind"})
+)

oauth/dpop/jti_cache.go

···
 }
 
 func newJTICache(size int) *jtiCache {
-	cache := cache.NewCache[string, bool]().WithTTL(24 * time.Hour).WithLRU().WithTTL(constants.JTITtl)
+	cache := cache.NewCache[string, bool]().WithTTL(24 * time.Hour).WithLRU().WithTTL(constants.JTITtl).WithMaxKeys(size)
 	return &jtiCache{
 		cache: cache,
 		mu:    sync.Mutex{},

server/handle_account.go

···
 
 func (s *Server) handleAccount(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleAuth")
 
 	repo, sess, err := s.getSessionRepoOrErr(e)
 	if err != nil {
···
 
 	var tokens []provider.OauthToken
 	if err := s.db.Raw(ctx, "SELECT * FROM oauth_tokens WHERE sub = ? AND created_at < ? ORDER BY created_at ASC", nil, repo.Repo.Did, oldestPossibleSession).Scan(&tokens).Error; err != nil {
-		s.logger.Error("couldnt fetch oauth sessions for account", "did", repo.Repo.Did, "error", err)
+		logger.Error("couldnt fetch oauth sessions for account", "did", repo.Repo.Did, "error", err)
 		sess.AddFlash("Unable to fetch sessions. See server logs for more details.", "error")
 		sess.Save(e.Request(), e.Response())
 		return e.Render(200, "account.html", map[string]any{

server/handle_account_revoke.go

···
 
 func (s *Server) handleAccountRevoke(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleAcocuntRevoke")
 
 	var req AccountRevokeInput
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("could not bind account revoke request", "error", err)
+		logger.Error("could not bind account revoke request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	}
 
 	if err := s.db.Exec(ctx, "DELETE FROM oauth_tokens WHERE sub = ? AND token = ?", nil, repo.Repo.Did, req.Token).Error; err != nil {
-		s.logger.Error("couldnt delete oauth session for account", "did", repo.Repo.Did, "token", req.Token, "error", err)
+		logger.Error("couldnt delete oauth session for account", "did", repo.Repo.Did, "token", req.Token, "error", err)
 		sess.AddFlash("Unable to revoke session. See server logs for more details.", "error")
 		sess.Save(e.Request(), e.Response())
 		return e.Redirect(303, "/account")

server/handle_account_signin.go

···
 
 func (s *Server) handleAccountSigninPost(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleAccountSigninPost")
 
 	var req OauthSigninInput
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding sign in req", "error", err)
+		logger.Error("error binding sign in req", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_identity_get_recommended_did_credentials.go

···
 )
 
 func (s *Server) handleGetRecommendedDidCredentials(e echo.Context) error {
+	logger := s.logger.With("name", "handleIdentityGetRecommendedDidCredentials")
+
 	repo := e.Get("repo").(*models.RepoActor)
 	k, err := atcrypto.ParsePrivateBytesK256(repo.SigningKey)
 	if err != nil {
-		s.logger.Error("error parsing key", "error", err)
+		logger.Error("error parsing key", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	creds, err := s.plcClient.CreateDidCredentials(k, "", repo.Actor.Handle)
 	if err != nil {
-		s.logger.Error("error crating did credentials", "error", err)
+		logger.Error("error crating did credentials", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_identity_request_plc_operation.go

···
 
 func (s *Server) handleIdentityRequestPlcOperationSignature(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleIdentityRequestPlcOperationSignature")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 	eat := time.Now().Add(10 * time.Minute).UTC()
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET plc_operation_code = ?, plc_operation_code_expires_at = ? WHERE did = ?", nil, code, eat, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating user", "error", err)
+		logger.Error("error updating user", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.sendPlcTokenReset(urepo.Email, urepo.Handle, code); err != nil {
-		s.logger.Error("error sending mail", "error", err)
+		logger.Error("error sending mail", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_identity_sign_plc_operation.go

···
 }
 
 func (s *Server) handleSignPlcOperation(e echo.Context) error {
+	logger := s.logger.With("name", "handleSignPlcOperation")
+
 	repo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoSignPlcOperationRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	ctx := context.WithValue(e.Request().Context(), "skip-cache", true)
 	log, err := identity.FetchDidAuditLog(ctx, nil, repo.Repo.Did)
 	if err != nil {
-		s.logger.Error("error fetching doc", "error", err)
+		logger.Error("error fetching doc", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	k, err := atcrypto.ParsePrivateBytesK256(repo.SigningKey)
 	if err != nil {
-		s.logger.Error("error parsing signing key", "error", err)
+		logger.Error("error parsing signing key", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.plcClient.SignOp(k, &op); err != nil {
-		s.logger.Error("error signing plc operation", "error", err)
+		logger.Error("error signing plc operation", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET plc_operation_code = NULL, plc_operation_code_expires_at = NULL WHERE did = ?", nil, repo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating repo", "error", err)
+		logger.Error("error updating repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_identity_submit_plc_operation.go

···
 }
 
 func (s *Server) handleSubmitPlcOperation(e echo.Context) error {
+	logger := s.logger.With("name", "handleIdentitySubmitPlcOperation")
+
 	repo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoSubmitPlcOperationRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	k, err := atcrypto.ParsePrivateBytesK256(repo.SigningKey)
 	if err != nil {
-		s.logger.Error("error parsing key", "error", err)
+		logger.Error("error parsing key", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	required, err := s.plcClient.CreateDidCredentials(k, "", repo.Actor.Handle)
 	if err != nil {
-		s.logger.Error("error crating did credentials", "error", err)
+		logger.Error("error crating did credentials", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	}
 
 	if err := s.passport.BustDoc(context.TODO(), repo.Repo.Did); err != nil {
-		s.logger.Warn("error busting did doc", "error", err)
+		logger.Warn("error busting did doc", "error", err)
 	}
 
 	s.evtman.AddEvent(context.TODO(), &events.XRPCStreamEvent{

server/handle_identity_update_handle.go

···
 }
 
 func (s *Server) handleIdentityUpdateHandle(e echo.Context) error {
+	logger := s.logger.With("name", "handleIdentityUpdateHandle")
+
 	repo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoIdentityUpdateHandleRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	if strings.HasPrefix(repo.Repo.Did, "did:plc:") {
 		log, err := identity.FetchDidAuditLog(ctx, nil, repo.Repo.Did)
 		if err != nil {
-			s.logger.Error("error fetching doc", "error", err)
+			logger.Error("error fetching doc", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 
 		k, err := atcrypto.ParsePrivateBytesK256(repo.SigningKey)
 		if err != nil {
-			s.logger.Error("error parsing signing key", "error", err)
+			logger.Error("error parsing signing key", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 	}
 
 	if err := s.passport.BustDoc(context.TODO(), repo.Repo.Did); err != nil {
-		s.logger.Warn("error busting did doc", "error", err)
+		logger.Warn("error busting did doc", "error", err)
 	}
 
 	s.evtman.AddEvent(context.TODO(), &events.XRPCStreamEvent{
···
 	})
 
 	if err := s.db.Exec(ctx, "UPDATE actors SET handle = ? WHERE did = ?", nil, req.Handle, repo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating handle in db", "error", err)
+		logger.Error("error updating handle in db", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_import_repo.go

···
 
 func (s *Server) handleRepoImportRepo(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleImportRepo")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
 	b, err := io.ReadAll(e.Request().Body)
 	if err != nil {
-		s.logger.Error("could not read bytes in import request", "error", err)
+		logger.Error("could not read bytes in import request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	cs, err := car.NewCarReader(bytes.NewReader(b))
 	if err != nil {
-		s.logger.Error("could not read car in import request", "error", err)
+		logger.Error("could not read car in import request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	orderedBlocks := []blocks.Block{}
 	currBlock, err := cs.Next()
 	if err != nil {
-		s.logger.Error("could not get first block from car", "error", err)
+		logger.Error("could not get first block from car", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	currBlockCt := 1
 
 	for currBlock != nil {
-		s.logger.Info("someone is importing their repo", "block", currBlockCt)
+		logger.Info("someone is importing their repo", "block", currBlockCt)
 		orderedBlocks = append(orderedBlocks, currBlock)
 		next, _ := cs.Next()
 		currBlock = next
···
 	slices.Reverse(orderedBlocks)
 
 	if err := bs.PutMany(context.TODO(), orderedBlocks); err != nil {
-		s.logger.Error("could not insert blocks", "error", err)
+		logger.Error("could not insert blocks", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	r, err := repo.OpenRepo(context.TODO(), bs, cs.Header.Roots[0])
 	if err != nil {
-		s.logger.Error("could not open repo", "error", err)
+		logger.Error("could not open repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 		cidStr := cid.String()
 		b, err := bs.Get(context.TODO(), cid)
 		if err != nil {
-			s.logger.Error("record bytes don't exist in blockstore", "error", err)
+			logger.Error("record bytes don't exist in blockstore", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 		return nil
 	}); err != nil {
 		tx.Rollback()
-		s.logger.Error("record bytes don't exist in blockstore", "error", err)
+		logger.Error("record bytes don't exist in blockstore", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	root, rev, err := r.Commit(context.TODO(), urepo.SignFor)
 	if err != nil {
-		s.logger.Error("error committing", "error", err)
+		logger.Error("error committing", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.UpdateRepo(context.TODO(), urepo.Repo.Did, root, rev); err != nil {
-		s.logger.Error("error updating repo after commit", "error", err)
+		logger.Error("error updating repo after commit", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_oauth_authorize.go

···
 
 func (s *Server) handleOauthAuthorizePost(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleOauthAuthorizePost")
 
 	repo, _, err := s.getSessionRepoOrErr(e)
 	if err != nil {
···
 
 	var req OauthAuthorizePostRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding authorize post request", "error", err)
+		logger.Error("error binding authorize post request", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 	code := oauth.GenerateCode()
 
 	if err := s.db.Exec(ctx, "UPDATE oauth_authorization_requests SET sub = ?, code = ?, accepted = ?, ip = ? WHERE request_id = ?", nil, repo.Repo.Did, code, true, e.RealIP(), reqId).Error; err != nil {
-		s.logger.Error("error updating authorization request", "error", err)
+		logger.Error("error updating authorization request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_oauth_par.go

···
 
 func (s *Server) handleOauthPar(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleOauthPar")
 
 	var parRequest provider.ParRequest
 	if err := e.Bind(&parRequest); err != nil {
-		s.logger.Error("error binding for par request", "error", err)
+		logger.Error("error binding for par request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(parRequest); err != nil {
-		s.logger.Error("missing parameters for par request", "error", err)
+		logger.Error("missing parameters for par request", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 				"error": "use_dpop_nonce",
 			})
 		}
-		s.logger.Error("error getting dpop proof", "error", err)
+		logger.Error("error getting dpop proof", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 		AllowMissingDpopProof: true,
 	})
 	if err != nil {
-		s.logger.Error("error authenticating client", "client_id", parRequest.ClientID, "error", err)
+		logger.Error("error authenticating client", "client_id", parRequest.ClientID, "error", err)
 		return helpers.InputError(e, to.StringPtr(err.Error()))
 	}
 
···
 	} else {
 		if !client.Metadata.DpopBoundAccessTokens {
 			msg := "dpop bound access tokens are not enabled for this client"
-			s.logger.Error(msg)
+			logger.Error(msg)
 			return helpers.InputError(e, &msg)
 		}
 
 		if dpopProof.JKT != *parRequest.DpopJkt {
 			msg := "supplied dpop jkt does not match header dpop jkt"
-			s.logger.Error(msg)
+			logger.Error(msg)
 			return helpers.InputError(e, &msg)
 		}
 	}
···
 	}
 
 	if err := s.db.Create(ctx, authRequest, nil).Error; err != nil {
-		s.logger.Error("error creating auth request in db", "error", err)
+		logger.Error("error creating auth request in db", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_oauth_token.go

···
 
 func (s *Server) handleOauthToken(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleOauthToken")
 
 	var req OauthTokenRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding token request", "error", err)
+		logger.Error("error binding token request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 				"error": "use_dpop_nonce",
 			})
 		}
-		s.logger.Error("error getting dpop proof", "error", err)
+		logger.Error("error getting dpop proof", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 		AllowMissingDpopProof: true,
 	})
 	if err != nil {
-		s.logger.Error("error authenticating client", "client_id", req.ClientID, "error", err)
+		logger.Error("error authenticating client", "client_id", req.ClientID, "error", err)
 		return helpers.InputError(e, to.StringPtr(err.Error()))
 	}
 
···
 		var authReq provider.OauthAuthorizationRequest
 		// get the lil guy and delete him
 		if err := s.db.Raw(ctx, "DELETE FROM oauth_authorization_requests WHERE code = ? RETURNING *", nil, *req.Code).Scan(&authReq).Error; err != nil {
-			s.logger.Error("error finding authorization request", "error", err)
+			logger.Error("error finding authorization request", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 			case "S256":
 				inputChal, err := base64.RawURLEncoding.DecodeString(*authReq.Parameters.CodeChallenge)
 				if err != nil {
-					s.logger.Error("error decoding code challenge", "error", err)
+					logger.Error("error decoding code challenge", "error", err)
 					return helpers.ServerError(e, nil)
 				}
 
···
 			RefreshToken: refreshToken,
 			Ip:           authReq.Ip,
 		}, nil).Error; err != nil {
-			s.logger.Error("error creating token in db", "error", err)
+			logger.Error("error creating token in db", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 
 		var oauthToken provider.OauthToken
 		if err := s.db.Raw(ctx, "SELECT * FROM oauth_tokens WHERE refresh_token = ?", nil, req.RefreshToken).Scan(&oauthToken).Error; err != nil {
-			s.logger.Error("error finding oauth token by refresh token", "error", err, "refresh_token", req.RefreshToken)
+			logger.Error("error finding oauth token by refresh token", "error", err, "refresh_token", req.RefreshToken)
 			return helpers.ServerError(e, nil)
 		}
 
···
 		}
 
 		if err := s.db.Exec(ctx, "UPDATE oauth_tokens SET token = ?, refresh_token = ?, expires_at = ?, updated_at = ? WHERE refresh_token = ?", nil, accessString, nextRefreshToken, eat, now, *req.RefreshToken).Error; err != nil {
-			s.logger.Error("error updating token", "error", err)
+			logger.Error("error updating token", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 

server/handle_proxy.go

···
 }
 
 func (s *Server) handleProxy(e echo.Context) error {
-	lgr := s.logger.With("handler", "handleProxy")
+	logger := s.logger.With("handler", "handleProxy")
 
 	repo, isAuthed := e.Get("repo").(*models.RepoActor)
 
···
 
 	endpoint, svcDid, err := s.getAtprotoProxyEndpointFromRequest(e)
 	if err != nil {
-		lgr.Error("could not get atproto proxy", "error", err)
+		logger.Error("could not get atproto proxy", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 		}
 		hj, err := json.Marshal(header)
 		if err != nil {
-			lgr.Error("error marshaling header", "error", err)
+			logger.Error("error marshaling header", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 		}
 		pj, err := json.Marshal(payload)
 		if err != nil {
-			lgr.Error("error marashaling payload", "error", err)
+			logger.Error("error marashaling payload", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 
 		sk, err := secp256k1secec.NewPrivateKey(repo.SigningKey)
 		if err != nil {
-			lgr.Error("can't load private key", "error", err)
+			logger.Error("can't load private key", "error", err)
 			return err
 		}
 
 		R, S, _, err := sk.SignRaw(rand.Reader, hash[:])
 		if err != nil {
-			lgr.Error("error signing", "error", err)
+			logger.Error("error signing", "error", err)
 		}
 
 		rBytes := R.Bytes()

server/handle_repo_apply_writes.go

···
 
 func (s *Server) handleApplyWrites(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleRepoApplyWrites")
 
 	var req ComAtprotoRepoApplyWritesInput
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
 	repo := e.Get("repo").(*models.RepoActor)
 
 	if repo.Repo.Did != req.Repo {
-		s.logger.Warn("mismatched repo/auth")
+		logger.Warn("mismatched repo/auth")
 		return helpers.InputError(e, nil)
 	}
 
···
 
 	results, err := s.repoman.applyWrites(ctx, repo.Repo, ops, req.SwapCommit)
 	if err != nil {
-		s.logger.Error("error applying writes", "error", err)
+		logger.Error("error applying writes", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_create_record.go

···
 
 func (s *Server) handleCreateRecord(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleCreateRecord")
 
 	repo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoRepoCreateRecordInput
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
 	if repo.Repo.Did != req.Repo {
-		s.logger.Warn("mismatched repo/auth")
+		logger.Warn("mismatched repo/auth")
 		return helpers.InputError(e, nil)
 	}
 
···
 		},
 	}, req.SwapCommit)
 	if err != nil {
-		s.logger.Error("error applying writes", "error", err)
+		logger.Error("error applying writes", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_delete_record.go

···
 
 func (s *Server) handleDeleteRecord(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleDeleteRecord")
 
 	repo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoRepoDeleteRecordInput
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
 	if repo.Repo.Did != req.Repo {
-		s.logger.Warn("mismatched repo/auth")
+		logger.Warn("mismatched repo/auth")
 		return helpers.InputError(e, nil)
 	}
 
···
 		},
 	}, req.SwapCommit)
 	if err != nil {
-		s.logger.Error("error applying writes", "error", err)
+		logger.Error("error applying writes", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_describe_repo.go

···
 
 func (s *Server) handleDescribeRepo(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleDescribeRepo")
 
 	did := e.QueryParam("repo")
 	repo, err := s.getRepoActorByDid(ctx, did)
···
 			return helpers.InputError(e, to.StringPtr("RepoNotFound"))
 		}
 
-		s.logger.Error("error looking up repo", "error", err)
+		logger.Error("error looking up repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	diddoc, err := s.passport.FetchDoc(e.Request().Context(), repo.Repo.Did)
 	if err != nil {
-		s.logger.Error("error fetching diddoc", "error", err)
+		logger.Error("error fetching diddoc", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	var records []models.Record
 	if err := s.db.Raw(ctx, "SELECT DISTINCT(nsid) FROM records WHERE did = ?", nil, repo.Repo.Did).Scan(&records).Error; err != nil {
-		s.logger.Error("error getting collections", "error", err)
+		logger.Error("error getting collections", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_list_missing_blobs.go

···
 
 func (s *Server) handleListMissingBlobs(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleListMissingBlos")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 
 	var records []models.Record
 	if err := s.db.Raw(ctx, "SELECT * FROM records WHERE did = ?", nil, urepo.Repo.Did).Scan(&records).Error; err != nil {
-		s.logger.Error("failed to get records for listMissingBlobs", "error", err)
+		logger.Error("failed to get records for listMissingBlobs", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_list_records.go

···
 
 func (s *Server) handleListRecords(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleListRecords")
 
 	var req ComAtprotoRepoListRecordsRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("could not bind list records request", "error", err)
+		logger.Error("could not bind list records request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	var records []models.Record
 	if err := s.db.Raw(ctx, "SELECT * FROM records WHERE did = ? AND nsid = ? "+cursorquery+" ORDER BY created_at "+sort+" limit ?", nil, params...).Scan(&records).Error; err != nil {
-		s.logger.Error("error getting records", "error", err)
+		logger.Error("error getting records", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_put_record.go

···
 
 func (s *Server) handlePutRecord(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handlePutRecord")
 
 	repo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoRepoPutRecordInput
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
 	if repo.Repo.Did != req.Repo {
-		s.logger.Warn("mismatched repo/auth")
+		logger.Warn("mismatched repo/auth")
 		return helpers.InputError(e, nil)
 	}
 
···
 		},
 	}, req.SwapCommit)
 	if err != nil {
-		s.logger.Error("error applying writes", "error", err)
+		logger.Error("error applying writes", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_repo_upload_blob.go

···
 
 func (s *Server) handleRepoUploadBlob(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleRepoUploadBlob")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 	}
 
 	if err := s.db.Create(ctx, &blob, nil).Error; err != nil {
-		s.logger.Error("error creating new blob in db", "error", err)
+		logger.Error("error creating new blob in db", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 				break
 			}
 		} else if err != nil && err != io.ErrUnexpectedEOF {
-			s.logger.Error("error reading blob", "error", err)
+			logger.Error("error reading blob", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 			}
 
 			if err := s.db.Create(ctx, &blobPart, nil).Error; err != nil {
-				s.logger.Error("error adding blob part to db", "error", err)
+				logger.Error("error adding blob part to db", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 		}
···
 
 	c, err := cid.NewPrefixV1(cid.Raw, multihash.SHA2_256).Sum(fulldata.Bytes())
 	if err != nil {
-		s.logger.Error("error creating cid prefix", "error", err)
+		logger.Error("error creating cid prefix", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 		sess, err := session.NewSession(config)
 		if err != nil {
-			s.logger.Error("error creating aws session", "error", err)
+			logger.Error("error creating aws session", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 			Key:    aws.String(fmt.Sprintf("blobs/%s/%s", urepo.Repo.Did, c.String())),
 			Body:   bytes.NewReader(fulldata.Bytes()),
 		}); err != nil {
-			s.logger.Error("error uploading blob to s3", "error", err)
+			logger.Error("error uploading blob to s3", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	}
 
 	if err := s.db.Exec(ctx, "UPDATE blobs SET cid = ? WHERE id = ?", nil, c.Bytes(), blob.ID).Error; err != nil {
 		// there should probably be somme handling here if this fails...
-		s.logger.Error("error updating blob", "error", err)
+		logger.Error("error updating blob", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_activate_account.go

···
 
 func (s *Server) handleServerActivateAccount(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerActivateAccount")
 
 	var req ComAtprotoServerDeactivateAccountRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET deactivated = ? WHERE did = ?", nil, false, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating account status to deactivated", "error", err)
+		logger.Error("error updating account status to deactivated", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_check_account_status.go

···
 
 func (s *Server) handleServerCheckAccountStatus(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerCheckAccountStatus")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 
 	rootcid, err := cid.Cast(urepo.Root)
 	if err != nil {
-		s.logger.Error("error casting cid", "error", err)
+		logger.Error("error casting cid", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	resp.RepoCommit = rootcid.String()
···
 
 	var blockCtResp CountResp
 	if err := s.db.Raw(ctx, "SELECT COUNT(*) AS ct FROM blocks WHERE did = ?", nil, urepo.Repo.Did).Scan(&blockCtResp).Error; err != nil {
-		s.logger.Error("error getting block count", "error", err)
+		logger.Error("error getting block count", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	resp.RepoBlocks = blockCtResp.Ct
 
 	var recCtResp CountResp
 	if err := s.db.Raw(ctx, "SELECT COUNT(*) AS ct FROM records WHERE did = ?", nil, urepo.Repo.Did).Scan(&recCtResp).Error; err != nil {
-		s.logger.Error("error getting record count", "error", err)
+		logger.Error("error getting record count", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	resp.IndexedRecords = recCtResp.Ct
 
 	var blobCtResp CountResp
 	if err := s.db.Raw(ctx, "SELECT COUNT(*) AS ct FROM blobs WHERE did = ?", nil, urepo.Repo.Did).Scan(&blobCtResp).Error; err != nil {
-		s.logger.Error("error getting record count", "error", err)
+		logger.Error("error getting record count", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	resp.ExpectedBlobs = blobCtResp.Ct

server/handle_server_confirm_email.go

···
 
 func (s *Server) handleServerConfirmEmail(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerConfirmEmail")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoServerConfirmEmailRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	now := time.Now().UTC()
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET email_verification_code = NULL, email_verification_code_expires_at = NULL, email_confirmed_at = ? WHERE did = ?", nil, now, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating user", "error", err)
+		logger.Error("error updating user", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_create_account.go

···
 
 func (s *Server) handleCreateAccount(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerCreateAccount")
 
 	var request ComAtprotoServerCreateAccountRequest
 
 	if err := e.Bind(&request); err != nil {
-		s.logger.Error("error receiving request", "endpoint", "com.atproto.server.createAccount", "error", err)
+		logger.Error("error receiving request", "endpoint", "com.atproto.server.createAccount", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	request.Handle = strings.ToLower(request.Handle)
 
 	if err := e.Validate(request); err != nil {
-		s.logger.Error("error validating request", "endpoint", "com.atproto.server.createAccount", "error", err)
+		logger.Error("error validating request", "endpoint", "com.atproto.server.createAccount", "error", err)
 
 		var verr ValidationError
 		if errors.As(err, &verr) {
···
 		authDid, err := s.validateServiceAuth(e.Request().Context(), token, "com.atproto.server.createAccount")
 
 		if err != nil {
-			s.logger.Warn("error validating authorization token", "endpoint", "com.atproto.server.createAccount", "error", err)
+			logger.Warn("error validating authorization token", "endpoint", "com.atproto.server.createAccount", "error", err)
 			return helpers.UnauthorizedError(e, to.StringPtr("invalid authorization token"))
 		}
 
···
 	// see if the handle is already taken
 	actor, err := s.getActorByHandle(ctx, request.Handle)
 	if err != nil && err != gorm.ErrRecordNotFound {
-		s.logger.Error("error looking up handle in db", "endpoint", "com.atproto.server.createAccount", "error", err)
+		logger.Error("error looking up handle in db", "endpoint", "com.atproto.server.createAccount", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	if err == nil && actor.Did != signupDid {
···
 			if err == gorm.ErrRecordNotFound {
 				return helpers.InputError(e, to.StringPtr("InvalidInviteCode"))
 			}
-			s.logger.Error("error getting invite code from db", "error", err)
+			logger.Error("error getting invite code from db", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 	// see if the email is already taken
 	existingRepo, err := s.getRepoByEmail(ctx, request.Email)
 	if err != nil && err != gorm.ErrRecordNotFound {
-		s.logger.Error("error looking up email in db", "endpoint", "com.atproto.server.createAccount", "error", err)
+		logger.Error("error looking up email in db", "endpoint", "com.atproto.server.createAccount", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 	if err == nil && existingRepo.Did != signupDid {
···
 	if signupDid != "" {
 		reservedKey, err := s.getReservedKey(ctx, signupDid)
 		if err != nil {
-			s.logger.Error("error looking up reserved key", "error", err)
+			logger.Error("error looking up reserved key", "error", err)
 		}
 		if reservedKey != nil {
 			k, err = atcrypto.ParsePrivateBytesK256(reservedKey.PrivateKey)
 			if err != nil {
-				s.logger.Error("error parsing reserved key", "error", err)
+				logger.Error("error parsing reserved key", "error", err)
 				k = nil
 			} else {
 				defer func() {
 					if delErr := s.deleteReservedKey(ctx, reservedKey.KeyDid, reservedKey.Did); delErr != nil {
-						s.logger.Error("error deleting reserved key", "error", delErr)
+						logger.Error("error deleting reserved key", "error", delErr)
 					}
 				}()
 			}
···
 	if k == nil {
 		k, err = atcrypto.GeneratePrivateKeyK256()
 		if err != nil {
-			s.logger.Error("error creating signing key", "endpoint", "com.atproto.server.createAccount", "error", err)
+			logger.Error("error creating signing key", "endpoint", "com.atproto.server.createAccount", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	}
···
 	if signupDid == "" {
 		did, op, err := s.plcClient.CreateDID(k, "", request.Handle)
 		if err != nil {
-			s.logger.Error("error creating operation", "endpoint", "com.atproto.server.createAccount", "error", err)
+			logger.Error("error creating operation", "endpoint", "com.atproto.server.createAccount", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
 		if err := s.plcClient.SendOperation(e.Request().Context(), did, op); err != nil {
-			s.logger.Error("error sending plc op", "endpoint", "com.atproto.server.createAccount", "error", err)
+			logger.Error("error sending plc op", "endpoint", "com.atproto.server.createAccount", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 		signupDid = did
···
 
 	hashed, err := bcrypt.GenerateFromPassword([]byte(request.Password), 10)
 	if err != nil {
-		s.logger.Error("error hashing password", "error", err)
+		logger.Error("error hashing password", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 		}
 
 		if err := s.db.Create(ctx, &urepo, nil).Error; err != nil {
-			s.logger.Error("error inserting new repo", "error", err)
+			logger.Error("error inserting new repo", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
 		if err := s.db.Create(ctx, &actor, nil).Error; err != nil {
-			s.logger.Error("error inserting new actor", "error", err)
+			logger.Error("error inserting new actor", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	} else {
 		if err := s.db.Save(ctx, &actor, nil).Error; err != nil {
-			s.logger.Error("error inserting new actor", "error", err)
+			logger.Error("error inserting new actor", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	}
···
 
 		root, rev, err := r.Commit(context.TODO(), urepo.SignFor)
 		if err != nil {
-			s.logger.Error("error committing", "error", err)
+			logger.Error("error committing", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
 		if err := s.UpdateRepo(context.TODO(), urepo.Did, root, rev); err != nil {
-			s.logger.Error("error updating repo after commit", "error", err)
+			logger.Error("error updating repo after commit", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 
 	if s.config.RequireInvite {
 		if err := s.db.Raw(ctx, "UPDATE invite_codes SET remaining_use_count = remaining_use_count - 1 WHERE code = ?", nil, request.InviteCode).Scan(&ic).Error; err != nil {
-			s.logger.Error("error decrementing use count", "error", err)
+			logger.Error("error decrementing use count", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	}
 
 	sess, err := s.createSession(ctx, &urepo)
 	if err != nil {
-		s.logger.Error("error creating new session", "error", err)
+		logger.Error("error creating new session", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	go func() {
 		if err := s.sendEmailVerification(urepo.Email, actor.Handle, *urepo.EmailVerificationCode); err != nil {
-			s.logger.Error("error sending email verification email", "error", err)
+			logger.Error("error sending email verification email", "error", err)
 		}
 		if err := s.sendWelcomeMail(urepo.Email, actor.Handle); err != nil {
-			s.logger.Error("error sending welcome email", "error", err)
+			logger.Error("error sending welcome email", "error", err)
 		}
 	}()
 

server/handle_server_create_invite_code.go

···
 
 func (s *Server) handleCreateInviteCode(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerCreateInviteCode")
 
 	var req ComAtprotoServerCreateInviteCodeRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 		Did:               acc,
 		RemainingUseCount: req.UseCount,
 	}, nil).Error; err != nil {
-		s.logger.Error("error creating invite code", "error", err)
+		logger.Error("error creating invite code", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_create_invite_codes.go

···
 
 func (s *Server) handleCreateInviteCodes(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerCreateInviteCodes")
 
 	var req ComAtprotoServerCreateInviteCodesRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 				Did:               did,
 				RemainingUseCount: req.UseCount,
 			}, nil).Error; err != nil {
-				s.logger.Error("error creating invite code", "error", err)
+				logger.Error("error creating invite code", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 		}

server/handle_server_create_session.go

···
 
 func (s *Server) handleCreateSession(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerCreateSession")
 
 	var req ComAtprotoServerCreateSessionRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding request", "endpoint", "com.atproto.server.serverCreateSession", "error", err)
+		logger.Error("error binding request", "endpoint", "com.atproto.server.serverCreateSession", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 			return helpers.InputError(e, to.StringPtr("InvalidRequest"))
 		}
 
-		s.logger.Error("erorr looking up repo", "endpoint", "com.atproto.server.createSession", "error", err)
+		logger.Error("erorr looking up repo", "endpoint", "com.atproto.server.createSession", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := bcrypt.CompareHashAndPassword([]byte(repo.Password), []byte(req.Password)); err != nil {
 		if err != bcrypt.ErrMismatchedHashAndPassword {
-			s.logger.Error("erorr comparing hash and password", "error", err)
+			logger.Error("erorr comparing hash and password", "error", err)
 		}
 		return helpers.InputError(e, to.StringPtr("InvalidRequest"))
 	}
 
 	sess, err := s.createSession(ctx, &repo.Repo)
 	if err != nil {
-		s.logger.Error("error creating session", "error", err)
+		logger.Error("error creating session", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_deactivate_account.go

···
 
 func (s *Server) handleServerDeactivateAccount(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerDeactivateAccount")
 
 	var req ComAtprotoServerDeactivateAccountRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET deactivated = ? WHERE did = ?", nil, true, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating account status to deactivated", "error", err)
+		logger.Error("error updating account status to deactivated", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_delete_account.go

···
 
 func (s *Server) handleServerDeleteAccount(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerDeleteAccount")
 
 	var req ComAtprotoServerDeleteAccountRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := e.Validate(&req); err != nil {
-		s.logger.Error("error validating", "error", err)
+		logger.Error("error validating", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	urepo, err := s.getRepoActorByDid(ctx, req.Did)
 	if err != nil {
-		s.logger.Error("error getting repo", "error", err)
+		logger.Error("error getting repo", "error", err)
 		return echo.NewHTTPError(400, "account not found")
 	}
 
 	if err := bcrypt.CompareHashAndPassword([]byte(urepo.Repo.Password), []byte(req.Password)); err != nil {
-		s.logger.Error("password mismatch", "error", err)
+		logger.Error("password mismatch", "error", err)
 		return echo.NewHTTPError(401, "Invalid did or password")
 	}
 
 	if urepo.Repo.AccountDeleteCode == nil || urepo.Repo.AccountDeleteCodeExpiresAt == nil {
-		s.logger.Error("no deletion token found for account")
+		logger.Error("no deletion token found for account")
 		return echo.NewHTTPError(400, map[string]interface{}{
 			"error":   "InvalidToken",
 			"message": "Token is invalid",
···
 	}
 
 	if *urepo.Repo.AccountDeleteCode != req.Token {
-		s.logger.Error("deletion token mismatch")
+		logger.Error("deletion token mismatch")
 		return echo.NewHTTPError(400, map[string]interface{}{
 			"error":   "InvalidToken",
 			"message": "Token is invalid",
···
 	}
 
 	if time.Now().UTC().After(*urepo.Repo.AccountDeleteCodeExpiresAt) {
-		s.logger.Error("deletion token expired")
+		logger.Error("deletion token expired")
 		return echo.NewHTTPError(400, map[string]interface{}{
 			"error":   "ExpiredToken",
 			"message": "Token is expired",
···
 
 	tx := s.db.BeginDangerously(ctx)
 	if tx.Error != nil {
-		s.logger.Error("error starting transaction", "error", tx.Error)
+		logger.Error("error starting transaction", "error", tx.Error)
 		return helpers.ServerError(e, nil)
 	}
 
+	status := "error"
+	func() {
+		if status == "error" {
+			if err := tx.Rollback().Error; err != nil {
+				logger.Error("error rolling back after delete failure", "err", err)
+			}
+		}
+	}()
+
 	if err := tx.Exec("DELETE FROM blocks WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting blocks", "error", err)
+		logger.Error("error deleting blocks", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM records WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting records", "error", err)
+		logger.Error("error deleting records", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM blobs WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting blobs", "error", err)
+		logger.Error("error deleting blobs", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM tokens WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting tokens", "error", err)
+		logger.Error("error deleting tokens", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM refresh_tokens WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting refresh tokens", "error", err)
+		logger.Error("error deleting refresh tokens", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM reserved_keys WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting reserved keys", "error", err)
+		logger.Error("error deleting reserved keys", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM invite_codes WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting invite codes", "error", err)
+		logger.Error("error deleting invite codes", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM actors WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting actor", "error", err)
+		logger.Error("error deleting actor", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := tx.Exec("DELETE FROM repos WHERE did = ?", nil, req.Did).Error; err != nil {
-		tx.Rollback()
-		s.logger.Error("error deleting repo", "error", err)
+		logger.Error("error deleting repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
+	status = "ok"
+
 	if err := tx.Commit().Error; err != nil {
-		s.logger.Error("error committing transaction", "error", err)
+		logger.Error("error committing transaction", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_get_service_auth.go

···
 }
 
 func (s *Server) handleServerGetServiceAuth(e echo.Context) error {
+	logger := s.logger.With("name", "handleServerGetServiceAuth")
+
 	var req ServerGetServiceAuthRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("could not bind service auth request", "error", err)
+		logger.Error("could not bind service auth request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	}
 	hj, err := json.Marshal(header)
 	if err != nil {
-		s.logger.Error("error marshaling header", "error", err)
+		logger.Error("error marshaling header", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	}
 	pj, err := json.Marshal(payload)
 	if err != nil {
-		s.logger.Error("error marashaling payload", "error", err)
+		logger.Error("error marashaling payload", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	sk, err := secp256k1secec.NewPrivateKey(repo.SigningKey)
 	if err != nil {
-		s.logger.Error("can't load private key", "error", err)
+		logger.Error("can't load private key", "error", err)
 		return err
 	}
 
 	R, S, _, err := sk.SignRaw(rand.Reader, hash[:])
 	if err != nil {
-		s.logger.Error("error signing", "error", err)
+		logger.Error("error signing", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_refresh_session.go

···
 
 func (s *Server) handleRefreshSession(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerRefreshSession")
 
 	token := e.Get("token").(string)
 	repo := e.Get("repo").(*models.RepoActor)
 
 	if err := s.db.Exec(ctx, "DELETE FROM refresh_tokens WHERE token = ?", nil, token).Error; err != nil {
-		s.logger.Error("error getting refresh token from db", "error", err)
+		logger.Error("error getting refresh token from db", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.db.Exec(ctx, "DELETE FROM tokens WHERE refresh_token = ?", nil, token).Error; err != nil {
-		s.logger.Error("error deleting access token from db", "error", err)
+		logger.Error("error deleting access token from db", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	sess, err := s.createSession(ctx, &repo.Repo)
 	if err != nil {
-		s.logger.Error("error creating new session for refresh", "error", err)
+		logger.Error("error creating new session for refresh", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_request_account_delete.go

···
 
 func (s *Server) handleServerRequestAccountDelete(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerRequestAccountDelete")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 	expiresAt := time.Now().UTC().Add(15 * time.Minute)
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET account_delete_code = ?, account_delete_code_expires_at = ? WHERE did = ?", nil, token, expiresAt, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error setting deletion token", "error", err)
+		logger.Error("error setting deletion token", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if urepo.Email != "" {
 		if err := s.sendAccountDeleteEmail(urepo.Email, urepo.Actor.Handle, token); err != nil {
-			s.logger.Error("error sending account deletion email", "error", err)
+			logger.Error("error sending account deletion email", "error", err)
 		}
 	}
 

server/handle_server_request_email_confirmation.go

···
 
 func (s *Server) handleServerRequestEmailConfirmation(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerRequestEmailConfirm")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 	eat := time.Now().Add(10 * time.Minute).UTC()
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET email_verification_code = ?, email_verification_code_expires_at = ? WHERE did = ?", nil, code, eat, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating user", "error", err)
+		logger.Error("error updating user", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.sendEmailVerification(urepo.Email, urepo.Handle, code); err != nil {
-		s.logger.Error("error sending mail", "error", err)
+		logger.Error("error sending mail", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_request_email_update.go

···
 
 func (s *Server) handleServerRequestEmailUpdate(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerRequestEmailUpdate")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
···
 		eat := time.Now().Add(10 * time.Minute).UTC()
 
 		if err := s.db.Exec(ctx, "UPDATE repos SET email_update_code = ?, email_update_code_expires_at = ? WHERE did = ?", nil, code, eat, urepo.Repo.Did).Error; err != nil {
-			s.logger.Error("error updating repo", "error", err)
+			logger.Error("error updating repo", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
 		if err := s.sendEmailUpdate(urepo.Email, urepo.Handle, code); err != nil {
-			s.logger.Error("error sending email", "error", err)
+			logger.Error("error sending email", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	}

server/handle_server_request_password_reset.go

···
 
 func (s *Server) handleServerRequestPasswordReset(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerRequestPasswordReset")
 
 	urepo, ok := e.Get("repo").(*models.RepoActor)
 	if !ok {
···
 	eat := time.Now().Add(10 * time.Minute).UTC()
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET password_reset_code = ?, password_reset_code_expires_at = ? WHERE did = ?", nil, code, eat, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating repo", "error", err)
+		logger.Error("error updating repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.sendPasswordReset(urepo.Email, urepo.Handle, code); err != nil {
-		s.logger.Error("error sending email", "error", err)
+		logger.Error("error sending email", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_reserve_signing_key.go

···
 
 func (s *Server) handleServerReserveSigningKey(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerReserveSigningKey")
 
 	var req ServerReserveSigningKeyRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("could not bind reserve signing key request", "error", err)
+		logger.Error("could not bind reserve signing key request", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	k, err := atcrypto.GeneratePrivateKeyK256()
 	if err != nil {
-		s.logger.Error("error creating signing key", "endpoint", "com.atproto.server.reserveSigningKey", "error", err)
+		logger.Error("error creating signing key", "endpoint", "com.atproto.server.reserveSigningKey", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	pubKey, err := k.PublicKey()
 	if err != nil {
-		s.logger.Error("error getting public key", "endpoint", "com.atproto.server.reserveSigningKey", "error", err)
+		logger.Error("error getting public key", "endpoint", "com.atproto.server.reserveSigningKey", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	}
 
 	if err := s.db.Create(ctx, &reservedKey, nil).Error; err != nil {
-		s.logger.Error("error storing reserved key", "endpoint", "com.atproto.server.reserveSigningKey", "error", err)
+		logger.Error("error storing reserved key", "endpoint", "com.atproto.server.reserveSigningKey", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
-	s.logger.Info("reserved signing key", "keyDid", keyDid, "forDid", req.Did)
+	logger.Info("reserved signing key", "keyDid", keyDid, "forDid", req.Did)
 
 	return e.JSON(200, ServerReserveSigningKeyResponse{
 		SigningKey: keyDid,

server/handle_server_reset_password.go

···
 
 func (s *Server) handleServerResetPassword(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerResetPassword")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoServerResetPasswordRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 
 	hash, err := bcrypt.GenerateFromPassword([]byte(req.Password), 10)
 	if err != nil {
-		s.logger.Error("error creating hash", "error", err)
+		logger.Error("error creating hash", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET password_reset_code = NULL, password_reset_code_expires_at = NULL, password = ? WHERE did = ?", nil, hash, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating repo", "error", err)
+		logger.Error("error updating repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_resolve_handle.go

···
 )
 
 func (s *Server) handleResolveHandle(e echo.Context) error {
+	logger := s.logger.With("name", "handleServerResolveHandle")
+
 	type Resp struct {
 		Did string `json:"did"`
 	}
···
 	ctx := context.WithValue(e.Request().Context(), "skip-cache", true)
 	did, err := s.passport.ResolveHandle(ctx, parsed.String())
 	if err != nil {
-		s.logger.Error("error resolving handle", "error", err)
+		logger.Error("error resolving handle", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_server_update_email.go

···
 
 func (s *Server) handleServerUpdateEmail(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleServerUpdateEmail")
 
 	urepo := e.Get("repo").(*models.RepoActor)
 
 	var req ComAtprotoServerUpdateEmailRequest
 	if err := e.Bind(&req); err != nil {
-		s.logger.Error("error binding", "error", err)
+		logger.Error("error binding", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	}
 
 	if err := s.db.Exec(ctx, "UPDATE repos SET email_update_code = NULL, email_update_code_expires_at = NULL, email_confirmed_at = NULL,  email = ? WHERE did = ?", nil, req.Email, urepo.Repo.Did).Error; err != nil {
-		s.logger.Error("error updating repo", "error", err)
+		logger.Error("error updating repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_sync_get_blob.go

···
 
 func (s *Server) handleSyncGetBlob(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleSyncGetBlob")
 
 	did := e.QueryParam("did")
 	if did == "" {
···
 
 	urepo, err := s.getRepoActorByDid(ctx, did)
 	if err != nil {
-		s.logger.Error("could not find user for requested blob", "error", err)
+		logger.Error("could not find user for requested blob", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 
 	var blob models.Blob
 	if err := s.db.Raw(ctx, "SELECT * FROM blobs WHERE did = ? AND cid = ?", nil, did, c.Bytes()).Scan(&blob).Error; err != nil {
-		s.logger.Error("error looking up blob", "error", err)
+		logger.Error("error looking up blob", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	if blob.Storage == "sqlite" {
 		var parts []models.BlobPart
 		if err := s.db.Raw(ctx, "SELECT * FROM blob_parts WHERE blob_id = ? ORDER BY idx", nil, blob.ID).Scan(&parts).Error; err != nil {
-			s.logger.Error("error getting blob parts", "error", err)
+			logger.Error("error getting blob parts", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 		}
 	} else if blob.Storage == "s3" {
 		if !(s.s3Config != nil && s.s3Config.BlobstoreEnabled) {
-			s.logger.Error("s3 storage disabled")
+			logger.Error("s3 storage disabled")
 			return helpers.ServerError(e, nil)
 		}
 
···
 
 		sess, err := session.NewSession(config)
 		if err != nil {
-			s.logger.Error("error creating aws session", "error", err)
+			logger.Error("error creating aws session", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 
···
 			Bucket: aws.String(s.s3Config.Bucket),
 			Key:    aws.String(blobKey),
 		}); err != nil {
-			s.logger.Error("error getting blob from s3", "error", err)
+			logger.Error("error getting blob from s3", "error", err)
 			return helpers.ServerError(e, nil)
 		} else {
 			read := 0
···
 						break
 					}
 				} else if err != nil && err != io.ErrUnexpectedEOF {
-					s.logger.Error("error reading blob", "error", err)
+					logger.Error("error reading blob", "error", err)
 					return helpers.ServerError(e, nil)
 				}
 
···
 			}
 		}
 	} else {
-		s.logger.Error("unknown storage", "storage", blob.Storage)
+		logger.Error("unknown storage", "storage", blob.Storage)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_sync_get_blocks.go

···
 
 func (s *Server) handleGetBlocks(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleSyncGetBlocks")
 
 	var req ComAtprotoSyncGetBlocksRequest
 	if err := e.Bind(&req); err != nil {
···
 	})
 
 	if _, err := carstore.LdWrite(buf, hb); err != nil {
-		s.logger.Error("error writing to car", "error", err)
+		logger.Error("error writing to car", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_sync_get_record.go

···
 
 func (s *Server) handleSyncGetRecord(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleSyncGetRecord")
 
 	did := e.QueryParam("did")
 	collection := e.QueryParam("collection")
···
 
 	var urepo models.Repo
 	if err := s.db.Raw(ctx, "SELECT * FROM repos WHERE did = ?", nil, did).Scan(&urepo).Error; err != nil {
-		s.logger.Error("error getting repo", "error", err)
+		logger.Error("error getting repo", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	})
 
 	if _, err := carstore.LdWrite(buf, hb); err != nil {
-		s.logger.Error("error writing to car", "error", err)
+		logger.Error("error writing to car", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
 	for _, blk := range blocks {
 		if _, err := carstore.LdWrite(buf, blk.Cid().Bytes(), blk.RawData()); err != nil {
-			s.logger.Error("error writing to car", "error", err)
+			logger.Error("error writing to car", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 	}

server/handle_sync_get_repo.go

···
 
 func (s *Server) handleSyncGetRepo(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleSyncGetRepo")
 
 	did := e.QueryParam("did")
 	if did == "" {
···
 	buf := new(bytes.Buffer)
 
 	if _, err := carstore.LdWrite(buf, hb); err != nil {
-		s.logger.Error("error writing to car", "error", err)
+		logger.Error("error writing to car", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/handle_sync_list_blobs.go

···
 
 func (s *Server) handleSyncListBlobs(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleSyncListBlobs")
 
 	did := e.QueryParam("did")
 	if did == "" {
···
 
 	urepo, err := s.getRepoActorByDid(ctx, did)
 	if err != nil {
-		s.logger.Error("could not find user for requested blobs", "error", err)
+		logger.Error("could not find user for requested blobs", "error", err)
 		return helpers.InputError(e, nil)
 	}
 
···
 
 	var blobs []models.Blob
 	if err := s.db.Raw(ctx, "SELECT * FROM blobs WHERE did = ? "+cursorquery+" ORDER BY created_at DESC LIMIT ?", nil, params...).Scan(&blobs).Error; err != nil {
-		s.logger.Error("error getting records", "error", err)
+		logger.Error("error getting records", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 
···
 	for _, b := range blobs {
 		c, err := cid.Cast(b.Cid)
 		if err != nil {
-			s.logger.Error("error casting cid", "error", err)
+			logger.Error("error casting cid", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 		cstrs = append(cstrs, c.String())

server/handle_sync_subscribe_repos.go

···
 	"github.com/bluesky-social/indigo/events"
 	"github.com/bluesky-social/indigo/lex/util"
 	"github.com/btcsuite/websocket"
+	"github.com/haileyok/cocoon/metrics"
 	"github.com/labstack/echo/v4"
 )
 
···
 	logger = logger.With("ident", ident)
 	logger.Info("new connection established")
 
+	metrics.RelaysConnected.WithLabelValues(ident).Inc()
+	defer func() {
+		metrics.RelaysConnected.WithLabelValues(ident).Dec()
+	}()
+
 	evts, cancel, err := s.evtman.Subscribe(ctx, ident, func(evt *events.XRPCStreamEvent) bool {
 		return true
 	}, nil)
···
 
 	header := events.EventHeader{Op: events.EvtKindMessage}
 	for evt := range evts {
-		wc, err := conn.NextWriter(websocket.BinaryMessage)
-		if err != nil {
-			logger.Error("error writing message to relay", "err", err)
-			break
-		}
+		func() {
+			defer func() {
+				metrics.RelaySends.WithLabelValues(header.MsgType).Inc()
+			}()
 
-		if ctx.Err() != nil {
-			logger.Error("context error", "err", err)
-			break
-		}
+			wc, err := conn.NextWriter(websocket.BinaryMessage)
+			if err != nil {
+				logger.Error("error writing message to relay", "err", err)
+				return
+			}
 
-		var obj util.CBOR
-		switch {
-		case evt.Error != nil:
-			header.Op = events.EvtKindErrorFrame
-			obj = evt.Error
-		case evt.RepoCommit != nil:
-			header.MsgType = "#commit"
-			obj = evt.RepoCommit
-		case evt.RepoIdentity != nil:
-			header.MsgType = "#identity"
-			obj = evt.RepoIdentity
-		case evt.RepoAccount != nil:
-			header.MsgType = "#account"
-			obj = evt.RepoAccount
-		case evt.RepoInfo != nil:
-			header.MsgType = "#info"
-			obj = evt.RepoInfo
-		default:
-			logger.Warn("unrecognized event kind")
-			return nil
-		}
+			if ctx.Err() != nil {
+				logger.Error("context error", "err", err)
+				return
+			}
 
-		if err := header.MarshalCBOR(wc); err != nil {
-			logger.Error("failed to write header to relay", "err", err)
-			break
-		}
+			var obj util.CBOR
+			switch {
+			case evt.Error != nil:
+				header.Op = events.EvtKindErrorFrame
+				obj = evt.Error
+			case evt.RepoCommit != nil:
+				header.MsgType = "#commit"
+				obj = evt.RepoCommit
+			case evt.RepoIdentity != nil:
+				header.MsgType = "#identity"
+				obj = evt.RepoIdentity
+			case evt.RepoAccount != nil:
+				header.MsgType = "#account"
+				obj = evt.RepoAccount
+			case evt.RepoInfo != nil:
+				header.MsgType = "#info"
+				obj = evt.RepoInfo
+			default:
+				logger.Warn("unrecognized event kind")
+				return
+			}
 
-		if err := obj.MarshalCBOR(wc); err != nil {
-			logger.Error("failed to write event to relay", "err", err)
-			break
-		}
+			if err := header.MarshalCBOR(wc); err != nil {
+				logger.Error("failed to write header to relay", "err", err)
+				return
+			}
 
-		if err := wc.Close(); err != nil {
-			logger.Error("failed to flush-close our event write", "err", err)
-			break
-		}
+			if err := obj.MarshalCBOR(wc); err != nil {
+				logger.Error("failed to write event to relay", "err", err)
+				return
+			}
+
+			if err := wc.Close(); err != nil {
+				logger.Error("failed to flush-close our event write", "err", err)
+				return
+			}
+		}()
 	}
 
 	// we should tell the relay to request a new crawl at this point if we got disconnected

server/handle_well_known.go

···
 
 func (s *Server) handleAtprotoDid(e echo.Context) error {
 	ctx := e.Request().Context()
+	logger := s.logger.With("name", "handleAtprotoDid")
 
 	host := e.Request().Host
 	if host == "" {
···
 		if err == gorm.ErrRecordNotFound {
 			return e.NoContent(404)
 		}
-		s.logger.Error("error looking up actor by handle", "error", err)
+		logger.Error("error looking up actor by handle", "error", err)
 		return helpers.ServerError(e, nil)
 	}
 

server/middleware.go

···
 func (s *Server) handleLegacySessionMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
 	return func(e echo.Context) error {
 		ctx := e.Request().Context()
+		logger := s.logger.With("name", "handleLegacySessionMiddleware")
 
 		authheader := e.Request().Header.Get("authorization")
 		if authheader == "" {
···
 		if hasLxm {
 			pts := strings.Split(e.Request().URL.String(), "/")
 			if lxm != pts[len(pts)-1] {
-				s.logger.Error("service auth lxm incorrect", "lxm", lxm, "expected", pts[len(pts)-1], "error", err)
+				logger.Error("service auth lxm incorrect", "lxm", lxm, "expected", pts[len(pts)-1], "error", err)
 				return helpers.InputError(e, nil)
 			}
 
 			maybeDid, ok := claims["iss"].(string)
 			if !ok {
-				s.logger.Error("no iss in service auth token", "error", err)
+				logger.Error("no iss in service auth token", "error", err)
 				return helpers.InputError(e, nil)
 			}
 			did = maybeDid
 
 			maybeRepo, err := s.getRepoActorByDid(ctx, did)
 			if err != nil {
-				s.logger.Error("error fetching repo", "error", err)
+				logger.Error("error fetching repo", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 			repo = maybeRepo
···
 				return s.privateKey.Public(), nil
 			})
 			if err != nil {
-				s.logger.Error("error parsing jwt", "error", err)
+				logger.Error("error parsing jwt", "error", err)
 				return helpers.ExpiredTokenError(e)
 			}
 
···
 			hash := sha256.Sum256([]byte(signingInput))
 			sigBytes, err := base64.RawURLEncoding.DecodeString(kpts[2])
 			if err != nil {
-				s.logger.Error("error decoding signature bytes", "error", err)
+				logger.Error("error decoding signature bytes", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 
 			if len(sigBytes) != 64 {
-				s.logger.Error("incorrect sigbytes length", "length", len(sigBytes))
+				logger.Error("incorrect sigbytes length", "length", len(sigBytes))
 				return helpers.ServerError(e, nil)
 			}
 
···
 
 			sk, err := secp256k1secec.NewPrivateKey(repo.SigningKey)
 			if err != nil {
-				s.logger.Error("can't load private key", "error", err)
+				logger.Error("can't load private key", "error", err)
 				return err
 			}
 
 			pubKey, ok := sk.Public().(*secp256k1secec.PublicKey)
 			if !ok {
-				s.logger.Error("error getting public key from sk")
+				logger.Error("error getting public key from sk")
 				return helpers.ServerError(e, nil)
 			}
 
 			verified := pubKey.VerifyRaw(hash[:], rr, ss)
 			if !verified {
-				s.logger.Error("error verifying", "error", err)
+				logger.Error("error verifying", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 		}
···
 					return helpers.InvalidTokenError(e)
 				}
 
-				s.logger.Error("error getting token from db", "error", err)
+				logger.Error("error getting token from db", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 
···
 
 		exp, ok := claims["exp"].(float64)
 		if !ok {
-			s.logger.Error("error getting iat from token")
+			logger.Error("error getting iat from token")
 			return helpers.ServerError(e, nil)
 		}
 
···
 		if repo == nil {
 			maybeRepo, err := s.getRepoActorByDid(ctx, claims["sub"].(string))
 			if err != nil {
-				s.logger.Error("error fetching repo", "error", err)
+				logger.Error("error fetching repo", "error", err)
 				return helpers.ServerError(e, nil)
 			}
 			repo = maybeRepo
···
 func (s *Server) handleOauthSessionMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
 	return func(e echo.Context) error {
 		ctx := e.Request().Context()
+		logger := s.logger.With("name", "handleOauthSessionMiddleware")
 
 		authheader := e.Request().Header.Get("authorization")
 		if authheader == "" {
···
 					"error": "use_dpop_nonce",
 				})
 			}
-			s.logger.Error("invalid dpop proof", "error", err)
+			logger.Error("invalid dpop proof", "error", err)
 			return helpers.InputError(e, nil)
 		}
 
 		var oauthToken provider.OauthToken
 		if err := s.db.Raw(ctx, "SELECT * FROM oauth_tokens WHERE token = ?", nil, accessToken).Scan(&oauthToken).Error; err != nil {
-			s.logger.Error("error finding access token in db", "error", err)
+			logger.Error("error finding access token in db", "error", err)
 			return helpers.InputError(e, nil)
 		}
 
···
 		}
 
 		if *oauthToken.Parameters.DpopJkt != proof.JKT {
-			s.logger.Error("jkt mismatch", "token", oauthToken.Parameters.DpopJkt, "proof", proof.JKT)
+			logger.Error("jkt mismatch", "token", oauthToken.Parameters.DpopJkt, "proof", proof.JKT)
 			return helpers.InputError(e, to.StringPtr("dpop jkt mismatch"))
 		}
 
···
 
 		repo, err := s.getRepoActorByDid(ctx, oauthToken.Sub)
 		if err != nil {
-			s.logger.Error("could not find actor in db", "error", err)
+			logger.Error("could not find actor in db", "error", err)
 			return helpers.ServerError(e, nil)
 		}
 

server/repo.go

···
 	lexutil "github.com/bluesky-social/indigo/lex/util"
 	"github.com/bluesky-social/indigo/repo"
 	"github.com/haileyok/cocoon/internal/db"
+	"github.com/haileyok/cocoon/metrics"
 	"github.com/haileyok/cocoon/models"
 	"github.com/haileyok/cocoon/recording_blockstore"
 	blocks "github.com/ipfs/go-block-format"
···
 	newroot, rev, err := r.Commit(ctx, urepo.SignFor)
 	if err != nil {
 		return nil, err
+	}
+
+	for _, result := range results {
+		if result.Type != nil {
+			metrics.RepoOperations.WithLabelValues(*result.Type).Inc()
+		}
 	}
 
 	// create a buffer for dumping our new cbor into

server/server.go

···
 	"github.com/haileyok/cocoon/oauth/provider"
 	"github.com/haileyok/cocoon/plc"
 	"github.com/ipfs/go-cid"
+	"github.com/labstack/echo-contrib/echoprometheus"
 	echo_session "github.com/labstack/echo-contrib/session"
 	"github.com/labstack/echo/v4"
 	"github.com/labstack/echo/v4/middleware"
···
 }
 
 type Args struct {
+	Logger *slog.Logger
+
 	Addr            string
 	DbName          string
 	DbType          string
 	DatabaseURL     string
-	Logger          *slog.Logger
 	Version         string
 	Did             string
 	Hostname        string
···
 }
 
 func New(args *Args) (*Server, error) {
+	if args.Logger == nil {
+		args.Logger = slog.Default()
+	}
+
+	logger := args.Logger.With("name", "New")
+
 	if args.Addr == "" {
 		return nil, fmt.Errorf("addr must be set")
 	}
···
 		return nil, fmt.Errorf("admin password must be set")
 	}
 
-	if args.Logger == nil {
-		args.Logger = slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{}))
-	}
-
 	if args.SessionSecret == "" {
 		panic("SESSION SECRET WAS NOT SET. THIS IS REQUIRED. ")
 	}
···
 	e := echo.New()
 
 	e.Pre(middleware.RemoveTrailingSlash())
-	e.Pre(slogecho.New(args.Logger))
+	e.Pre(slogecho.New(args.Logger.With("component", "slogecho")))
 	e.Use(echo_session.Middleware(sessions.NewCookieStore([]byte(args.SessionSecret))))
+	e.Use(echoprometheus.NewMiddleware("cocoon"))
 	e.Use(middleware.CORSWithConfig(middleware.CORSConfig{
 		AllowOrigins:     []string{"*"},
 		AllowHeaders:     []string{"*"},
···
 		if err != nil {
 			return nil, fmt.Errorf("failed to connect to postgres: %w", err)
 		}
-		args.Logger.Info("connected to PostgreSQL database")
+		logger.Info("connected to PostgreSQL database")
 	default:
 		gdb, err = gorm.Open(sqlite.Open(args.DbName), &gorm.Config{})
 		if err != nil {
 			return nil, fmt.Errorf("failed to open sqlite database: %w", err)
 		}
-		args.Logger.Info("connected to SQLite database", "path", args.DbName)
+		logger.Info("connected to SQLite database", "path", args.DbName)
 	}
 	dbw := db.NewDB(gdb)
 
···
 	var nonceSecret []byte
 	maybeSecret, err := os.ReadFile("nonce.secret")
 	if err != nil && !os.IsNotExist(err) {
-		args.Logger.Error("error attempting to read nonce secret", "error", err)
+		logger.Error("error attempting to read nonce secret", "error", err)
 	} else {
 		nonceSecret = maybeSecret
 	}
···
 			Hostname: args.Hostname,
 			ClientManagerArgs: client.ManagerArgs{
 				Cli:    oauthCli,
-				Logger: args.Logger,
+				Logger: args.Logger.With("component", "oauth-client-manager"),
 			},
 			DpopManagerArgs: dpop.ManagerArgs{
 				NonceSecret:           nonceSecret,
 				NonceRotationInterval: constants.NonceMaxRotationInterval / 3,
 				OnNonceSecretCreated: func(newNonce []byte) {
 					if err := os.WriteFile("nonce.secret", newNonce, 0644); err != nil {
-						args.Logger.Error("error writing new nonce secret", "error", err)
+						logger.Error("error writing new nonce secret", "error", err)
 					}
 				},
-				Logger:   args.Logger,
+				Logger:   args.Logger.With("component", "dpop-manager"),
 				Hostname: args.Hostname,
 			},
 		}),
···
 }
 
 func (s *Server) Serve(ctx context.Context) error {
+	logger := s.logger.With("name", "Serve")
+
 	s.addRoutes()
 
-	s.logger.Info("migrating...")
+	logger.Info("migrating...")
 
 	s.db.AutoMigrate(
 		&models.Actor{},
···
 		&provider.OauthAuthorizationRequest{},
 	)
 
-	s.logger.Info("starting cocoon")
+	logger.Info("starting cocoon")
 
 	go func() {
 		if err := s.httpd.ListenAndServe(); err != nil {
···
 
 	go func() {
 		if err := s.requestCrawl(ctx); err != nil {
-			s.logger.Error("error requesting crawls", "err", err)
+			logger.Error("error requesting crawls", "err", err)
 		}
 	}()
 
···
 
 	logger.Info("requesting crawl with configured relays")
 
-	if time.Now().Sub(s.lastRequestCrawl) <= 1*time.Minute {
+	if time.Since(s.lastRequestCrawl) <= 1*time.Minute {
 		return fmt.Errorf("a crawl request has already been made within the last minute")
 	}
 
···
 }
 
 func (s *Server) doBackup() {
+	logger := s.logger.With("name", "doBackup")
+
 	if s.dbType == "postgres" {
-		s.logger.Info("skipping S3 backup - PostgreSQL backups should be handled externally (pg_dump, managed database backups, etc.)")
+		logger.Info("skipping S3 backup - PostgreSQL backups should be handled externally (pg_dump, managed database backups, etc.)")
 		return
 	}
 
 	start := time.Now()
 
-	s.logger.Info("beginning backup to s3...")
+	logger.Info("beginning backup to s3...")
 
 	var buf bytes.Buffer
 	if err := func() error {
-		s.logger.Info("reading database bytes...")
+		logger.Info("reading database bytes...")
 		s.db.Lock()
 		defer s.db.Unlock()
 
···
 
 		return nil
 	}(); err != nil {
-		s.logger.Error("error backing up database", "error", err)
+		logger.Error("error backing up database", "error", err)
 		return
 	}
 
 	if err := func() error {
-		s.logger.Info("sending to s3...")
+		logger.Info("sending to s3...")
 
 		currTime := time.Now().Format("2006-01-02_15-04-05")
 		key := "cocoon-backup-" + currTime + ".db"
···
 			return fmt.Errorf("error uploading file to s3: %w", err)
 		}
 
-		s.logger.Info("finished uploading backup to s3", "key", key, "duration", time.Now().Sub(start).Seconds())
+		logger.Info("finished uploading backup to s3", "key", key, "duration", time.Now().Sub(start).Seconds())
 
 		return nil
 	}(); err != nil {
-		s.logger.Error("error uploading database backup", "error", err)
+		logger.Error("error uploading database backup", "error", err)
 		return
 	}
 
···
 }
 
 func (s *Server) backupRoutine() {
+	logger := s.logger.With("name", "backupRoutine")
+
 	if s.s3Config == nil || !s.s3Config.BackupsEnabled {
 		return
 	}
 
 	if s.s3Config.Region == "" {
-		s.logger.Warn("no s3 region configured but backups are enabled. backups will not run.")
+		logger.Warn("no s3 region configured but backups are enabled. backups will not run.")
 		return
 	}
 
 	if s.s3Config.Bucket == "" {
-		s.logger.Warn("no s3 bucket configured but backups are enabled. backups will not run.")
+		logger.Warn("no s3 bucket configured but backups are enabled. backups will not run.")
 		return
 	}
 
 	if s.s3Config.AccessKey == "" {
-		s.logger.Warn("no s3 access key configured but backups are enabled. backups will not run.")
+		logger.Warn("no s3 access key configured but backups are enabled. backups will not run.")
 		return
 	}
 
 	if s.s3Config.SecretKey == "" {
-		s.logger.Warn("no s3 secret key configured but backups are enabled. backups will not run.")
+		logger.Warn("no s3 secret key configured but backups are enabled. backups will not run.")
 		return
 	}
 

test.go

···
 
 	u.Path = "xrpc/com.atproto.sync.subscribeRepos"
 	conn, _, err := dialer.Dial(u.String(), http.Header{
-		"User-Agent": []string{fmt.Sprintf("hot-topic/0.0.0")},
+		"User-Agent": []string{"cocoon-test/0.0.0"},
 	})
 	if err != nil {
 		return fmt.Errorf("subscribing to firehose failed (dialing): %w", err)