From 100fa9b2354efa05b4fbff3a3cb745ea7783d41c Mon Sep 17 00:00:00 2001 From: Till <2353100+S7evinK@users.noreply.github.com> Date: Tue, 13 Sep 2022 08:07:43 +0200 Subject: [PATCH 1/3] Check unique constraint errors when manually inserting migrations (#2712) This should avoid unnecessary logging on startup if the migration (were we need `InsertMigration`) was already executed. This now checks for "unique constraint errors" for SQLite and Postgres and fails the startup process if the migration couldn't be manually inserted for some other reason. --- internal/sqlutil/migrate.go | 5 +++++ ...{postgres_wasm.go => unique_constraint.go} | 21 ++++++++++++++++--- ...{postgres.go => unique_constraint_wasm.go} | 17 +++++++++------ .../storage/postgres/key_changes_table.go | 6 ++---- .../storage/sqlite3/key_changes_table.go | 6 ++---- roomserver/storage/postgres/storage.go | 5 +---- roomserver/storage/sqlite3/storage.go | 4 +--- 7 files changed, 40 insertions(+), 24 deletions(-) rename internal/sqlutil/{postgres_wasm.go => unique_constraint.go} (62%) rename internal/sqlutil/{postgres.go => unique_constraint_wasm.go} (74%) diff --git a/internal/sqlutil/migrate.go b/internal/sqlutil/migrate.go index 98e7d8938..b6a8b1f25 100644 --- a/internal/sqlutil/migrate.go +++ b/internal/sqlutil/migrate.go @@ -155,5 +155,10 @@ func InsertMigration(ctx context.Context, db *sql.DB, migrationName string) erro time.Now().Format(time.RFC3339), internal.VersionString(), ) + // If the migration was already executed, we'll get a unique constraint error, + // return nil instead, to avoid unnecessary logging. + if IsUniqueConstraintViolationErr(err) { + return nil + } return err } diff --git a/internal/sqlutil/postgres_wasm.go b/internal/sqlutil/unique_constraint.go similarity index 62% rename from internal/sqlutil/postgres_wasm.go rename to internal/sqlutil/unique_constraint.go index 34086f450..4a1b7fd94 100644 --- a/internal/sqlutil/postgres_wasm.go +++ b/internal/sqlutil/unique_constraint.go @@ -12,12 +12,27 @@ // See the License for the specific language governing permissions and // limitations under the License. -//go:build wasm -// +build wasm +//go:build !wasm +// +build !wasm package sqlutil -// IsUniqueConstraintViolationErr no-ops for this architecture +import ( + "github.com/lib/pq" + "github.com/mattn/go-sqlite3" +) + +// IsUniqueConstraintViolationErr returns true if the error is an unique_violation error func IsUniqueConstraintViolationErr(err error) bool { + switch e := err.(type) { + case *pq.Error: + return e.Code == "23505" + case pq.Error: + return e.Code == "23505" + case *sqlite3.Error: + return e.Code == sqlite3.ErrConstraint + case sqlite3.Error: + return e.Code == sqlite3.ErrConstraint + } return false } diff --git a/internal/sqlutil/postgres.go b/internal/sqlutil/unique_constraint_wasm.go similarity index 74% rename from internal/sqlutil/postgres.go rename to internal/sqlutil/unique_constraint_wasm.go index 5e656b1da..02ceb5851 100644 --- a/internal/sqlutil/postgres.go +++ b/internal/sqlutil/unique_constraint_wasm.go @@ -12,15 +12,20 @@ // See the License for the specific language governing permissions and // limitations under the License. -//go:build !wasm -// +build !wasm +//go:build wasm +// +build wasm package sqlutil -import "github.com/lib/pq" +import "github.com/mattn/go-sqlite3" -// IsUniqueConstraintViolationErr returns true if the error is a postgresql unique_violation error +// IsUniqueConstraintViolationErr returns true if the error is an unique_violation error func IsUniqueConstraintViolationErr(err error) bool { - pqErr, ok := err.(*pq.Error) - return ok && pqErr.Code == "23505" + switch e := err.(type) { + case *sqlite3.Error: + return e.Code == sqlite3.ErrConstraint + case sqlite3.Error: + return e.Code == sqlite3.ErrConstraint + } + return false } diff --git a/keyserver/storage/postgres/key_changes_table.go b/keyserver/storage/postgres/key_changes_table.go index e91b048d5..c0e3429c7 100644 --- a/keyserver/storage/postgres/key_changes_table.go +++ b/keyserver/storage/postgres/key_changes_table.go @@ -18,8 +18,7 @@ import ( "context" "database/sql" "errors" - - "github.com/sirupsen/logrus" + "fmt" "github.com/matrix-org/dendrite/internal" "github.com/matrix-org/dendrite/internal/sqlutil" @@ -81,8 +80,7 @@ func executeMigration(ctx context.Context, db *sql.DB) error { if err != nil { if errors.Is(err, sql.ErrNoRows) { // migration was already executed, as the column was removed if err = sqlutil.InsertMigration(ctx, db, migrationName); err != nil { - // not a fatal error, log and continue - logrus.WithError(err).Warnf("unable to manually insert migration '%s'", migrationName) + return fmt.Errorf("unable to manually insert migration '%s': %w", migrationName, err) } return nil } diff --git a/keyserver/storage/sqlite3/key_changes_table.go b/keyserver/storage/sqlite3/key_changes_table.go index b68df5552..0c844d67a 100644 --- a/keyserver/storage/sqlite3/key_changes_table.go +++ b/keyserver/storage/sqlite3/key_changes_table.go @@ -18,8 +18,7 @@ import ( "context" "database/sql" "errors" - - "github.com/sirupsen/logrus" + "fmt" "github.com/matrix-org/dendrite/internal" "github.com/matrix-org/dendrite/internal/sqlutil" @@ -80,8 +79,7 @@ func executeMigration(ctx context.Context, db *sql.DB) error { if err != nil { if errors.Is(err, sql.ErrNoRows) { // migration was already executed, as the column was removed if err = sqlutil.InsertMigration(ctx, db, migrationName); err != nil { - // not a fatal error, log and continue - logrus.WithError(err).Warnf("unable to manually insert migration '%s'", migrationName) + return fmt.Errorf("unable to manually insert migration '%s': %w", migrationName, err) } return nil } diff --git a/roomserver/storage/postgres/storage.go b/roomserver/storage/postgres/storage.go index 26178df83..23a5f79eb 100644 --- a/roomserver/storage/postgres/storage.go +++ b/roomserver/storage/postgres/storage.go @@ -21,8 +21,6 @@ import ( "errors" "fmt" - "github.com/sirupsen/logrus" - // Import the postgres database driver. _ "github.com/lib/pq" @@ -79,8 +77,7 @@ func executeMigration(ctx context.Context, db *sql.DB) error { if err != nil { if errors.Is(err, sql.ErrNoRows) { // migration was already executed, as the column was removed if err = sqlutil.InsertMigration(ctx, db, migrationName); err != nil { - // not a fatal error, log and continue - logrus.WithError(err).Warnf("unable to manually insert migration '%s'", migrationName) + return fmt.Errorf("unable to manually insert migration '%s': %w", migrationName, err) } return nil } diff --git a/roomserver/storage/sqlite3/storage.go b/roomserver/storage/sqlite3/storage.go index c7bc00393..01c3f879c 100644 --- a/roomserver/storage/sqlite3/storage.go +++ b/roomserver/storage/sqlite3/storage.go @@ -22,7 +22,6 @@ import ( "fmt" "github.com/matrix-org/gomatrixserverlib" - "github.com/sirupsen/logrus" "github.com/matrix-org/dendrite/internal/caching" "github.com/matrix-org/dendrite/internal/sqlutil" @@ -87,8 +86,7 @@ func executeMigration(ctx context.Context, db *sql.DB) error { if err != nil { if errors.Is(err, sql.ErrNoRows) { // migration was already executed, as the column was removed if err = sqlutil.InsertMigration(ctx, db, migrationName); err != nil { - // not a fatal error, log and continue - logrus.WithError(err).Warnf("unable to manually insert migration '%s'", migrationName) + return fmt.Errorf("unable to manually insert migration '%s': %w", migrationName, err) } return nil } From c366ccdfcaf1ea820bef4744fda90aff4db1c67d Mon Sep 17 00:00:00 2001 From: Till <2353100+S7evinK@users.noreply.github.com> Date: Tue, 13 Sep 2022 09:35:45 +0200 Subject: [PATCH 2/3] Send-to-device consumer/producer tweaks (#2713) Some tweaks for the send-to-device consumers/producers: - use `json.RawMessage` without marshalling it first - try further devices (if available) if we failed to `PublishMsg` in the producers - some logging changes (to better debug E2EE issues) --- clientapi/producers/syncapi.go | 32 ++++++++++++++---------------- federationapi/producers/syncapi.go | 24 ++++++++++------------ syncapi/consumers/sendtodevice.go | 15 ++++++++------ syncapi/syncapi_test.go | 4 +--- 4 files changed, 35 insertions(+), 40 deletions(-) diff --git a/clientapi/producers/syncapi.go b/clientapi/producers/syncapi.go index 5933ce1a8..2dc0c4843 100644 --- a/clientapi/producers/syncapi.go +++ b/clientapi/producers/syncapi.go @@ -21,12 +21,13 @@ import ( "strconv" "time" - "github.com/matrix-org/dendrite/setup/jetstream" - "github.com/matrix-org/dendrite/syncapi/types" - userapi "github.com/matrix-org/dendrite/userapi/api" "github.com/matrix-org/gomatrixserverlib" "github.com/nats-io/nats.go" log "github.com/sirupsen/logrus" + + "github.com/matrix-org/dendrite/setup/jetstream" + "github.com/matrix-org/dendrite/syncapi/types" + userapi "github.com/matrix-org/dendrite/userapi/api" ) // SyncAPIProducer produces events for the sync API server to consume @@ -61,7 +62,7 @@ func (p *SyncAPIProducer) SendReceipt( func (p *SyncAPIProducer) SendToDevice( ctx context.Context, sender, userID, deviceID, eventType string, - message interface{}, + message json.RawMessage, ) error { devices := []string{} _, domain, err := gomatrixserverlib.SplitID('@', userID) @@ -89,24 +90,19 @@ func (p *SyncAPIProducer) SendToDevice( devices = append(devices, deviceID) } - js, err := json.Marshal(message) - if err != nil { - return err - } - log.WithFields(log.Fields{ "user_id": userID, "num_devices": len(devices), "type": eventType, }).Tracef("Producing to topic '%s'", p.TopicSendToDeviceEvent) - for _, device := range devices { + for i, device := range devices { ote := &types.OutputSendToDeviceEvent{ UserID: userID, DeviceID: device, SendToDeviceEvent: gomatrixserverlib.SendToDeviceEvent{ Sender: sender, Type: eventType, - Content: js, + Content: message, }, } @@ -115,15 +111,17 @@ func (p *SyncAPIProducer) SendToDevice( log.WithError(err).Error("sendToDevice failed json.Marshal") return err } - m := &nats.Msg{ - Subject: p.TopicSendToDeviceEvent, - Data: eventJSON, - Header: nats.Header{}, - } + m := nats.NewMsg(p.TopicSendToDeviceEvent) + m.Data = eventJSON m.Header.Set("sender", sender) m.Header.Set(jetstream.UserID, userID) + if _, err = p.JetStream.PublishMsg(m, nats.Context(ctx)); err != nil { - log.WithError(err).Error("sendToDevice failed t.Producer.SendMessage") + if i < len(devices)-1 { + log.WithError(err).Warn("sendToDevice failed to PublishMsg, trying further devices") + continue + } + log.WithError(err).Error("sendToDevice failed to PublishMsg for all devices") return err } } diff --git a/federationapi/producers/syncapi.go b/federationapi/producers/syncapi.go index 86c8c10a3..4abd3fbe5 100644 --- a/federationapi/producers/syncapi.go +++ b/federationapi/producers/syncapi.go @@ -64,7 +64,7 @@ func (p *SyncAPIProducer) SendReceipt( func (p *SyncAPIProducer) SendToDevice( ctx context.Context, sender, userID, deviceID, eventType string, - message interface{}, + message json.RawMessage, ) error { devices := []string{} _, domain, err := gomatrixserverlib.SplitID('@', userID) @@ -92,24 +92,19 @@ func (p *SyncAPIProducer) SendToDevice( devices = append(devices, deviceID) } - js, err := json.Marshal(message) - if err != nil { - return err - } - log.WithFields(log.Fields{ "user_id": userID, "num_devices": len(devices), "type": eventType, }).Tracef("Producing to topic '%s'", p.TopicSendToDeviceEvent) - for _, device := range devices { + for i, device := range devices { ote := &types.OutputSendToDeviceEvent{ UserID: userID, DeviceID: device, SendToDeviceEvent: gomatrixserverlib.SendToDeviceEvent{ Sender: sender, Type: eventType, - Content: js, + Content: message, }, } @@ -118,16 +113,17 @@ func (p *SyncAPIProducer) SendToDevice( log.WithError(err).Error("sendToDevice failed json.Marshal") return err } - m := &nats.Msg{ - Subject: p.TopicSendToDeviceEvent, - Data: eventJSON, - Header: nats.Header{}, - } + m := nats.NewMsg(p.TopicSendToDeviceEvent) + m.Data = eventJSON m.Header.Set("sender", sender) m.Header.Set(jetstream.UserID, userID) if _, err = p.JetStream.PublishMsg(m, nats.Context(ctx)); err != nil { - log.WithError(err).Error("sendToDevice failed t.Producer.SendMessage") + if i < len(devices)-1 { + log.WithError(err).Warn("sendToDevice failed to PublishMsg, trying further devices") + continue + } + log.WithError(err).Error("sendToDevice failed to PublishMsg for all devices") return err } } diff --git a/syncapi/consumers/sendtodevice.go b/syncapi/consumers/sendtodevice.go index 89b01d7e5..7d6aae597 100644 --- a/syncapi/consumers/sendtodevice.go +++ b/syncapi/consumers/sendtodevice.go @@ -19,16 +19,17 @@ import ( "encoding/json" "github.com/getsentry/sentry-go" + "github.com/matrix-org/gomatrixserverlib" + "github.com/matrix-org/util" + "github.com/nats-io/nats.go" + log "github.com/sirupsen/logrus" + "github.com/matrix-org/dendrite/setup/config" "github.com/matrix-org/dendrite/setup/jetstream" "github.com/matrix-org/dendrite/setup/process" "github.com/matrix-org/dendrite/syncapi/notifier" "github.com/matrix-org/dendrite/syncapi/storage" "github.com/matrix-org/dendrite/syncapi/types" - "github.com/matrix-org/gomatrixserverlib" - "github.com/matrix-org/util" - "github.com/nats-io/nats.go" - log "github.com/sirupsen/logrus" ) // OutputSendToDeviceEventConsumer consumes events that originated in the EDU server. @@ -79,16 +80,18 @@ func (s *OutputSendToDeviceEventConsumer) onMessage(ctx context.Context, msgs [] _, domain, err := gomatrixserverlib.SplitID('@', userID) if err != nil { sentry.CaptureException(err) + log.WithError(err).Errorf("send-to-device: failed to split user id, dropping message") return true } if domain != s.serverName { + log.Tracef("ignoring send-to-device event with destination %s", domain) return true } var output types.OutputSendToDeviceEvent if err = json.Unmarshal(msg.Data, &output); err != nil { // If the message was invalid, log it and move on to the next message in the stream - log.WithError(err).Errorf("output log: message parse failure") + log.WithError(err).Errorf("send-to-device: message parse failure") sentry.CaptureException(err) return true } @@ -105,7 +108,7 @@ func (s *OutputSendToDeviceEventConsumer) onMessage(ctx context.Context, msgs [] ) if err != nil { sentry.CaptureException(err) - log.WithError(err).Errorf("failed to store send-to-device message") + log.WithError(err).Errorf("send-to-device: failed to store message") return false } diff --git a/syncapi/syncapi_test.go b/syncapi/syncapi_test.go index c81256aa7..a4985dbf4 100644 --- a/syncapi/syncapi_test.go +++ b/syncapi/syncapi_test.go @@ -624,9 +624,7 @@ func testSendToDevice(t *testing.T, dbType test.DBType) { // Send to-device messages of type "m.dendrite.test" with content `{"dummy":"message $counter"}` for i := 0; i < tc.sendMessagesCount; i++ { msgCounter++ - msg := map[string]string{ - "dummy": fmt.Sprintf("message %d", msgCounter), - } + msg := json.RawMessage(fmt.Sprintf(`{"dummy":"message %d"}`, msgCounter)) if err := producer.SendToDevice(ctx, user.ID, user.ID, alice.ID, "m.dendrite.test", msg); err != nil { t.Fatalf("unable to send to device message: %v", err) } From 3e55856254f6bc918f5075d7adb85d53da92c7c8 Mon Sep 17 00:00:00 2001 From: Neil Alexander Date: Tue, 13 Sep 2022 09:37:38 +0100 Subject: [PATCH 3/3] Always resolve state in `QueryStateAfterEvents` --- roomserver/internal/query/query.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/roomserver/internal/query/query.go b/roomserver/internal/query/query.go index 6dce2bc3e..d08c5c491 100644 --- a/roomserver/internal/query/query.go +++ b/roomserver/internal/query/query.go @@ -106,7 +106,7 @@ func (r *Queryer) QueryStateAfterEvents( return err } - if len(request.PrevEventIDs) > 1 && len(request.StateToFetch) == 0 { + if len(request.PrevEventIDs) > 1 { var authEventIDs []string for _, e := range stateEvents { authEventIDs = append(authEventIDs, e.AuthEventIDs()...)