hoernschen/dendrite
1
0
Fork 0
mirror of https://github.com/hoernschen/dendrite.git synced 2025-07-29 12:42:46 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions

Tweak some logging (#2130)

Browse source 
* Modify some log levels

* Update gomatrixserverlib to matrix-org/gomatrixserverlib@336334f

* Update gomatrixserverlib to matrix-org/gomatrixserverlib@cde7ac8

* Demote warning about key change producer

* Add more useful roomserver logging

* Further tweaking
This commit is contained in:
Neil Alexander 2022-01-31 10:48:28 +00:00 • committed by GitHub
parent eb8e770e99
commit ba1a9b98b7
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
13 changed files with 77 additions and 57 deletions
Download patch file Download diff file Expand all files Collapse all files

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

@ -33,6 +33,7 @@ import (
"github.com/matrix-org/gomatrixserverlib"
"github.com/nats-io/nats.go"
"github.com/prometheus/client_golang/prometheus"
"github.com/sirupsen/logrus"
log "github.com/sirupsen/logrus"
"github.com/tidwall/gjson"
)
@ -104,6 +105,11 @@ func (r *Inputer) Start() error {
if !errors.Is(err, context.DeadlineExceeded) && !errors.Is(err, context.Canceled) {
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()
})
@ -146,6 +152,10 @@ func (r *Inputer) InputRoomEvents(
return
}
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
}
}
@ -173,6 +183,10 @@ func (r *Inputer) InputRoomEvents(
if !errors.Is(err, context.DeadlineExceeded) && !errors.Is(err, context.Canceled) {
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 {
case <-ctx.Done():

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

@ -327,7 +327,7 @@ func (t *missingStateReq) lookupStateAfterEventLocally(ctx context.Context, room
queryReq := api.QueryEventsByIDRequest{
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
if err = t.queryer.QueryEventsByID(ctx, &queryReq, &queryRes); err != nil {
return nil
@ -382,7 +382,7 @@ retryAllowedState:
default:
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())
goto retryAllowedState
default:
@ -429,7 +429,7 @@ func (t *missingStateReq) getMissingEvents(ctx context.Context, e *gomatrixserve
missingResp = &m
break
} 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) {
select {
case <-ctx.Done(): // the parent request context timed out
@ -442,7 +442,7 @@ func (t *missingStateReq) getMissingEvents(ctx context.Context, e *gomatrixserve
}
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",
t.origin, len(t.servers),
)
@ -454,7 +454,7 @@ func (t *missingStateReq) getMissingEvents(ctx context.Context, e *gomatrixserve
// Make sure events from the missingResp are using the cache - missing events
// 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 {
missingResp.Events[i] = t.cacheAndReturn(ev.Headered(roomVersion)).Unwrap()
}
@ -474,7 +474,7 @@ Event:
}
if !hasPrevEvent {
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",
t.origin,
)
@ -565,7 +565,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
concurrentRequests := 8
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
// then we'll just call /state instead, otherwise we'll just end up
@ -577,7 +577,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
"room_id": roomID,
"total_state": len(stateIDs.StateEventIDs),
"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)
}
@ -589,7 +589,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
"total_state": len(stateIDs.StateEventIDs),
"total_auth_events": len(stateIDs.AuthEventIDs),
"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
// to retrieve.
@ -626,7 +626,7 @@ func (t *missingStateReq) lookupMissingStateViaStateIDs(ctx context.Context, roo
util.GetLogger(ctx).WithFields(logrus.Fields{
"event_id": missingEventID,
"room_id": roomID,
}).Info("Failed to fetch missing event")
}).Warn("Failed to fetch missing event")
return
}
haveEventsMutex.Lock()

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

@ -60,7 +60,7 @@ func (r *Inviter) PerformInvite(
"room_version": req.RoomVersion,
"target_user_id": targetUserID,
"room_info_exists": info != nil,
}).Info("processing invite event")
}).Debug("processing invite event")
_, domain, _ := gomatrixserverlib.SplitID('@', targetUserID)
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)
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)
perr, ok := err.(*rsAPI.PerformError)
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/gomatrixserverlib"
"github.com/matrix-org/util"
"github.com/sirupsen/logrus"
)
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)
}
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)
}