Skip to content

Commit

Permalink
user: use structured logging
Browse files Browse the repository at this point in the history 
Signed-off-by: Sumner Evans <[email protected]>
  • Loading branch information
@sumnerevans
sumnerevans committed Dec 31, 2023
1 parent 57c0185 commit ece211b
Showing 1 changed file with 31 additions and 20 deletions.
51 changes: 31 additions & 20 deletions user.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -198,7 +198,7 @@ func (br *SignalBridge) NewUser(dbUser *database.User) *User {
user := &User{
User: dbUser,
bridge: br,
log: br.ZLog.With().Str("user_id", string(dbUser.MXID)).Logger(),
log: br.ZLog.With().Str("user_id", dbUser.MXID.String()).Logger(),

PermissionLevel: br.Config.Bridge.Permissions.Get(dbUser.MXID),
}
Expand All @@ -208,6 +208,7 @@ func (br *SignalBridge) NewUser(dbUser *database.User) *User {
}

func (user *User) ensureInvited(intent *appservice.IntentAPI, roomID id.RoomID, isDirect bool) (ok bool) {
log := user.log.With().Str("action", "ensure_invited").Str("room_id", roomID.String()).Logger()
if user.bridge.StateStore.GetMembership(roomID, user.MXID) == event.MembershipJoin {
ok = true
return
Expand All @@ -218,10 +219,10 @@ func (user *User) ensureInvited(intent *appservice.IntentAPI, roomID id.RoomID,
}
customPuppet := user.bridge.GetPuppetByCustomMXID(user.MXID)
if customPuppet != nil && customPuppet.CustomIntent() != nil {
user.log.Debug().Msgf("adding will_auto_accept for %s", user.MXID)
log.Debug().Msg("adding will_auto_accept to invite content")
extraContent["fi.mau.will_auto_accept"] = true
} else {
user.log.Debug().Msgf("NOT adding will_auto_accept for %s", user.MXID)
log.Debug().Msg("NOT adding will_auto_accept to invite content")
}
_, err := intent.InviteUser(roomID, &mautrix.ReqInviteUser{UserID: user.MXID}, extraContent)
var httpErr mautrix.HTTPError
Expand All @@ -230,16 +231,16 @@ func (user *User) ensureInvited(intent *appservice.IntentAPI, roomID id.RoomID,
ok = true
return
} else if err != nil {
user.log.Warn().Err(err).Msgf("Failed to invite user to %s", roomID)
log.Warn().Err(err).Msg("Failed to invite user to room")
} else {
ok = true
}

if customPuppet != nil && customPuppet.CustomIntent() != nil {
user.log.Debug().Msgf("ensuring joined for %s", user.MXID)
log.Debug().Msg("ensuring custom puppet is joined")
err = customPuppet.CustomIntent().EnsureJoined(roomID, appservice.EnsureJoinedParams{IgnoreCache: true})
if err != nil {
user.log.Warn().Err(err).Msgf("Failed to auto-join %s", roomID)
log.Warn().Err(err).Msg("Failed to auto-join custom puppet")
ok = false
} else {
ok = true
Expand Down Expand Up @@ -355,7 +356,9 @@ func (user *User) startupTryConnect(retryCount int) {
for {
var connectionStatus signalmeow.SignalConnectionStatus
if peekedConnectionStatus.Event != signalmeow.SignalConnectionEventNone {
user.log.Debug().Msgf("Using peeked connectionStatus event: %v", peekedConnectionStatus.Event)
user.log.Debug().
Str("peeked_connection_status_event", peekedConnectionStatus.Event.String()).
Msg("Using peeked connectionStatus event")
connectionStatus = peekedConnectionStatus
peekedConnectionStatus = signalmeow.SignalConnectionStatus{}
} else {
Expand Down Expand Up @@ -505,18 +508,22 @@ func (user *User) Connect() {
func (user *User) populateSignalDevice() *signalmeow.Device {
user.Lock()
defer user.Unlock()
log := user.log.With().
Str("action", "populate_signal_device").
Str("signal_id", user.SignalID.String()).
Logger()

if user.SignalID == uuid.Nil {
return nil
}

device, err := user.bridge.MeowStore.DeviceByAci(user.SignalID.String())
if err != nil {
user.log.Err(err).Msgf("problem looking up aci %s", user.SignalID)
log.Err(err).Msg("problem looking up ACI")
return nil
}
if device == nil {
user.log.Err(ErrNotLoggedIn).Msgf("no device found for aci %s", user.SignalID)
log.Err(ErrNotLoggedIn).Msg("no device found for ACI")
return nil
}

Expand All @@ -526,26 +533,30 @@ func (user *User) populateSignalDevice() *signalmeow.Device {
}

func updatePuppetWithSignalContact(ctx context.Context, user *User, puppet *Puppet, newContactAvatar *signalmeow.ContactAvatar) error {
log := user.log.With().
Str("action", "update_puppet_with_signal_contact").
Str("signal_id", puppet.SignalID.String()).
Logger()
contact, newProfileAvatar, err := user.SignalDevice.ContactByIDWithProfileAvatar(puppet.SignalID.String())
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error retrieving contact")
log.Err(err).Msg("error retrieving contact")
return err
}

name := user.bridge.Config.Bridge.FormatDisplayname(contact)
if name != puppet.Name {
user.log.Debug().Msgf("updatePuppetWithSignalContact: updating puppet name to %s", name)
log.Debug().Str("new_name", name).Msg("updating puppet name")
puppet.Name = name
puppet.NameSet = false
err = puppet.DefaultIntent().SetDisplayName(name)
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error setting display name")
log.Err(err).Msg("error setting display name")
return err
}
puppet.NameSet = true
err = puppet.Update(ctx)
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error updating puppet with new name")
log.Err(err).Msg("error updating puppet with new name")
return err
}
}
Expand All @@ -562,29 +573,29 @@ func updatePuppetWithSignalContact(ctx context.Context, user *User, puppet *Pupp
}

if preferredAvatarHash == "" && puppet.AvatarSet {
user.log.Debug().Msg("updatePuppetWithSignalContact: clearing avatar")
log.Debug().Msg("clearing avatar")
puppet.AvatarSet = false
puppet.AvatarURL = id.ContentURI{}
puppet.AvatarHash = ""
err = puppet.DefaultIntent().SetAvatarURL(id.ContentURI{})
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error clearing avatar url")
log.Err(err).Msg("error clearing avatar url")
return err
}
err = puppet.Update(ctx)
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error updating puppet while clearing avatar")
log.Err(err).Msg("error updating puppet while clearing avatar")
return err
}
return nil
}

// If avatar is set, we must have a new avatar image, so update it
if newAvatar != nil {
user.log.Debug().Msg("updatePuppetWithSignalContact: uploading avatar")
log.Debug().Msg("uploading avatar")
avatarURL, err := puppet.DefaultIntent().UploadBytes(newAvatar.Image, newAvatar.ContentType)
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error uploading avatar")
log.Err(err).Msg("error uploading avatar")
return err
}
puppet.AvatarURL = avatarURL.ContentURI
Expand All @@ -593,12 +604,12 @@ func updatePuppetWithSignalContact(ctx context.Context, user *User, puppet *Pupp

err = puppet.DefaultIntent().SetAvatarURL(avatarURL.ContentURI)
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error setting avatar url")
log.Err(err).Msg("error setting avatar URL")
return err
}
err = puppet.Update(ctx)
if err != nil {
user.log.Err(err).Msg("updatePuppetWithSignalContact: error updating puppet with new avatar")
log.Err(err).Msg("error updating puppet with new avatar")
return err
}
}
Expand Down

0 comments on commit ece211b

Please sign in to comment.