Resync all puppets after app state sync completes

commands.go

@@ -967,7 +967,7 @@ func (handler *CommandHandler) CommandPM(ce *CommandEvent) {
 
 	handler.log.Debugln("Importing", targetUser.JID, "for", user)
 	puppet := user.bridge.GetPuppetByJID(targetUser.JID)
-	puppet.SyncContact(user, true)
+	puppet.SyncContact(user, true, "manual pm command")
 	portal := user.GetPortalByJID(puppet.JID)
 	if len(portal.MXID) > 0 {
 		ok := portal.ensureUserInvited(user)

portal.go

@@ -503,20 +503,13 @@ func (portal *Portal) getMessagePuppet(user *User, info *types.MessageInfo) *Pup
 		return portal.bridge.GetPuppetByJID(portal.Key.JID)
 	} else {
 		puppet := portal.bridge.GetPuppetByJID(info.Sender)
-		puppet.SyncContact(user, true)
+		puppet.SyncContact(user, true, "handling message")
 		return puppet
 	}
 }
 
 func (portal *Portal) getMessageIntent(user *User, info *types.MessageInfo) *appservice.IntentAPI {
-	if info.IsFromMe {
-		return portal.bridge.GetPuppetByJID(user.JID).IntentFor(portal)
-	} else if portal.IsPrivateChat() {
-		return portal.MainIntent()
-	}
-	puppet := portal.bridge.GetPuppetByJID(info.Sender)
-	puppet.SyncContact(user, true)
-	return puppet.IntentFor(portal)
+	return portal.getMessagePuppet(user, info).IntentFor(portal)
 }
 
 func (portal *Portal) finishHandling(existing *database.Message, message *types.MessageInfo, mxid id.EventID, decryptionError bool) {
@@ -578,7 +571,7 @@ func (portal *Portal) SyncParticipants(source *User, metadata *types.GroupInfo)
 	for _, participant := range metadata.Participants {
 		participantMap[participant.JID] = true
 		puppet := portal.bridge.GetPuppetByJID(participant.JID)
-		puppet.SyncContact(source, true)
+		puppet.SyncContact(source, true, "group participant")
 		user := portal.bridge.GetUserByJID(participant.JID)
 		if user != nil {
 			portal.ensureUserInvited(user)
@@ -977,7 +970,7 @@ func (portal *Portal) CreateMatrixRoom(user *User, groupInfo *types.GroupInfo, i
 	//var broadcastMetadata *types.BroadcastListInfo
 	if portal.IsPrivateChat() {
 		puppet := portal.bridge.GetPuppetByJID(portal.Key.JID)
-		puppet.SyncContact(user, true)
+		puppet.SyncContact(user, true, "creating private chat portal")
 		if portal.bridge.Config.Bridge.PrivateChatPortalMeta {
 			portal.Name = puppet.Displayname
 			portal.AvatarURL = puppet.AvatarURL
@@ -1476,7 +1469,7 @@ func (portal *Portal) HandleWhatsAppInvite(source *User, senderJID *types.JID, j
 	}
 	for _, jid := range jids {
 		puppet := portal.bridge.GetPuppetByJID(jid)
-		puppet.SyncContact(source, true)
+		puppet.SyncContact(source, true, "handling whatsapp invite")
 		content := event.Content{
 			Parsed: event.MemberEventContent{
 				Membership:  "invite",

puppet.go

@@ -232,6 +232,7 @@ func (puppet *Puppet) UpdateAvatar(source *User) bool {
 	if err != nil {
 		puppet.log.Warnln("Failed to set avatar:", err)
 	}
+	puppet.log.Debugln("Updated avatar", puppet.Avatar, "->", avatar.ID)
 	puppet.Avatar = avatar.ID
 	go puppet.updatePortalAvatar()
 	return true
@@ -289,16 +290,16 @@ func (puppet *Puppet) updatePortalName() {
 	})
 }
 
-func (puppet *Puppet) SyncContact(source *User, onlyIfNoName bool) {
+func (puppet *Puppet) SyncContact(source *User, onlyIfNoName bool, reason string) {
 	if onlyIfNoName && len(puppet.Displayname) > 0 {
 		return
 	}
 
 	contact, err := source.Client.Store.Contacts.GetContact(puppet.JID)
 	if err != nil {
-		puppet.log.Warnfln("Failed to get contact info through %s in SyncContact: %v", source.MXID)
+		puppet.log.Warnfln("Failed to get contact info through %s in SyncContact: %v (sync reason: %s)", source.MXID, reason)
 	} else if !contact.Found {
-		puppet.log.Warnfln("No contact info found through %s in SyncContact", source.MXID)
+		puppet.log.Warnfln("No contact info found through %s in SyncContact (sync reason: %s)", source.MXID, reason)
 	}
 	puppet.Sync(source, contact)
 }

user.go

@@ -383,6 +383,8 @@ func (user *User) HandleEvent(event interface{}) {
 			if err != nil {
 				user.log.Warnln("Failed to send presence after app state sync:", err)
 			}
+		} else if v.Name == appstate.WAPatchCriticalUnblockLow {
+			go user.resyncPuppets()
 		}
 	case *events.PushNameSetting:
 		// Send presence available when connecting and when the pushname is changed.
@@ -403,9 +405,9 @@ func (user *User) HandleEvent(event interface{}) {
 		go user.sendBridgeState(BridgeState{StateEvent: StateTransientDisconnect})
 		user.bridge.Metrics.TrackConnectionState(user.JID, false)
 	case *events.Contact:
-		go user.syncPuppet(v.JID)
+		go user.syncPuppet(v.JID, "contact event")
 	case *events.PushName:
-		go user.syncPuppet(v.JID)
+		go user.syncPuppet(v.JID, "push name event")
 	case *events.GroupInfo:
 		go user.handleGroupUpdate(v)
 	case *events.JoinedGroup:
@@ -620,8 +622,20 @@ func (user *User) GetPortalByJID(jid types.JID) *Portal {
 	return user.bridge.GetPortalByJID(database.NewPortalKey(jid, user.JID))
 }
 
-func (user *User) syncPuppet(jid types.JID) {
-	user.bridge.GetPuppetByJID(jid).SyncContact(user, false)
+func (user *User) syncPuppet(jid types.JID, reason string) {
+	user.bridge.GetPuppetByJID(jid).SyncContact(user, false, reason)
+}
+
+func (user *User) resyncPuppets() {
+	contacts, err := user.Client.Store.Contacts.GetAllContacts()
+	if err != nil {
+		user.log.Errorln("Failed to get all contacts to sync puppets:", err)
+		return
+	}
+	for jid, contact := range contacts {
+		puppet := user.bridge.GetPuppetByJID(jid)
+		puppet.Sync(user, contact)
+	}
 }
 
 const WATypingTimeout = 15 * time.Second
@@ -769,12 +783,13 @@ func (user *User) handleGroupUpdate(evt *events.GroupInfo) {
 func (user *User) handlePictureUpdate(evt *events.Picture) {
 	if evt.JID.Server == types.DefaultUserServer {
 		puppet := user.bridge.GetPuppetByJID(evt.JID)
+		user.log.Debugfln("Received picture update for puppet %s (current: %s, new: %s)", evt.JID, puppet.Avatar, evt.PictureID)
 		if puppet.Avatar != evt.PictureID {
 			puppet.UpdateAvatar(user)
 		}
-	} else {
-		portal := user.GetPortalByJID(evt.JID)
-		if portal != nil && portal.Avatar != evt.PictureID {
+	} else if portal := user.GetPortalByJID(evt.JID); portal != nil {
+		user.log.Debugfln("Received picture update for portal %s (current: %s, new: %s)", evt.JID, portal.Avatar, evt.PictureID)
+		if portal.Avatar != evt.PictureID {
 			portal.UpdateAvatar(user, evt.Author, true)
 		}
 	}