Update dependencies and lots of code

* Bump minimum Go version to 1.21
* Add contexts everywhere
* Switch database code to new dbutil patterns
* Finish switching away from maulogger

.github/workflows/go.yml

@@ -8,7 +8,8 @@ jobs:
     strategy:
       fail-fast: false
       matrix:
-        go-version: ["1.20", "1.21"]
+        go-version: ["1.21", "1.22"]
+    name: Lint ${{ matrix.go-version == '1.22' && '(latest)' || '(old)' }}
 
     steps:
       - uses: actions/checkout@v4

.pre-commit-config.yaml

@@ -15,6 +15,6 @@ repos:
       - id: go-vet-repo-mod
 
   - repo: https://github.com/beeper/pre-commit-go
-    rev: v0.2.2
+    rev: v0.3.1
     hooks:
       - id: zerolog-ban-msgf

CHANGELOG.md

@@ -1,3 +1,9 @@
+# v0.10.6 (unreleased)
+
+* Bumped minimum Go version to 1.21.
+* Added 8-letter code pairing support to provisioning API.
+* Added more bugs to fix later.
+
 # v0.10.5 (2023-12-16)
 
 * Added support for sending media to channels.

analytics.go

@@ -22,15 +22,15 @@ import (
 	"fmt"
 	"net/http"
 
-	log "maunium.net/go/maulogger/v2"
+	"github.com/rs/zerolog"
 	"maunium.net/go/mautrix/id"
 )
 
 type AnalyticsClient struct {
 	url    string
 	key    string
 	userID string
-	log    log.Logger
+	log    zerolog.Logger
 	client http.Client
 }
 
@@ -88,9 +88,9 @@ func (sc *AnalyticsClient) Track(userID id.UserID, event string, properties ...m
 		props["bridge"] = "whatsapp"
 		err := sc.trackSync(userID, event, props)
 		if err != nil {
-			sc.log.Errorfln("Error tracking %s: %v", event, err)
+			sc.log.Err(err).Str("event", event).Msg("Error tracking event")
 		} else {
-			sc.log.Debugln("Tracked", event)
+			sc.log.Debug().Str("event", event).Msg("Tracked event")
 		}
 	}()
 }

backfillqueue.go

@@ -1,5 +1,5 @@
 // mautrix-whatsapp - A Matrix-WhatsApp puppeting bridge.
-// Copyright (C) 2021 Tulir Asokan, Sumner Evans
+// Copyright (C) 2024 Tulir Asokan, Sumner Evans
 //
 // This program is free software: you can redistribute it and/or modify
 // it under the terms of the GNU Affero General Public License as published by
@@ -17,35 +17,41 @@
 package main
 
 import (
+	"context"
 	"time"
 
-	log "maunium.net/go/maulogger/v2"
+	"github.com/rs/zerolog"
 	"maunium.net/go/mautrix/id"
 
 	"maunium.net/go/mautrix-whatsapp/database"
 )
 
 type BackfillQueue struct {
-	BackfillQuery   *database.BackfillQuery
+	BackfillQuery   *database.BackfillTaskQuery
 	reCheckChannels []chan bool
-	log             log.Logger
 }
 
 func (bq *BackfillQueue) ReCheck() {
-	bq.log.Infofln("Sending re-checks to %d channels", len(bq.reCheckChannels))
 	for _, channel := range bq.reCheckChannels {
 		go func(c chan bool) {
 			c <- true
 		}(channel)
 	}
 }
 
