hoernschen/dendrite
1
0
Fork 0
mirror of https://github.com/hoernschen/dendrite.git synced 2024-12-26 06:58:27 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions

Merge branch 'master' into allow_uppercase_username_on_login

Browse source
This commit is contained in:
kegsay 2022-01-31 13:44:39 +00:00 committed by GitHub
commit 9d337cde80
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
14 changed files with 102 additions and 74 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
clientapi/producers/syncapi.go
View file

@ -51,7 +51,7 @@ func (p *SyncAPIProducer) SendData(userID string, roomID string, dataType string
"user_id": userID, "user_id": userID,
"room_id": roomID, "room_id": roomID,
"data_type": dataType, "data_type": dataType,
}).Infof("Producing to topic '%s'", p.Topic) }).Tracef("Producing to topic '%s'", p.Topic)
_, err = p.JetStream.PublishMsg(m) _, err = p.JetStream.PublishMsg(m)
return err return err

8
eduserver/input/input.go
View file

@ -98,7 +98,7 @@ func (t *EDUServerInputAPI) InputCrossSigningKeyUpdate(
logrus.WithFields(logrus.Fields{ logrus.WithFields(logrus.Fields{
"user_id": request.UserID, "user_id": request.UserID,
}).Infof("Producing to topic '%s'", t.OutputKeyChangeEventTopic) }).Tracef("Producing to topic '%s'", t.OutputKeyChangeEventTopic)
_, err = t.JetStream.PublishMsg(&nats.Msg{ _, err = t.JetStream.PublishMsg(&nats.Msg{
Subject: t.OutputKeyChangeEventTopic, Subject: t.OutputKeyChangeEventTopic,
@ -134,7 +134,7 @@ func (t *EDUServerInputAPI) sendTypingEvent(ite *api.InputTypingEvent) error {
"room_id": ite.RoomID, "room_id": ite.RoomID,
"user_id": ite.UserID, "user_id": ite.UserID,
"typing": ite.Typing, "typing": ite.Typing,
}).Infof("Producing to topic '%s'", t.OutputTypingEventTopic) }).Tracef("Producing to topic '%s'", t.OutputTypingEventTopic)
_, err = t.JetStream.PublishMsg(&nats.Msg{ _, err = t.JetStream.PublishMsg(&nats.Msg{
Subject: t.OutputTypingEventTopic, Subject: t.OutputTypingEventTopic,
@ -175,7 +175,7 @@ func (t *EDUServerInputAPI) sendToDeviceEvent(ise *api.InputSendToDeviceEvent) e
"user_id": ise.UserID, "user_id": ise.UserID,
"num_devices": len(devices), "num_devices": len(devices),
"type": ise.Type, "type": ise.Type,
}).Infof("Producing to topic '%s'", t.OutputSendToDeviceEventTopic) }).Tracef("Producing to topic '%s'", t.OutputSendToDeviceEventTopic)
for _, device := range devices { for _, device := range devices {
ote := &api.OutputSendToDeviceEvent{ ote := &api.OutputSendToDeviceEvent{
UserID: ise.UserID, UserID: ise.UserID,
@ -208,7 +208,7 @@ func (t *EDUServerInputAPI) InputReceiptEvent(
request *api.InputReceiptEventRequest, request *api.InputReceiptEventRequest,
response *api.InputReceiptEventResponse, response *api.InputReceiptEventResponse,
) error { ) error {
logrus.WithFields(logrus.Fields{}).Infof("Producing to topic '%s'", t.OutputReceiptEventTopic) logrus.WithFields(logrus.Fields{}).Tracef("Producing to topic '%s'", t.OutputReceiptEventTopic)
output := &api.OutputReceiptEvent{ output := &api.OutputReceiptEvent{
UserID: request.InputReceiptEvent.UserID, UserID: request.InputReceiptEvent.UserID,
RoomID: request.InputReceiptEvent.RoomID, RoomID: request.InputReceiptEvent.RoomID,

28
federationapi/routing/send.go
View file

@ -162,7 +162,7 @@ func Send(
t.TransactionID = txnID t.TransactionID = txnID
t.Destination = cfg.Matrix.ServerName t.Destination = cfg.Matrix.ServerName
util.GetLogger(httpReq.Context()).Infof("Received transaction %q from %q containing %d PDUs, %d EDUs", txnID, request.Origin(), len(t.PDUs), len(t.EDUs)) util.GetLogger(httpReq.Context()).Debugf("Received transaction %q from %q containing %d PDUs, %d EDUs", txnID, request.Origin(), len(t.PDUs), len(t.EDUs))
resp, jsonErr := t.processTransaction(httpReq.Context()) resp, jsonErr := t.processTransaction(httpReq.Context())
if jsonErr != nil { if jsonErr != nil {
@ -221,7 +221,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
verReq := api.QueryRoomVersionForRoomRequest{RoomID: roomID} verReq := api.QueryRoomVersionForRoomRequest{RoomID: roomID}
verRes := api.QueryRoomVersionForRoomResponse{} verRes := api.QueryRoomVersionForRoomResponse{}
if err := t.rsAPI.QueryRoomVersionForRoom(ctx, &verReq, &verRes); err != nil { if err := t.rsAPI.QueryRoomVersionForRoom(ctx, &verReq, &verRes); err != nil {
util.GetLogger(ctx).WithError(err).Warn("Transaction: Failed to query room version for room", verReq.RoomID) util.GetLogger(ctx).WithError(err).Debug("Transaction: Failed to query room version for room", verReq.RoomID)
return "" return ""
} }
roomVersions[roomID] = verRes.RoomVersion roomVersions[roomID] = verRes.RoomVersion
@ -234,7 +234,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
RoomID string `json:"room_id"` RoomID string `json:"room_id"`
} }
if err := json.Unmarshal(pdu, &header); err != nil { if err := json.Unmarshal(pdu, &header); err != nil {
util.GetLogger(ctx).WithError(err).Warn("Transaction: Failed to extract room ID from event") util.GetLogger(ctx).WithError(err).Debug("Transaction: Failed to extract room ID from event")
// We don't know the event ID at this point so we can't return the // We don't know the event ID at this point so we can't return the
// failure in the PDU results // failure in the PDU results
continue continue
@ -255,7 +255,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
JSON: jsonerror.BadJSON("PDU contains bad JSON"), JSON: jsonerror.BadJSON("PDU contains bad JSON"),
} }
} }
util.GetLogger(ctx).WithError(err).Warnf("Transaction: Failed to parse event JSON of event %s", string(pdu)) util.GetLogger(ctx).WithError(err).Debugf("Transaction: Failed to parse event JSON of event %s", string(pdu))
continue continue
} }
if api.IsServerBannedFromRoom(ctx, t.rsAPI, event.RoomID(), t.Origin) { if api.IsServerBannedFromRoom(ctx, t.rsAPI, event.RoomID(), t.Origin) {
@ -265,7 +265,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
continue continue
} }
if err = event.VerifyEventSignatures(ctx, t.keys); err != nil { if err = event.VerifyEventSignatures(ctx, t.keys); err != nil {
util.GetLogger(ctx).WithError(err).Warnf("Transaction: Couldn't validate signature of event %q", event.EventID()) util.GetLogger(ctx).WithError(err).Debugf("Transaction: Couldn't validate signature of event %q", event.EventID())
results[event.EventID()] = gomatrixserverlib.PDUResult{ results[event.EventID()] = gomatrixserverlib.PDUResult{
Error: err.Error(), Error: err.Error(),
} }
@ -287,7 +287,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
nil, nil,
true, true,
); err != nil { ); err != nil {
util.GetLogger(ctx).WithError(err).Warnf("Transaction: Couldn't submit event %q to input queue: %s", event.EventID(), err) util.GetLogger(ctx).WithError(err).Errorf("Transaction: Couldn't submit event %q to input queue: %s", event.EventID(), err)
results[event.EventID()] = gomatrixserverlib.PDUResult{ results[event.EventID()] = gomatrixserverlib.PDUResult{
Error: err.Error(), Error: err.Error(),
} }
@ -314,16 +314,16 @@ func (t *txnReq) processEDUs(ctx context.Context) {
Typing bool `json:"typing"` Typing bool `json:"typing"`
} }
if err := json.Unmarshal(e.Content, &typingPayload); err != nil { if err := json.Unmarshal(e.Content, &typingPayload); err != nil {
util.GetLogger(ctx).WithError(err).Error("Failed to unmarshal typing event") util.GetLogger(ctx).WithError(err).Debug("Failed to unmarshal typing event")
continue continue
} }
_, domain, err := gomatrixserverlib.SplitID('@', typingPayload.UserID) _, domain, err := gomatrixserverlib.SplitID('@', typingPayload.UserID)
if err != nil { if err != nil {
util.GetLogger(ctx).WithError(err).Error("Failed to split domain from typing event sender") util.GetLogger(ctx).WithError(err).Debug("Failed to split domain from typing event sender")
continue continue
} }
if domain != t.Origin { if domain != t.Origin {
util.GetLogger(ctx).Warnf("Dropping typing event where sender domain (%q) doesn't match origin (%q)", domain, t.Origin) util.GetLogger(ctx).Debugf("Dropping typing event where sender domain (%q) doesn't match origin (%q)", domain, t.Origin)
continue continue
} }
if err := eduserverAPI.SendTyping(ctx, t.eduAPI, typingPayload.UserID, typingPayload.RoomID, typingPayload.Typing, 30*1000); err != nil { if err := eduserverAPI.SendTyping(ctx, t.eduAPI, typingPayload.UserID, typingPayload.RoomID, typingPayload.Typing, 30*1000); err != nil {
@ -333,7 +333,7 @@ func (t *txnReq) processEDUs(ctx context.Context) {
// https://matrix.org/docs/spec/server_server/r0.1.3#m-direct-to-device-schema // https://matrix.org/docs/spec/server_server/r0.1.3#m-direct-to-device-schema
var directPayload gomatrixserverlib.ToDeviceMessage var directPayload gomatrixserverlib.ToDeviceMessage
if err := json.Unmarshal(e.Content, &directPayload); err != nil { if err := json.Unmarshal(e.Content, &directPayload); err != nil {
util.GetLogger(ctx).WithError(err).Error("Failed to unmarshal send-to-device events") util.GetLogger(ctx).WithError(err).Debug("Failed to unmarshal send-to-device events")
continue continue
} }
for userID, byUser := range directPayload.Messages { for userID, byUser := range directPayload.Messages {
@ -355,7 +355,7 @@ func (t *txnReq) processEDUs(ctx context.Context) {
payload := map[string]eduserverAPI.FederationReceiptMRead{} payload := map[string]eduserverAPI.FederationReceiptMRead{}
if err := json.Unmarshal(e.Content, &payload); err != nil { if err := json.Unmarshal(e.Content, &payload); err != nil {
util.GetLogger(ctx).WithError(err).Error("Failed to unmarshal receipt event") util.GetLogger(ctx).WithError(err).Debug("Failed to unmarshal receipt event")
continue continue
} }
@ -363,11 +363,11 @@ func (t *txnReq) processEDUs(ctx context.Context) {
for userID, mread := range receipt.User { for userID, mread := range receipt.User {
_, domain, err := gomatrixserverlib.SplitID('@', userID) _, domain, err := gomatrixserverlib.SplitID('@', userID)
if err != nil { if err != nil {
util.GetLogger(ctx).WithError(err).Error("Failed to split domain from receipt event sender") util.GetLogger(ctx).WithError(err).Debug("Failed to split domain from receipt event sender")
continue continue
} }
if t.Origin != domain { if t.Origin != domain {
util.GetLogger(ctx).Warnf("Dropping receipt event where sender domain (%q) doesn't match origin (%q)", domain, t.Origin) util.GetLogger(ctx).Debugf("Dropping receipt event where sender domain (%q) doesn't match origin (%q)", domain, t.Origin)
continue continue
} }
if err := t.processReceiptEvent(ctx, userID, roomID, "m.read", mread.Data.TS, mread.EventIDs); err != nil { if err := t.processReceiptEvent(ctx, userID, roomID, "m.read", mread.Data.TS, mread.EventIDs); err != nil {
@ -386,7 +386,7 @@ func (t *txnReq) processEDUs(ctx context.Context) {
if err := json.Unmarshal(e.Content, &updatePayload); err != nil { if err := json.Unmarshal(e.Content, &updatePayload); err != nil {
util.GetLogger(ctx).WithError(err).WithFields(logrus.Fields{ util.GetLogger(ctx).WithError(err).WithFields(logrus.Fields{
"user_id": updatePayload.UserID, "user_id": updatePayload.UserID,
}).Error("Failed to send signing key update to edu server") }).Debug("Failed to send signing key update to edu server")
continue continue
} }
inputReq := &eduserverAPI.InputCrossSigningKeyUpdateRequest{ inputReq := &eduserverAPI.InputCrossSigningKeyUpdateRequest{

9
go.mod
View file

@ -13,6 +13,7 @@ require (
github.com/Masterminds/semver/v3 v3.1.1 github.com/Masterminds/semver/v3 v3.1.1
github.com/S7evinK/saramajetstream v0.0.0-20210709110708-de6efc8c4a32 github.com/S7evinK/saramajetstream v0.0.0-20210709110708-de6efc8c4a32
github.com/Shopify/sarama v1.31.0 github.com/Shopify/sarama v1.31.0
github.com/cespare/xxhash/v2 v2.1.2 // indirect
github.com/codeclysm/extract v2.2.0+incompatible github.com/codeclysm/extract v2.2.0+incompatible
github.com/containerd/containerd v1.5.9 // indirect github.com/containerd/containerd v1.5.9 // indirect
github.com/docker/docker v20.10.12+incompatible github.com/docker/docker v20.10.12+incompatible
@ -23,6 +24,7 @@ require (
github.com/gorilla/websocket v1.4.2 github.com/gorilla/websocket v1.4.2
github.com/h2non/filetype v1.1.3 // indirect github.com/h2non/filetype v1.1.3 // indirect
github.com/hashicorp/golang-lru v0.5.4 github.com/hashicorp/golang-lru v0.5.4
github.com/json-iterator/go v1.1.12 // indirect
github.com/juju/testing v0.0.0-20211215003918-77eb13d6cad2 // indirect github.com/juju/testing v0.0.0-20211215003918-77eb13d6cad2 // indirect
github.com/klauspost/compress v1.14.2 // indirect github.com/klauspost/compress v1.14.2 // indirect
github.com/lib/pq v1.10.4 github.com/lib/pq v1.10.4
@ -40,7 +42,7 @@ require (
github.com/matrix-org/go-http-js-libp2p v0.0.0-20200518170932-783164aeeda4 github.com/matrix-org/go-http-js-libp2p v0.0.0-20200518170932-783164aeeda4
github.com/matrix-org/go-sqlite3-js v0.0.0-20210709140738-b0d1ba599a6d github.com/matrix-org/go-sqlite3-js v0.0.0-20210709140738-b0d1ba599a6d
github.com/matrix-org/gomatrix v0.0.0-20210324163249-be2af5ef2e16 github.com/matrix-org/gomatrix v0.0.0-20210324163249-be2af5ef2e16
github.com/matrix-org/gomatrixserverlib v0.0.0-20220128100033-8d79e0c35e32 github.com/matrix-org/gomatrixserverlib v0.0.0-20220131105022-801c51af9f29
github.com/matrix-org/pinecone v0.0.0-20220121094951-351265543ddf github.com/matrix-org/pinecone v0.0.0-20220121094951-351265543ddf
github.com/matrix-org/util v0.0.0-20200807132607-55161520e1d4 github.com/matrix-org/util v0.0.0-20200807132607-55161520e1d4
github.com/mattn/go-sqlite3 v1.14.10 github.com/mattn/go-sqlite3 v1.14.10
@ -54,7 +56,9 @@ require (
github.com/patrickmn/go-cache v2.1.0+incompatible github.com/patrickmn/go-cache v2.1.0+incompatible
github.com/pkg/errors v0.9.1 github.com/pkg/errors v0.9.1
github.com/pressly/goose v2.7.0+incompatible github.com/pressly/goose v2.7.0+incompatible
github.com/prometheus/client_golang v1.12.0 github.com/prometheus/client_golang v1.11.0
github.com/prometheus/common v0.32.1 // indirect
github.com/prometheus/procfs v0.7.3 // indirect
github.com/sirupsen/logrus v1.8.1 github.com/sirupsen/logrus v1.8.1
github.com/tidwall/gjson v1.13.0 github.com/tidwall/gjson v1.13.0
github.com/tidwall/sjson v1.2.4 github.com/tidwall/sjson v1.2.4
@ -66,6 +70,7 @@ require (
golang.org/x/image v0.0.0-20211028202545-6944b10bf410 golang.org/x/image v0.0.0-20211028202545-6944b10bf410
golang.org/x/mobile v0.0.0-20220112015953-858099ff7816 golang.org/x/mobile v0.0.0-20220112015953-858099ff7816
golang.org/x/net v0.0.0-20220127200216-cd36cc0744dd golang.org/x/net v0.0.0-20220127200216-cd36cc0744dd
golang.org/x/sys v0.0.0-20220114195835-da31bd327af9 // indirect
golang.org/x/term v0.0.0-20210927222741-03fcf44c2211 golang.org/x/term v0.0.0-20210927222741-03fcf44c2211
gopkg.in/h2non/bimg.v1 v1.1.5 gopkg.in/h2non/bimg.v1 v1.1.5
gopkg.in/yaml.v2 v2.4.0 gopkg.in/yaml.v2 v2.4.0

14
go.sum
View file

@ -429,7 +429,6 @@ github.com/go-openapi/jsonreference v0.19.3/go.mod h1:rjx6GuL8TTa9VaixXglHmQmIL9
github.com/go-openapi/spec v0.19.3/go.mod h1:FpwSN1ksY1eteniUU7X0N/BgJ7a4WvBFVA8Lj9mJglo= github.com/go-openapi/spec v0.19.3/go.mod h1:FpwSN1ksY1eteniUU7X0N/BgJ7a4WvBFVA8Lj9mJglo=
github.com/go-openapi/swag v0.19.2/go.mod h1:POnQmlKehdgb5mhVOsnJFsivZCEZ/vjK9gh66Z9tfKk= github.com/go-openapi/swag v0.19.2/go.mod h1:POnQmlKehdgb5mhVOsnJFsivZCEZ/vjK9gh66Z9tfKk=
github.com/go-openapi/swag v0.19.5/go.mod h1:POnQmlKehdgb5mhVOsnJFsivZCEZ/vjK9gh66Z9tfKk= github.com/go-openapi/swag v0.19.5/go.mod h1:POnQmlKehdgb5mhVOsnJFsivZCEZ/vjK9gh66Z9tfKk=
github.com/go-playground/assert/v2 v2.0.1 h1:MsBgLAaY856+nPRTKrp3/OZK38U/wa0CcBYNjji3q3A=
github.com/go-playground/assert/v2 v2.0.1/go.mod h1:VDjEfimB/XKnb+ZQfWdccd7VUvScMdVu0Titje2rxJ4= github.com/go-playground/assert/v2 v2.0.1/go.mod h1:VDjEfimB/XKnb+ZQfWdccd7VUvScMdVu0Titje2rxJ4=
github.com/go-playground/locales v0.13.0 h1:HyWk6mgj5qFqCT5fjGBuRArbVDfE4hi8+e8ceBS/t7Q= github.com/go-playground/locales v0.13.0 h1:HyWk6mgj5qFqCT5fjGBuRArbVDfE4hi8+e8ceBS/t7Q=
github.com/go-playground/locales v0.13.0/go.mod h1:taPMhCMXrRLJO55olJkUXHZBHCxTMfnGwq/HNwmWNS8= github.com/go-playground/locales v0.13.0/go.mod h1:taPMhCMXrRLJO55olJkUXHZBHCxTMfnGwq/HNwmWNS8=
@ -553,9 +552,7 @@ github.com/gorilla/handlers v0.0.0-20150720190736-60c7bfde3e33/go.mod h1:Qkdc/uu
github.com/gorilla/mux v1.7.2/go.mod h1:1lud6UwP+6orDFRuTfBEV8e9/aOM/c4fVVCaMa2zaAs= github.com/gorilla/mux v1.7.2/go.mod h1:1lud6UwP+6orDFRuTfBEV8e9/aOM/c4fVVCaMa2zaAs=
github.com/gorilla/mux v1.8.0 h1:i40aqfkR1h2SlN9hojwV5ZA91wcXFOvkdNIeFDP5koI= github.com/gorilla/mux v1.8.0 h1:i40aqfkR1h2SlN9hojwV5ZA91wcXFOvkdNIeFDP5koI=
github.com/gorilla/mux v1.8.0/go.mod h1:DVbg23sWSpFRCP0SfiEN6jmj59UnW/n46BH5rLB71So= github.com/gorilla/mux v1.8.0/go.mod h1:DVbg23sWSpFRCP0SfiEN6jmj59UnW/n46BH5rLB71So=
github.com/gorilla/securecookie v1.1.1 h1:miw7JPhV+b/lAHSXz4qd/nN9jRiAFV5FwjeKyCS8BvQ=
github.com/gorilla/securecookie v1.1.1/go.mod h1:ra0sb63/xPlUeL+yeDciTfxMRAA+MP+HVt/4epWDjd4= github.com/gorilla/securecookie v1.1.1/go.mod h1:ra0sb63/xPlUeL+yeDciTfxMRAA+MP+HVt/4epWDjd4=
github.com/gorilla/sessions v1.2.1 h1:DHd3rPN5lE3Ts3D8rKkQ8x/0kqfeNmBAaiSi+o7FsgI=
github.com/gorilla/sessions v1.2.1/go.mod h1:dk2InVEVJ0sfLlnXv9EAgkf6ecYs/i80K/zI+bUmuGM= github.com/gorilla/sessions v1.2.1/go.mod h1:dk2InVEVJ0sfLlnXv9EAgkf6ecYs/i80K/zI+bUmuGM=
github.com/gorilla/websocket v0.0.0-20170926233335-4201258b820c/go.mod h1:E7qHFY5m1UJ88s3WnNqhKjPHQ0heANvMoAMk2YaljkQ= github.com/gorilla/websocket v0.0.0-20170926233335-4201258b820c/go.mod h1:E7qHFY5m1UJ88s3WnNqhKjPHQ0heANvMoAMk2YaljkQ=
github.com/gorilla/websocket v1.4.0/go.mod h1:E7qHFY5m1UJ88s3WnNqhKjPHQ0heANvMoAMk2YaljkQ= github.com/gorilla/websocket v1.4.0/go.mod h1:E7qHFY5m1UJ88s3WnNqhKjPHQ0heANvMoAMk2YaljkQ=
@ -1024,8 +1021,8 @@ github.com/matrix-org/go-sqlite3-js v0.0.0-20210709140738-b0d1ba599a6d/go.mod h1
github.com/matrix-org/gomatrix v0.0.0-20190528120928-7df988a63f26/go.mod h1:3fxX6gUjWyI/2Bt7J1OLhpCzOfO/bB3AiX0cJtEKud0= github.com/matrix-org/gomatrix v0.0.0-20190528120928-7df988a63f26/go.mod h1:3fxX6gUjWyI/2Bt7J1OLhpCzOfO/bB3AiX0cJtEKud0=
github.com/matrix-org/gomatrix v0.0.0-20210324163249-be2af5ef2e16 h1:ZtO5uywdd5dLDCud4r0r55eP4j9FuUNpl60Gmntcop4= github.com/matrix-org/gomatrix v0.0.0-20210324163249-be2af5ef2e16 h1:ZtO5uywdd5dLDCud4r0r55eP4j9FuUNpl60Gmntcop4=
github.com/matrix-org/gomatrix v0.0.0-20210324163249-be2af5ef2e16/go.mod h1:/gBX06Kw0exX1HrwmoBibFA98yBk/jxKpGVeyQbff+s= github.com/matrix-org/gomatrix v0.0.0-20210324163249-be2af5ef2e16/go.mod h1:/gBX06Kw0exX1HrwmoBibFA98yBk/jxKpGVeyQbff+s=
github.com/matrix-org/gomatrixserverlib v0.0.0-20220128100033-8d79e0c35e32 h1:DiWPsGAYMlBQq/urm7TJkIeSf9FnfzegcaQUpgwIbUs= github.com/matrix-org/gomatrixserverlib v0.0.0-20220131105022-801c51af9f29 h1:1t/J3AldUbgRxltlcmMbUefexxzolG5DvV2CkriZ4LM=
github.com/matrix-org/gomatrixserverlib v0.0.0-20220128100033-8d79e0c35e32/go.mod h1:qFvhfbQ5orQxlH9vCiFnP4dW27xxnWHdNUBKyj/fbiY= github.com/matrix-org/gomatrixserverlib v0.0.0-20220131105022-801c51af9f29/go.mod h1:qFvhfbQ5orQxlH9vCiFnP4dW27xxnWHdNUBKyj/fbiY=
github.com/matrix-org/pinecone v0.0.0-20220121094951-351265543ddf h1:/nqfHUdQHr3WVdbZieaYFvHF1rin5pvDTa/NOZ/qCyE= github.com/matrix-org/pinecone v0.0.0-20220121094951-351265543ddf h1:/nqfHUdQHr3WVdbZieaYFvHF1rin5pvDTa/NOZ/qCyE=
github.com/matrix-org/pinecone v0.0.0-20220121094951-351265543ddf/go.mod h1:r6dsL+ylE0yXe/7zh8y/Bdh6aBYI1r+u4yZni9A4iyk= github.com/matrix-org/pinecone v0.0.0-20220121094951-351265543ddf/go.mod h1:r6dsL+ylE0yXe/7zh8y/Bdh6aBYI1r+u4yZni9A4iyk=
github.com/matrix-org/util v0.0.0-20190711121626-527ce5ddefc7/go.mod h1:vVQlW/emklohkZnOPwD3LrZUBqdfsbiyO3p1lNV8F6U= github.com/matrix-org/util v0.0.0-20190711121626-527ce5ddefc7/go.mod h1:vVQlW/emklohkZnOPwD3LrZUBqdfsbiyO3p1lNV8F6U=
@ -1169,7 +1166,6 @@ github.com/nats-io/nkeys v0.3.0 h1:cgM5tL53EvYRU+2YLXIK0G2mJtK12Ft9oeooSZMA2G8=
github.com/nats-io/nkeys v0.3.0/go.mod h1:gvUNGjVcM2IPr5rCsRsC6Wb3Hr2CQAm08dsxtV6A5y4= github.com/nats-io/nkeys v0.3.0/go.mod h1:gvUNGjVcM2IPr5rCsRsC6Wb3Hr2CQAm08dsxtV6A5y4=
github.com/nats-io/nuid v1.0.1 h1:5iA8DT8V7q8WK2EScv2padNa/rTESc1KdnPw4TC2paw= github.com/nats-io/nuid v1.0.1 h1:5iA8DT8V7q8WK2EScv2padNa/rTESc1KdnPw4TC2paw=
github.com/nats-io/nuid v1.0.1/go.mod h1:19wcPz3Ph3q0Jbyiqsd0kePYG7A95tJPxeL+1OSON2c= github.com/nats-io/nuid v1.0.1/go.mod h1:19wcPz3Ph3q0Jbyiqsd0kePYG7A95tJPxeL+1OSON2c=
github.com/nbio/st v0.0.0-20140626010706-e9e8d9816f32 h1:W6apQkHrMkS0Muv8G/TipAy/FJl/rCYT0+EuS8+Z0z4=
github.com/nbio/st v0.0.0-20140626010706-e9e8d9816f32/go.mod h1:9wM+0iRr9ahx58uYLpLIr5fm8diHn0JbqRycJi6w0Ms= github.com/nbio/st v0.0.0-20140626010706-e9e8d9816f32/go.mod h1:9wM+0iRr9ahx58uYLpLIr5fm8diHn0JbqRycJi6w0Ms=
github.com/ncw/swift v1.0.47/go.mod h1:23YIA4yWVnGwv2dQlN4bB7egfYX6YLn0Yo/S6zZO/ZM= github.com/ncw/swift v1.0.47/go.mod h1:23YIA4yWVnGwv2dQlN4bB7egfYX6YLn0Yo/S6zZO/ZM=
github.com/neelance/astrewrite v0.0.0-20160511093645-99348263ae86/go.mod h1:kHJEU3ofeGjhHklVoIGuVj85JJwZ6kWPaJwCIxgnFmo= github.com/neelance/astrewrite v0.0.0-20160511093645-99348263ae86/go.mod h1:kHJEU3ofeGjhHklVoIGuVj85JJwZ6kWPaJwCIxgnFmo=
@ -1276,9 +1272,8 @@ github.com/prometheus/client_golang v0.9.3/go.mod h1:/TN21ttK/J9q6uSwhBd54HahCDf
github.com/prometheus/client_golang v1.0.0/go.mod h1:db9x61etRT2tGnBNRi70OPL5FsnadC4Ky3P0J6CfImo= github.com/prometheus/client_golang v1.0.0/go.mod h1:db9x61etRT2tGnBNRi70OPL5FsnadC4Ky3P0J6CfImo=
github.com/prometheus/client_golang v1.1.0/go.mod h1:I1FGZT9+L76gKKOs5djB6ezCbFQP1xR9D75/vuwEF3g= github.com/prometheus/client_golang v1.1.0/go.mod h1:I1FGZT9+L76gKKOs5djB6ezCbFQP1xR9D75/vuwEF3g=
github.com/prometheus/client_golang v1.7.1/go.mod h1:PY5Wy2awLA44sXw4AOSfFBetzPP4j5+D6mVACh+pe2M= github.com/prometheus/client_golang v1.7.1/go.mod h1:PY5Wy2awLA44sXw4AOSfFBetzPP4j5+D6mVACh+pe2M=
github.com/prometheus/client_golang v1.11.0 h1:HNkLOAEQMIDv/K+04rukrLx6ch7msSRwf3/SASFAGtQ=
github.com/prometheus/client_golang v1.11.0/go.mod h1:Z6t4BnS23TR94PD6BsDNk8yVqroYurpAkEiz0P2BEV0= github.com/prometheus/client_golang v1.11.0/go.mod h1:Z6t4BnS23TR94PD6BsDNk8yVqroYurpAkEiz0P2BEV0=
github.com/prometheus/client_golang v1.12.0 h1:C+UIj/QWtmqY13Arb8kwMt5j34/0Z2iKamrJ+ryC0Gg=
github.com/prometheus/client_golang v1.12.0/go.mod h1:3Z9XVyYiZYEO+YQWt3RD2R3jrbd179Rt297l4aS6nDY=
github.com/prometheus/client_model v0.0.0-20171117100541-99fa1f4be8e5/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= github.com/prometheus/client_model v0.0.0-20171117100541-99fa1f4be8e5/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo=
github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo=
github.com/prometheus/client_model v0.0.0-20190129233127-fd36f4220a90/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/prometheus/client_model v0.0.0-20190129233127-fd36f4220a90/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA=
@ -1579,7 +1574,6 @@ golang.org/x/exp v0.0.0-20191129062945-2f5052295587/go.mod h1:2RIsYlXP63K8oxa1u0
golang.org/x/exp v0.0.0-20191227195350-da58074b4299/go.mod h1:2RIsYlXP63K8oxa1u096TMicItID8zy7Y6sNkU49FU4= golang.org/x/exp v0.0.0-20191227195350-da58074b4299/go.mod h1:2RIsYlXP63K8oxa1u096TMicItID8zy7Y6sNkU49FU4=
golang.org/x/exp v0.0.0-20200119233911-0405dc783f0a/go.mod h1:2RIsYlXP63K8oxa1u096TMicItID8zy7Y6sNkU49FU4= golang.org/x/exp v0.0.0-20200119233911-0405dc783f0a/go.mod h1:2RIsYlXP63K8oxa1u096TMicItID8zy7Y6sNkU49FU4=
golang.org/x/exp v0.0.0-20200207192155-f17229e696bd/go.mod h1:J/WKrq2StrnmMY6+EHIKF9dgMWnmCNThgcyBT1FY9mM= golang.org/x/exp v0.0.0-20200207192155-f17229e696bd/go.mod h1:J/WKrq2StrnmMY6+EHIKF9dgMWnmCNThgcyBT1FY9mM=
golang.org/x/exp v0.0.0-20200224162631-6cc2880d07d6 h1:QE6XYQK6naiK1EPAe1g/ILLxN5RBoH5xkJk3CqlMI/Y=
golang.org/x/exp v0.0.0-20200224162631-6cc2880d07d6/go.mod h1:3jZMyOhIsHpP37uCMkUooju7aAi5cS1Q23tOzKc+0MU= golang.org/x/exp v0.0.0-20200224162631-6cc2880d07d6/go.mod h1:3jZMyOhIsHpP37uCMkUooju7aAi5cS1Q23tOzKc+0MU=
golang.org/x/image v0.0.0-20180708004352-c73c2afc3b81/go.mod h1:ux5Hcp/YLpHSI86hEcLt0YII63i6oz57MZXIpbrjZUs= golang.org/x/image v0.0.0-20180708004352-c73c2afc3b81/go.mod h1:ux5Hcp/YLpHSI86hEcLt0YII63i6oz57MZXIpbrjZUs=
golang.org/x/image v0.0.0-20190227222117-0694c2d4d067/go.mod h1:kZ7UVZpmo3dzQBMxlp+ypCbDeSB+sBbTgSJuh5dn5js= golang.org/x/image v0.0.0-20190227222117-0694c2d4d067/go.mod h1:kZ7UVZpmo3dzQBMxlp+ypCbDeSB+sBbTgSJuh5dn5js=
@ -1890,9 +1884,7 @@ golang.zx2c4.com/wireguard v0.0.0-20210604143328-f9b48a961cd2/go.mod h1:laHzsbfM
golang.zx2c4.com/wireguard v0.0.0-20210927201915-bb745b2ea326/go.mod h1:SDoazCvdy7RDjBPNEMBwrXhomlmtG7svs8mgwWEqtVI= golang.zx2c4.com/wireguard v0.0.0-20210927201915-bb745b2ea326/go.mod h1:SDoazCvdy7RDjBPNEMBwrXhomlmtG7svs8mgwWEqtVI=
golang.zx2c4.com/wireguard/windows v0.3.14/go.mod h1:3P4IEAsb+BjlKZmpUXgy74c0iX9AVwwr3WcVJ8nPgME= golang.zx2c4.com/wireguard/windows v0.3.14/go.mod h1:3P4IEAsb+BjlKZmpUXgy74c0iX9AVwwr3WcVJ8nPgME=
gonum.org/v1/gonum v0.0.0-20180816165407-929014505bf4/go.mod h1:Y+Yx5eoAFn32cQvJDxZx5Dpnq+c3wtXuadVZAcxbbBo= gonum.org/v1/gonum v0.0.0-20180816165407-929014505bf4/go.mod h1:Y+Yx5eoAFn32cQvJDxZx5Dpnq+c3wtXuadVZAcxbbBo=
gonum.org/v1/gonum v0.8.2 h1:CCXrcPKiGGotvnN6jfUsKk4rRqm7q09/YbKb5xCEvtM=
gonum.org/v1/gonum v0.8.2/go.mod h1:oe/vMfY3deqTw+1EZJhuvEW2iwGF1bW9wwu7XCu0+v0= gonum.org/v1/gonum v0.8.2/go.mod h1:oe/vMfY3deqTw+1EZJhuvEW2iwGF1bW9wwu7XCu0+v0=
gonum.org/v1/netlib v0.0.0-20190313105609-8cb42192e0e0 h1:OE9mWmgKkjJyEmDAAtGMPjXu+YNeGvK9VTSHY6+Qihc=
gonum.org/v1/netlib v0.0.0-20190313105609-8cb42192e0e0/go.mod h1:wa6Ws7BG/ESfp6dHfk7C6KdzKA7wR7u/rKwOGE66zvw= gonum.org/v1/netlib v0.0.0-20190313105609-8cb42192e0e0/go.mod h1:wa6Ws7BG/ESfp6dHfk7C6KdzKA7wR7u/rKwOGE66zvw=
gonum.org/v1/plot v0.0.0-20190515093506-e2840ee46a6b/go.mod h1:Wt8AAjI+ypCyYX3nZBvf6cAIx93T+c/OS2HFAYskSZc= gonum.org/v1/plot v0.0.0-20190515093506-e2840ee46a6b/go.mod h1:Wt8AAjI+ypCyYX3nZBvf6cAIx93T+c/OS2HFAYskSZc=
google.golang.org/api v0.0.0-20160322025152-9bf6e6e569ff/go.mod h1:4mhQ8q/RsB7i+udVvVy5NUi08OU8ZlA0gRVgrF7VFY0= google.golang.org/api v0.0.0-20160322025152-9bf6e6e569ff/go.mod h1:4mhQ8q/RsB7i+udVvVy5NUi08OU8ZlA0gRVgrF7VFY0=

4
keyserver/producers/keychange.go
View file

@ -65,7 +65,7 @@ func (p *KeyChange) ProduceKeyChanges(keys []api.DeviceMessage) error {
logrus.WithFields(logrus.Fields{ logrus.WithFields(logrus.Fields{
"user_id": userID, "user_id": userID,
"num_key_changes": count, "num_key_changes": count,
}).Infof("Produced to key change topic '%s'", p.Topic) }).Tracef("Produced to key change topic '%s'", p.Topic)
} }
return nil return nil
} }
@ -103,6 +103,6 @@ func (p *KeyChange) ProduceSigningKeyUpdate(key eduapi.CrossSigningKeyUpdate) er
logrus.WithFields(logrus.Fields{ logrus.WithFields(logrus.Fields{
"user_id": key.UserID, "user_id": key.UserID,
}).Infof("Produced to cross-signing update topic '%s'", p.Topic) }).Tracef("Produced to cross-signing update topic '%s'", p.Topic)
return nil return nil
} }

26
mediaapi/routing/download.go
View file

@ -157,7 +157,7 @@ func (r *downloadRequest) jsonErrorResponse(w http.ResponseWriter, res util.JSON
// Set status code and write the body // Set status code and write the body
w.WriteHeader(res.Code) w.WriteHeader(res.Code)
r.Logger.WithField("code", res.Code).Infof("Responding (%d bytes)", len(resBytes)) r.Logger.WithField("code", res.Code).Tracef("Responding (%d bytes)", len(resBytes))
// we don't really care that much if we fail to write the error response // we don't really care that much if we fail to write the error response
w.Write(resBytes) // nolint: errcheck w.Write(resBytes) // nolint: errcheck
@ -293,11 +293,11 @@ func (r *downloadRequest) respondFromLocalFile(
"Base64Hash": r.MediaMetadata.Base64Hash, "Base64Hash": r.MediaMetadata.Base64Hash,
"FileSizeBytes": r.MediaMetadata.FileSizeBytes, "FileSizeBytes": r.MediaMetadata.FileSizeBytes,
"ContentType": r.MediaMetadata.ContentType, "ContentType": r.MediaMetadata.ContentType,
}).Info("No good thumbnail found. Responding with original file.") }).Trace("No good thumbnail found. Responding with original file.")
responseFile = file responseFile = file
responseMetadata = r.MediaMetadata responseMetadata = r.MediaMetadata
} else { } else {
r.Logger.Info("Responding with thumbnail") r.Logger.Trace("Responding with thumbnail")
responseFile = thumbFile responseFile = thumbFile
responseMetadata = thumbMetadata.MediaMetadata responseMetadata = thumbMetadata.MediaMetadata
} }
@ -307,7 +307,7 @@ func (r *downloadRequest) respondFromLocalFile(
"Base64Hash": r.MediaMetadata.Base64Hash, "Base64Hash": r.MediaMetadata.Base64Hash,
"FileSizeBytes": r.MediaMetadata.FileSizeBytes, "FileSizeBytes": r.MediaMetadata.FileSizeBytes,
"ContentType": r.MediaMetadata.ContentType, "ContentType": r.MediaMetadata.ContentType,
}).Info("Responding with file") }).Trace("Responding with file")
responseFile = file responseFile = file
responseMetadata = r.MediaMetadata responseMetadata = r.MediaMetadata
if err := r.addDownloadFilenameToHeaders(w, responseMetadata); err != nil { if err := r.addDownloadFilenameToHeaders(w, responseMetadata); err != nil {
@ -436,7 +436,7 @@ func (r *downloadRequest) getThumbnailFile(
"Width": thumbnailSize.Width, "Width": thumbnailSize.Width,
"Height": thumbnailSize.Height, "Height": thumbnailSize.Height,
"ResizeMethod": thumbnailSize.ResizeMethod, "ResizeMethod": thumbnailSize.ResizeMethod,
}).Info("Pre-generating thumbnail for immediate response.") }).Debug("Pre-generating thumbnail for immediate response.")
thumbnail, err = r.generateThumbnail( thumbnail, err = r.generateThumbnail(
ctx, filePath, *thumbnailSize, activeThumbnailGeneration, ctx, filePath, *thumbnailSize, activeThumbnailGeneration,
maxThumbnailGenerators, db, maxThumbnailGenerators, db,
@ -574,7 +574,7 @@ func (r *downloadRequest) getMediaMetadataFromActiveRequest(activeRemoteRequests
defer activeRemoteRequests.Unlock() defer activeRemoteRequests.Unlock()
if activeRemoteRequestResult, ok := activeRemoteRequests.MXCToResult[mxcURL]; ok { if activeRemoteRequestResult, ok := activeRemoteRequests.MXCToResult[mxcURL]; ok {
r.Logger.Info("Waiting for another goroutine to fetch the remote file.") r.Logger.Trace("Waiting for another goroutine to fetch the remote file.")
// NOTE: Wait unlocks and locks again internally. There is still a deferred Unlock() that will unlock this. // NOTE: Wait unlocks and locks again internally. There is still a deferred Unlock() that will unlock this.
activeRemoteRequestResult.Cond.Wait() activeRemoteRequestResult.Cond.Wait()
@ -604,7 +604,7 @@ func (r *downloadRequest) broadcastMediaMetadata(activeRemoteRequests *types.Act
defer activeRemoteRequests.Unlock() defer activeRemoteRequests.Unlock()
mxcURL := "mxc://" + string(r.MediaMetadata.Origin) + "/" + string(r.MediaMetadata.MediaID) mxcURL := "mxc://" + string(r.MediaMetadata.Origin) + "/" + string(r.MediaMetadata.MediaID)
if activeRemoteRequestResult, ok := activeRemoteRequests.MXCToResult[mxcURL]; ok { if activeRemoteRequestResult, ok := activeRemoteRequests.MXCToResult[mxcURL]; ok {
r.Logger.Info("Signalling other goroutines waiting for this goroutine to fetch the file.") r.Logger.Trace("Signalling other goroutines waiting for this goroutine to fetch the file.")
activeRemoteRequestResult.MediaMetadata = r.MediaMetadata activeRemoteRequestResult.MediaMetadata = r.MediaMetadata
activeRemoteRequestResult.Error = err activeRemoteRequestResult.Error = err
activeRemoteRequestResult.Cond.Broadcast() activeRemoteRequestResult.Cond.Broadcast()
@ -635,7 +635,7 @@ func (r *downloadRequest) fetchRemoteFileAndStoreMetadata(
"UploadName": r.MediaMetadata.UploadName, "UploadName": r.MediaMetadata.UploadName,
"FileSizeBytes": r.MediaMetadata.FileSizeBytes, "FileSizeBytes": r.MediaMetadata.FileSizeBytes,
"ContentType": r.MediaMetadata.ContentType, "ContentType": r.MediaMetadata.ContentType,
}).Info("Storing file metadata to media repository database") }).Debug("Storing file metadata to media repository database")
// FIXME: timeout db request // FIXME: timeout db request
if err := db.StoreMediaMetadata(ctx, r.MediaMetadata); err != nil { if err := db.StoreMediaMetadata(ctx, r.MediaMetadata); err != nil {
@ -669,7 +669,7 @@ func (r *downloadRequest) fetchRemoteFileAndStoreMetadata(
"Base64Hash": r.MediaMetadata.Base64Hash, "Base64Hash": r.MediaMetadata.Base64Hash,
"FileSizeBytes": r.MediaMetadata.FileSizeBytes, "FileSizeBytes": r.MediaMetadata.FileSizeBytes,
"ContentType": r.MediaMetadata.ContentType, "ContentType": r.MediaMetadata.ContentType,
}).Infof("Remote file cached") }).Debug("Remote file cached")
return nil return nil
} }
@ -717,7 +717,7 @@ func (r *downloadRequest) fetchRemoteFile(
absBasePath config.Path, absBasePath config.Path,
maxFileSizeBytes config.FileSizeBytes, maxFileSizeBytes config.FileSizeBytes,
) (types.Path, bool, error) { ) (types.Path, bool, error) {
r.Logger.Info("Fetching remote file") r.Logger.Debug("Fetching remote file")
// create request for remote file // create request for remote file
resp, err := r.createRemoteRequest(ctx, client) resp, err := r.createRemoteRequest(ctx, client)
@ -762,7 +762,7 @@ func (r *downloadRequest) fetchRemoteFile(
} }
} }
r.Logger.Info("Transferring remote file") r.Logger.Trace("Transferring remote file")
// The file data is hashed but is NOT used as the MediaID, unlike in Upload. The hash is useful as a // The file data is hashed but is NOT used as the MediaID, unlike in Upload. The hash is useful as a
// method of deduplicating files to save storage, as well as a way to conduct // method of deduplicating files to save storage, as well as a way to conduct
@ -776,7 +776,7 @@ func (r *downloadRequest) fetchRemoteFile(
return "", false, errors.New("file could not be downloaded from remote server") return "", false, errors.New("file could not be downloaded from remote server")
} }
r.Logger.Info("Remote file transferred") r.Logger.Trace("Remote file transferred")
// It's possible the bytesWritten to the temporary file is different to the reported Content-Length from the remote // It's possible the bytesWritten to the temporary file is different to the reported Content-Length from the remote
// request's response. bytesWritten is therefore used as it is what would be sent to clients when reading from the local // request's response. bytesWritten is therefore used as it is what would be sent to clients when reading from the local
@ -790,7 +790,7 @@ func (r *downloadRequest) fetchRemoteFile(
return "", false, fmt.Errorf("fileutils.MoveFileWithHashCheck: %w", err) return "", false, fmt.Errorf("fileutils.MoveFileWithHashCheck: %w", err)
} }
if duplicate { if duplicate {
r.Logger.WithField("dst", finalPath).Info("File was stored previously - discarding duplicate") r.Logger.WithField("dst", finalPath).Trace("File was stored previously - discarding duplicate")
// Continue on to store the metadata in the database // Continue on to store the metadata in the database
} }

16
roomserver/internal/input/input.go
View file

@ -33,6 +33,7 @@ import (
"github.com/matrix-org/gomatrixserverlib" "github.com/matrix-org/gomatrixserverlib"
"github.com/nats-io/nats.go" "github.com/nats-io/nats.go"
"github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus"
"github.com/sirupsen/logrus"
log "github.com/sirupsen/logrus" log "github.com/sirupsen/logrus"
"github.com/tidwall/gjson" "github.com/tidwall/gjson"
) )
@ -104,6 +105,11 @@ func (r *Inputer) Start() error {
if !errors.Is(err, context.DeadlineExceeded) && !errors.Is(err, context.Canceled) { if !errors.Is(err, context.DeadlineExceeded) && !errors.Is(err, context.Canceled) {
sentry.CaptureException(err) sentry.CaptureException(err)
} }
logrus.WithError(err).WithFields(logrus.Fields{
"room_id": roomID,
"event_id": inputRoomEvent.Event.EventID(),
"type": inputRoomEvent.Event.Type(),
}).Warn("Roomserver failed to process async event")
} }
_ = msg.Ack() _ = msg.Ack()
}) })
@ -120,7 +126,7 @@ func (r *Inputer) Start() error {
nats.DeliverAll(), nats.DeliverAll(),
// Ensure that NATS doesn't try to resend us something that wasn't done // Ensure that NATS doesn't try to resend us something that wasn't done
// within the period of time that we might still be processing it. // within the period of time that we might still be processing it.
nats.AckWait(MaximumProcessingTime+(time.Second*10)), nats.AckWait(MaximumMissingProcessingTime+(time.Second*10)),
) )
return err return err
} }
@ -146,6 +152,10 @@ func (r *Inputer) InputRoomEvents(
return return
} }
if _, err = r.JetStream.PublishMsg(msg); err != nil { if _, err = r.JetStream.PublishMsg(msg); err != nil {
logrus.WithError(err).WithFields(logrus.Fields{
"room_id": roomID,
"event_id": e.Event.EventID(),
}).Error("Roomserver failed to queue async event")
return return
} }
} }
@ -173,6 +183,10 @@ func (r *Inputer) InputRoomEvents(
if !errors.Is(err, context.DeadlineExceeded) && !errors.Is(err, context.Canceled) { if !errors.Is(err, context.DeadlineExceeded) && !errors.Is(err, context.Canceled) {
sentry.CaptureException(err) sentry.CaptureException(err)
} }
logrus.WithError(err).WithFields(logrus.Fields{
"room_id": roomID,
"event_id": inputRoomEvent.Event.EventID(),
}).Warn("Roomserver failed to process sync event")
} }
select { select {
case <-ctx.Done(): case <-ctx.Done():

26
roomserver/internal/input/input_events.go
View file

@ -41,7 +41,7 @@ func init() {
} }
// TODO: Does this value make sense? // TODO: Does this value make sense?
const MaximumProcessingTime = time.Minute * 2 const MaximumMissingProcessingTime = time.Minute * 2
var processRoomEventDuration = prometheus.NewHistogramVec( var processRoomEventDuration = prometheus.NewHistogramVec(
prometheus.HistogramOpts{ prometheus.HistogramOpts{
@ -66,11 +66,11 @@ var processRoomEventDuration = prometheus.NewHistogramVec(
// TODO: Break up function - we should probably do transaction ID checks before calling this. // TODO: Break up function - we should probably do transaction ID checks before calling this.
// nolint:gocyclo // nolint:gocyclo
func (r *Inputer) processRoomEvent( func (r *Inputer) processRoomEvent(
inctx context.Context, ctx context.Context,
input *api.InputRoomEvent, input *api.InputRoomEvent,
) (err error) { ) (err error) {
select { select {
case <-inctx.Done(): case <-ctx.Done():
// Before we do anything, make sure the context hasn't expired for this pending task. // Before we do anything, make sure the context hasn't expired for this pending task.
// If it has then we'll give up straight away — it's probably a synchronous input // If it has then we'll give up straight away — it's probably a synchronous input
// request and the caller has already given up, but the inbox task was still queued. // request and the caller has already given up, but the inbox task was still queued.
@ -78,13 +78,6 @@ func (r *Inputer) processRoomEvent(
default: default:
} }
// Wrap the context with a time limit. We'll allow no more than MaximumProcessingTime for
// everything that we need to do for this event, or it's possible that we could end up wedging
// the roomserver for a very long time.
var cancel context.CancelFunc
ctx, cancel := context.WithTimeout(inctx, MaximumProcessingTime)
defer cancel()
// Measure how long it takes to process this event. // Measure how long it takes to process this event.
started := time.Now() started := time.Now()
defer func() { defer func() {
@ -164,7 +157,7 @@ func (r *Inputer) processRoomEvent(
var rejectionErr error var rejectionErr error
if rejectionErr = gomatrixserverlib.Allowed(event, &authEvents); rejectionErr != nil { if rejectionErr = gomatrixserverlib.Allowed(event, &authEvents); rejectionErr != nil {
isRejected = true isRejected = true
logger.WithError(rejectionErr).Warnf("Event %s rejected", event.EventID()) logger.WithError(rejectionErr).Warnf("Event %s not allowed by auth events", event.EventID())
} }
// Accumulate the auth event NIDs. // Accumulate the auth event NIDs.
@ -183,7 +176,7 @@ func (r *Inputer) processRoomEvent(
// current room state. // current room state.
softfail, err = helpers.CheckForSoftFail(ctx, r.DB, headered, input.StateEventIDs) softfail, err = helpers.CheckForSoftFail(ctx, r.DB, headered, input.StateEventIDs)
if err != nil { if err != nil {
logger.WithError(err).Info("Error authing soft-failed event") logger.WithError(err).Warn("Error authing soft-failed event")
} }
} }
@ -273,7 +266,10 @@ func (r *Inputer) processRoomEvent(
// We stop here if the event is rejected: We've stored it but won't update forward extremities or notify anyone about it. // We stop here if the event is rejected: We've stored it but won't update forward extremities or notify anyone about it.
if isRejected || softfail { if isRejected || softfail {
logger.WithError(rejectionErr).WithField("soft_fail", softfail).Debug("Stored rejected event") logger.WithError(rejectionErr).WithFields(logrus.Fields{
"soft_fail": softfail,
"missing_prev": missingPrev,
}).Warn("Stored rejected event")
return rejectionErr return rejectionErr
} }
@ -344,6 +340,10 @@ func (r *Inputer) fetchAuthEvents(
known map[string]*types.Event, known map[string]*types.Event,
servers []gomatrixserverlib.ServerName, servers []gomatrixserverlib.ServerName,
) error { ) error {
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(ctx, MaximumMissingProcessingTime)
defer cancel()
unknown := map[string]struct{}{} unknown := map[string]struct{}{}
authEventIDs := event.AuthEventIDs() authEventIDs := event.AuthEventIDs()
if len(authEventIDs) == 0 { if len(authEventIDs) == 0 {

24
roomserver/internal/input/input_missing.go
View file

@ -37,6 +37,10 @@ type missingStateReq struct {
func (t *missingStateReq) processEventWithMissingState( func (t *missingStateReq) processEventWithMissingState(
ctx context.Context, e *gomatrixserverlib.Event, roomVersion gomatrixserverlib.RoomVersion, ctx context.Context, e *gomatrixserverlib.Event, roomVersion gomatrixserverlib.RoomVersion,
) error { ) error {
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(ctx, MaximumMissingProcessingTime)
defer cancel()
// We are missing the previous events for this events. // We are missing the previous events for this events.
// This means that there is a gap in our view of the history of the // This means that there is a gap in our view of the history of the
// room. There two ways that we can handle such a gap: // room. There two ways that we can handle such a gap:
@ -323,7 +327,7 @@ func (t *missingStateReq) lookupStateAfterEventLocally(ctx context.Context, room
queryReq := api.QueryEventsByIDRequest{ queryReq := api.QueryEventsByIDRequest{
EventIDs: missingEventList, EventIDs: missingEventList,
} }
util.GetLogger(ctx).WithField("count", len(missingEventList)).Infof("Fetching missing auth events") util.GetLogger(ctx).WithField("count", len(missingEventList)).Debugf("Fetching missing auth events")
var queryRes api.QueryEventsByIDResponse var queryRes api.QueryEventsByIDResponse
if err = t.queryer.QueryEventsByID(ctx, &queryReq, &queryRes); err != nil { if err = t.queryer.QueryEventsByID(ctx, &queryReq, &queryRes); err != nil {
return nil return nil
@ -378,7 +382,7 @@ retryAllowedState:
default: default:
return nil, fmt.Errorf("missing auth event %s and failed to look it up: %w", missing.AuthEventID, err2) return nil, fmt.Errorf("missing auth event %s and failed to look it up: %w", missing.AuthEventID, err2)
} }
util.GetLogger(ctx).Infof("fetched event %s", missing.AuthEventID) util.GetLogger(ctx).Tracef("fetched event %s", missing.AuthEventID)
resolvedStateEvents = append(resolvedStateEvents, h.Unwrap()) resolvedStateEvents = append(resolvedStateEvents, h.Unwrap())
goto retryAllowedState goto retryAllowedState
default: default:
@ -425,7 +429,7 @@ func (t *missingStateReq) getMissingEvents(ctx context.Context, e *gomatrixserve
missingResp = &m missingResp = &m
break break
} else { } else {
logger.WithError(err).Errorf("%s pushed us an event but %q did not respond to /get_missing_events", t.origin, server) logger.WithError(err).Warnf("%s pushed us an event but %q did not respond to /get_missing_events", t.origin, server)
if errors.Is(err, context.DeadlineExceeded) { if errors.Is(err, context.DeadlineExceeded) {
select { select {
case <-ctx.Done(): // the parent request context timed out case <-ctx.Done(): // the parent request context timed out
@ -438,7 +442,7 @@ func (t *missingStateReq) getMissingEvents(ctx context.Context, e *gomatrixserve
} }
if missingResp == nil { if missingResp == nil {
logger.WithError(err).Errorf( logger.WithError(err).Warnf(
"%s pushed us an event but %d server(s) couldn't give us details about prev_events via /get_missing_events - dropping this event until it can", "%s pushed us an event but %d server(s) couldn't give us details about prev_events via /get_missing_events - dropping this event until it can",
t.origin, len(t.servers), t.origin, len(t.servers),
) )
@ -450,7 +454,7 @@ func (t *missingStateReq) getMissingEvents(ctx context.Context, e *gomatrixserve
// Make sure events from the missingResp are using the cache - missing events // Make sure events from the missingResp are using the cache - missing events
// will be added and duplicates will be removed. // will be added and duplicates will be removed.
logger.Infof("get_missing_events returned %d events", len(missingResp.Events)) logger.Debugf("get_missing_events returned %d events", len(missingResp.Events))
for i, ev := range missingResp.Events { for i, ev := range missingResp.Events {
missingResp.Events[i] = t.cacheAndReturn(ev.Headered(roomVersion)).Unwrap() missingResp.Events[i] = t.cacheAndReturn(ev.Headered(roomVersion)).Unwrap()
} }
@ -470,7 +474,7 @@ Event:
} }
if !hasPrevEvent { if !hasPrevEvent {
err = fmt.Errorf("called /get_missing_events but server %s didn't return any prev_events with IDs %v", t.origin, shouldHaveSomeEventIDs) err = fmt.Errorf("called /get_missing_events but server %s didn't return any prev_events with IDs %v", t.origin, shouldHaveSomeEventIDs)
logger.WithError(err).Errorf( logger.WithError(err).Warnf(
"%s pushed us an event but couldn't give us details about prev_events via /get_missing_events - dropping this event until it can", "%s pushed us an event but couldn't give us details about prev_events via /get_missing_events - dropping this event until it can",
t.origin, t.origin,
) )
@ -561,7 +565,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
concurrentRequests := 8 concurrentRequests := 8
missingCount := len(missing) missingCount := len(missing)
util.GetLogger(ctx).WithField("room_id", roomID).WithField("event_id", eventID).Infof("lookupMissingStateViaStateIDs missing %d/%d events", missingCount, len(wantIDs)) util.GetLogger(ctx).WithField("room_id", roomID).WithField("event_id", eventID).Debugf("lookupMissingStateViaStateIDs missing %d/%d events", missingCount, len(wantIDs))
// If over 50% of the auth/state events from /state_ids are missing // If over 50% of the auth/state events from /state_ids are missing
// then we'll just call /state instead, otherwise we'll just end up // then we'll just call /state instead, otherwise we'll just end up
@ -573,7 +577,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
"room_id": roomID, "room_id": roomID,
"total_state": len(stateIDs.StateEventIDs), "total_state": len(stateIDs.StateEventIDs),
"total_auth_events": len(stateIDs.AuthEventIDs), "total_auth_events": len(stateIDs.AuthEventIDs),
}).Info("Fetching all state at event") }).Debug("Fetching all state at event")
return t.lookupMissingStateViaState(ctx, roomID, eventID, roomVersion) return t.lookupMissingStateViaState(ctx, roomID, eventID, roomVersion)
} }
@ -585,7 +589,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
"total_state": len(stateIDs.StateEventIDs), "total_state": len(stateIDs.StateEventIDs),
"total_auth_events": len(stateIDs.AuthEventIDs), "total_auth_events": len(stateIDs.AuthEventIDs),
"concurrent_requests": concurrentRequests, "concurrent_requests": concurrentRequests,
}).Info("Fetching missing state at event") }).Debug("Fetching missing state at event")
// Create a queue containing all of the missing event IDs that we want // Create a queue containing all of the missing event IDs that we want
// to retrieve. // to retrieve.
@ -622,7 +626,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
util.GetLogger(ctx).WithFields(logrus.Fields{ util.GetLogger(ctx).WithFields(logrus.Fields{
"event_id": missingEventID, "event_id": missingEventID,
"room_id": roomID, "room_id": roomID,
}).Info("Failed to fetch missing event") }).Warn("Failed to fetch missing event")
return return
} }
haveEventsMutex.Lock() haveEventsMutex.Lock()

2
roomserver/internal/perform/perform_invite.go
View file

@ -60,7 +60,7 @@ func (r *Inviter) PerformInvite(
"room_version": req.RoomVersion, "room_version": req.RoomVersion,
"target_user_id": targetUserID, "target_user_id": targetUserID,
"room_info_exists": info != nil, "room_info_exists": info != nil,
}).Info("processing invite event") }).Debug("processing invite event")
_, domain, _ := gomatrixserverlib.SplitID('@', targetUserID) _, domain, _ := gomatrixserverlib.SplitID('@', targetUserID)
isTargetLocal := domain == r.Cfg.Matrix.ServerName isTargetLocal := domain == r.Cfg.Matrix.ServerName

5
roomserver/internal/perform/perform_join.go
View file

@ -53,6 +53,11 @@ func (r *Joiner) PerformJoin(
) { ) {
roomID, joinedVia, err := r.performJoin(ctx, req) roomID, joinedVia, err := r.performJoin(ctx, req)
if err != nil { if err != nil {
logrus.WithContext(ctx).WithFields(logrus.Fields{
"room_id": req.RoomIDOrAlias,
"user_id": req.UserID,
"servers": req.ServerNames,
}).WithError(err).Error("Failed to join room")
sentry.CaptureException(err) sentry.CaptureException(err)
perr, ok := err.(*rsAPI.PerformError) perr, ok := err.(*rsAPI.PerformError)
if ok { if ok {

10
roomserver/internal/perform/perform_leave.go
View file

@ -27,6 +27,7 @@ import (
"github.com/matrix-org/dendrite/setup/config" "github.com/matrix-org/dendrite/setup/config"
"github.com/matrix-org/gomatrixserverlib" "github.com/matrix-org/gomatrixserverlib"
"github.com/matrix-org/util" "github.com/matrix-org/util"
"github.com/sirupsen/logrus"
) )
type Leaver struct { type Leaver struct {
@ -51,7 +52,14 @@ func (r *Leaver) PerformLeave(
return nil, fmt.Errorf("user %q does not belong to this homeserver", req.UserID) return nil, fmt.Errorf("user %q does not belong to this homeserver", req.UserID)
} }
if strings.HasPrefix(req.RoomID, "!") { if strings.HasPrefix(req.RoomID, "!") {
return r.performLeaveRoomByID(ctx, req, res) output, err := r.performLeaveRoomByID(ctx, req, res)
if err != nil {
logrus.WithContext(ctx).WithFields(logrus.Fields{
"room_id": req.RoomID,
"user_id": req.UserID,
}).WithError(err).Error("Failed to leave room")
}
return output, err
} }
return nil, fmt.Errorf("room ID %q is invalid", req.RoomID) return nil, fmt.Errorf("room ID %q is invalid", req.RoomID)
} }

2
syncapi/consumers/clientapi.go
View file

@ -85,7 +85,7 @@ func (s *OutputClientDataConsumer) onMessage(msg *nats.Msg) {
log.WithFields(log.Fields{ log.WithFields(log.Fields{
"type": output.Type, "type": output.Type,
"room_id": output.RoomID, "room_id": output.RoomID,
}).Info("received data from client API server") }).Debug("Received data from client API server")
streamPos, err := s.db.UpsertAccountData( streamPos, err := s.db.UpsertAccountData(
s.ctx, userID, output.RoomID, output.Type, s.ctx, userID, output.RoomID, output.Type,