Modify some log levels

This commit is contained in:
Neil Alexander 2022-01-31 09:35:08 +00:00
parent 4281976df9
commit 4846acbc1e
No known key found for this signature in database
GPG key ID: A02A2019A2BB0944
7 changed files with 44 additions and 31 deletions

View file

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

View file

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

View file

@ -162,7 +162,7 @@ func Send(
t.TransactionID = txnID
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())
if jsonErr != nil {
@ -221,7 +221,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
verReq := api.QueryRoomVersionForRoomRequest{RoomID: roomID}
verRes := api.QueryRoomVersionForRoomResponse{}
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 ""
}
roomVersions[roomID] = verRes.RoomVersion
@ -234,7 +234,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
RoomID string `json:"room_id"`
}
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
// failure in the PDU results
continue
@ -255,7 +255,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
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
}
if api.IsServerBannedFromRoom(ctx, t.rsAPI, event.RoomID(), t.Origin) {
@ -265,7 +265,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
continue
}
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{
Error: err.Error(),
}
@ -287,7 +287,7 @@ func (t *txnReq) processTransaction(ctx context.Context) (*gomatrixserverlib.Res
nil,
true,
); 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{
Error: err.Error(),
}
@ -314,16 +314,16 @@ func (t *txnReq) processEDUs(ctx context.Context) {
Typing bool `json:"typing"`
}
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
}
_, domain, err := gomatrixserverlib.SplitID('@', typingPayload.UserID)
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
}
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
}
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
var directPayload gomatrixserverlib.ToDeviceMessage
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
}
for userID, byUser := range directPayload.Messages {
@ -355,7 +355,7 @@ func (t *txnReq) processEDUs(ctx context.Context) {
payload := map[string]eduserverAPI.FederationReceiptMRead{}
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
}
@ -363,11 +363,11 @@ func (t *txnReq) processEDUs(ctx context.Context) {
for userID, mread := range receipt.User {
_, domain, err := gomatrixserverlib.SplitID('@', userID)
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
}
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
}
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 {
util.GetLogger(ctx).WithError(err).WithFields(logrus.Fields{
"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
}
inputReq := &eduserverAPI.InputCrossSigningKeyUpdateRequest{

View file

@ -323,7 +323,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
@ -378,7 +378,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:
@ -425,7 +425,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
@ -438,7 +438,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),
)
@ -450,7 +450,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()
}
@ -470,7 +470,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,
)
@ -561,7 +561,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
@ -573,7 +573,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)
}
@ -585,7 +585,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.
@ -622,7 +622,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()

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

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 {

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)
}