-func (bq *BackfillQueue) GetNextBackfill(userID id.UserID, backfillTypes []database.BackfillType, waitForBackfillTypes []database.BackfillType, reCheckChannel chan bool) *database.Backfill {
+func (bq *BackfillQueue) GetNextBackfill(ctx context.Context, userID id.UserID, backfillTypes []database.BackfillType, waitForBackfillTypes []database.BackfillType, reCheckChannel chan bool) *database.BackfillTask {
 	for {
-		if !bq.BackfillQuery.HasUnstartedOrInFlightOfType(userID, waitForBackfillTypes) {
+		if !bq.BackfillQuery.HasUnstartedOrInFlightOfType(ctx, userID, waitForBackfillTypes) {
 			// check for immediate when dealing with deferred
-			if backfill := bq.BackfillQuery.GetNext(userID, backfillTypes); backfill != nil {
-				backfill.MarkDispatched()
+			if backfill, err := bq.BackfillQuery.GetNext(ctx, userID, backfillTypes); err != nil {
+				zerolog.Ctx(ctx).Err(err).Msg("Failed to get next backfill task")
+			} else if backfill != nil {
+				err = backfill.MarkDispatched(ctx)
+				if err != nil {
+					zerolog.Ctx(ctx).Warn().Err(err).
+						Int("queue_id", backfill.QueueID).
+						Msg("Failed to mark backfill task as dispatched")
+				}
 				return backfill
 			}
 		}
@@ -58,38 +64,73 @@ func (bq *BackfillQueue) GetNextBackfill(userID id.UserID, backfillTypes []datab
 }
 
 func (user *User) HandleBackfillRequestsLoop(backfillTypes []database.BackfillType, waitForBackfillTypes []database.BackfillType) {
+	log := user.zlog.With().
+		Str("action", "backfill request loop").
+		Any("types", backfillTypes).
+		Logger()
+	ctx := log.WithContext(context.TODO())
 	reCheckChannel := make(chan bool)
 	user.BackfillQueue.reCheckChannels = append(user.BackfillQueue.reCheckChannels, reCheckChannel)
 
 	for {
-		req := user.BackfillQueue.GetNextBackfill(user.MXID, backfillTypes, waitForBackfillTypes, reCheckChannel)
-		user.log.Infofln("Handling backfill request %s", req)
+		req := user.BackfillQueue.GetNextBackfill(ctx, user.MXID, backfillTypes, waitForBackfillTypes, reCheckChannel)
+		log.Info().Any("backfill_request", req).Msg("Handling backfill request")
+		log := log.With().
+			Int("queue_id", req.QueueID).
+			Stringer("portal_jid", req.Portal.JID).
+			Logger()
+		ctx := log.WithContext(ctx)
 
-		conv := user.bridge.DB.HistorySync.GetConversation(user.MXID, *req.Portal)
-		if conv == nil {
-			user.log.Debugfln("Could not find history sync conversation data for %s", req.Portal.String())
-			req.MarkDone()
+		conv, err := user.bridge.DB.HistorySync.GetConversation(ctx, user.MXID, req.Portal)
+		if err != nil {
+			log.Err(err).Msg("Failed to get conversation data for backfill request")
+			continue
+		} else if conv == nil {
+			log.Debug().Msg("Couldn't find conversation data for backfill request")
+			err = req.MarkDone(ctx)
+			if err != nil {
+				log.Err(err).Msg("Failed to mark backfill request as done after data was not found")
+			}
 			continue
 		}
 		portal := user.GetPortalByJID(conv.PortalKey.JID)
 
 		// Update the client store with basic chat settings.
 		if conv.MuteEndTime.After(time.Now()) {
-			user.Client.Store.ChatSettings.PutMutedUntil(conv.PortalKey.JID, conv.MuteEndTime)
+			err = user.Client.Store.ChatSettings.PutMutedUntil(conv.PortalKey.JID, conv.MuteEndTime)
+			if err != nil {
+				log.Err(err).Msg("Failed to save muted until time from conversation data")
+			}
 		}
 		if conv.Archived {
-			user.Client.Store.ChatSettings.PutArchived(conv.PortalKey.JID, true)
+			err = user.Client.Store.ChatSettings.PutArchived(conv.PortalKey.JID, true)
+			if err != nil {
+				log.Err(err).Msg("Failed to save archived state from conversation data")
+			}
 		}
 		if conv.Pinned > 0 {
-			user.Client.Store.ChatSettings.PutPinned(conv.PortalKey.JID, true)
+			err = user.Client.Store.ChatSettings.PutPinned(conv.PortalKey.JID, true)
+			if err != nil {
+				log.Err(err).Msg("Failed to save pinned state from conversation data")
+			}
 		}
 
 		if conv.EphemeralExpiration != nil && portal.ExpirationTime != *conv.EphemeralExpiration {
+			log.Debug().
+				Uint32("old_time", portal.ExpirationTime).
+				Uint32("new_time", *conv.EphemeralExpiration).
+				Msg("Updating portal ephemeral expiration time")
 			portal.ExpirationTime = *conv.EphemeralExpiration
-			portal.Update(nil)
+			err = portal.Update(ctx)
+			if err != nil {
+				log.Err(err).Msg("Failed to save portal after updating expiration time")
+			}
 		}
 
-		user.backfillInChunks(req, conv, portal)
-		req.MarkDone()
+		user.backfillInChunks(ctx, req, conv, portal)
+		err = req.MarkDone(ctx)
+		if err != nil {
+			log.Err(err).Msg("Failed to mark backfill request as done after backfilling")
+		}
 	}
 }

bridgestate.go

@@ -93,7 +93,7 @@ func (prov *ProvisioningAPI) BridgeStatePing(w http.ResponseWriter, r *http.Requ
 		remote = remote.Fill(user)
 		resp.RemoteStates[remote.RemoteID] = remote
 	}
-	user.log.Debugfln("Responding bridge state in bridge status endpoint: %+v", resp)
+	user.zlog.Debug().Any("response_data", &resp).Msg("Responding bridge state in bridge status endpoint")
 	jsonResponse(w, http.StatusOK, &resp)
 	if len(resp.RemoteStates) > 0 {
 		user.BridgeState.SetPrev(remote)