Improve startup sync timeout handling

commands.go

@@ -138,11 +138,9 @@ const cmdLoginHelp = `login - Authenticate this Bridge as WhatsApp Web Client`
 
 // CommandLogin handles login command
 func (handler *CommandHandler) CommandLogin(ce *CommandEvent) {
-	if ce.User.Conn == nil {
+	if !ce.User.Connect(true) {
-		if !ce.User.Connect(true) {
+		ce.User.log.Debugln("Connect() returned false, assuming error was logged elsewhere and canceling login.")
-			ce.User.log.Debugln("Connect() returned false, assuming error was logged elsewhere and canceling login.")
+		return
-			return
-		}
 	}
 	ce.User.Login(ce)
 }

config/bridge.go

@@ -39,7 +39,8 @@ type BridgeConfig struct {
 	MaxConnectionAttempts int  `yaml:"max_connection_attempts"`
 	ConnectionRetryDelay  int  `yaml:"connection_retry_delay"`
 	ReportConnectionRetry bool `yaml:"report_connection_retry"`
-	ContactWaitDelay      int  `yaml:"contact_wait_delay"`
+	ChatListWait          int  `yaml:"chat_list_wait"`
+	PortalSyncWait        int  `yaml:"portal_sync_wait"`
 
 	CallNotices struct {
 		Start bool `yaml:"start"`
@@ -74,7 +75,8 @@ func (bc *BridgeConfig) setDefaults() {
 	bc.MaxConnectionAttempts = 3
 	bc.ConnectionRetryDelay = -1
 	bc.ReportConnectionRetry = true
-	bc.ContactWaitDelay = 30
+	bc.ChatListWait = 30
+	bc.PortalSyncWait = 600
 
 	bc.CallNotices.Start = true
 	bc.CallNotices.End = true

database/statestore.go

@@ -17,6 +17,7 @@
 package database
 
 import (
+	"database/sql"
 	"encoding/json"
 	"fmt"
 	"sync"
@@ -91,11 +92,9 @@ func (store *SQLStateStore) GetRoomMemberships(roomID string) map[string]mautrix
 func (store *SQLStateStore) GetMembership(roomID, userID string) mautrix.Membership {
 	row := store.db.QueryRow("SELECT membership FROM mx_user_profile WHERE room_id=$1 AND user_id=$2", roomID, userID)
 	membership := mautrix.MembershipLeave
-	if row != nil {
+	err := row.Scan(&membership)
-		err := row.Scan(&membership)
+	if err != nil && err != sql.ErrNoRows {
-		if err != nil {
+		store.log.Warnfln("Failed to scan membership of %s in %s: %v", userID, roomID, err)
-			store.log.Warnfln("Failed to scan membership of %s in %s: %v", userID, roomID, err)
-		}
 	}
 	return membership
 }

example-config.yaml

@@ -74,7 +74,10 @@ bridge:
     report_connection_retry: true
     # Maximum number of seconds to wait for chats to be sent at startup.
     # If this is too low and you have lots of chats, it could cause backfilling to fail.
-    contact_wait_delay: 30
+    chat_list_wait: 30
+    # Maximum number of seconds to wait to sync portals before force unlocking message processing.
+    # If this is too low and you have lots of chats, it could cause backfilling to fail.
+    portal_sync_wait: 600
 
     # Whether or not to send call start/end notices to Matrix.
     call_notices:

matrix.go

@@ -191,6 +191,7 @@ func (mx *MatrixHandler) HandleMessage(evt *mautrix.Event) {
 	}
 
 	if !user.HasSession() {
+		mx.log.Debugln("Ignoring message from", user.MXID, "in", evt.RoomID, "as user has no session")
 		return
 	} else if !user.IsConnected() {
 		msg := format.RenderMarkdown(fmt.Sprintf("\u26a0 You are not connected to WhatsApp, so your message was not bridged. " +

user.go

@@ -55,7 +55,8 @@ type User struct {
 
 	cleanDisconnection bool
 
-	syncPortalsDone chan struct{}
+	chatListReceived chan struct{}
+	syncPortalsDone  chan struct{}
 
 	messages chan PortalMessage
 	syncLock sync.Mutex
@@ -143,8 +144,9 @@ func (bridge *Bridge) NewUser(dbUser *database.User) *User {
 		bridge: bridge,
 		log:    bridge.Log.Sub("User").Sub(string(dbUser.MXID)),
 
+		chatListReceived: make(chan struct{}, 1),
 		syncPortalsDone: make(chan struct{}, 1),
-		messages: make(chan PortalMessage, 256),
+		messages:        make(chan PortalMessage, 256),
 	}
 	user.Whitelisted = user.bridge.Config.Bridge.Permissions.IsWhitelisted(user.MXID)
 	user.Admin = user.bridge.Config.Bridge.Permissions.IsAdmin(user.MXID)
@@ -350,17 +352,25 @@ func (user *User) PostLogin() {
 
 func (user *User) intPostLogin() {
 	user.createCommunity()
+	defer user.syncLock.Unlock()
 
 	select {
-	case <- user.syncPortalsDone:
+	case <-user.chatListReceived:
+		user.log.Debugln("Chat list receive confirmation received in PostLogin")
+	case <-time.After(time.Duration(user.bridge.Config.Bridge.ChatListWait) * time.Second):
+		user.log.Warnln("Timed out waiting for chat list to arrive! Unlocking processing of incoming messages.")
+		return
+	}
+	select {
+	case <-user.syncPortalsDone:
 		user.log.Debugln("Post-login portal sync complete, unlocking processing of incoming messages.")
-	case <- time.After(time.Duration(user.bridge.Config.Bridge.ContactWaitDelay) * time.Second):
+	case <-time.After(time.Duration(user.bridge.Config.Bridge.PortalSyncWait) * time.Second):
 		user.log.Warnln("Timed out waiting for chat list to arrive! Unlocking processing of incoming messages.")
 	}
-	user.syncLock.Unlock()
 }
 
 func (user *User) HandleChatList(chats []whatsapp.Chat) {
+	user.log.Infoln("Chat list received")
 	chatMap := make(map[string]whatsapp.Chat)
 	for _, chat := range user.Conn.Store.Chats {
 		chatMap[chat.Jid] = chat
@@ -368,6 +378,10 @@ func (user *User) HandleChatList(chats []whatsapp.Chat) {
 	for _, chat := range chats {
 		chatMap[chat.Jid] = chat
 	}
+	select {
+	case user.chatListReceived <- struct{}{}:
+	default:
+	}
 	go user.syncPortals(chatMap, false)
 }