From 6d506e681b14ac015627055bfd479e86f2f0e9ef Mon Sep 17 00:00:00 2001 From: k1ngsterr1 Date: Fri, 16 Jan 2026 17:11:50 +0500 Subject: [PATCH] feat: Enhance logging and state management in Protocol and MessageRepository; improve dialog read status handling in ChatViewModel --- .../messenger/data/MessageRepository.kt | 13 +- .../com/rosetta/messenger/network/Protocol.kt | 119 +++++++++++++----- .../messenger/network/ProtocolManager.kt | 20 ++- .../messenger/ui/chats/ChatViewModel.kt | 21 +++- 4 files changed, 132 insertions(+), 41 deletions(-) diff --git a/app/src/main/java/com/rosetta/messenger/data/MessageRepository.kt b/app/src/main/java/com/rosetta/messenger/data/MessageRepository.kt index a9d1210..235e2e8 100644 --- a/app/src/main/java/com/rosetta/messenger/data/MessageRepository.kt +++ b/app/src/main/java/com/rosetta/messenger/data/MessageRepository.kt @@ -310,13 +310,17 @@ class MessageRepository private constructor(private val context: Context) { // ✅ Проверяем существование перед вставкой (защита от дубликатов) val stillExists = messageDao.messageExists(account, messageId) + android.util.Log.d("MessageRepo", "📥 INCOMING: messageId=${messageId.take(16)}..., stillExists=$stillExists") + if (!stillExists) { // Сохраняем в БД только если сообщения нет messageDao.insertMessage(entity) + android.util.Log.d("MessageRepo", "📥 INSERTED message with read=0, fromMe=0") } - // Обновляем диалог + // Обновляем диалог ПОСЛЕ вставки сообщения updateDialog(packet.fromPublicKey, plainText, packet.timestamp, incrementUnread = true) + android.util.Log.d("MessageRepo", "📥 Dialog updated") // 🔥 Запрашиваем информацию о пользователе для отображения имени вместо ключа requestUserInfo(packet.fromPublicKey) @@ -469,21 +473,25 @@ class MessageRepository private constructor(private val context: Context) { val account = currentAccount ?: return val privateKey = currentPrivateKey ?: return + android.util.Log.d("MessageRepo", "📊 updateDialog: opponent=${opponentKey.take(16)}..., incrementUnread=$incrementUnread") try { // 🔥 КРИТИЧНО: Сначала считаем реальное количество непрочитанных из messages val unreadCount = messageDao.getUnreadCountForDialog(account, opponentKey) + android.util.Log.d("MessageRepo", "📊 unreadCount from DB: $unreadCount") // 🔒 Шифруем lastMessage val encryptedLastMessage = CryptoManager.encryptWithPassword(lastMessage, privateKey) // Проверяем существует ли диалог val existing = dialogDao.getDialog(account, opponentKey) + android.util.Log.d("MessageRepo", "📊 existing dialog: ${existing != null}, currentUnread=${existing?.unreadCount}") if (existing != null) { // Обновляем существующий диалог dialogDao.updateLastMessage(account, opponentKey, encryptedLastMessage, timestamp) dialogDao.updateUnreadCount(account, opponentKey, unreadCount) + android.util.Log.d("MessageRepo", "📊 UPDATED dialog unread to: $unreadCount") } else { // Создаем новый диалог dialogDao.insertDialog(DialogEntity( @@ -493,9 +501,12 @@ class MessageRepository private constructor(private val context: Context) { lastMessageTimestamp = timestamp, unreadCount = unreadCount )) + android.util.Log.d("MessageRepo", "📊 CREATED new dialog with unread: $unreadCount") } } catch (e: Exception) { + android.util.Log.e("MessageRepo", "📊 ERROR in updateDialog: ${e.message}") + e.printStackTrace() } } diff --git a/app/src/main/java/com/rosetta/messenger/network/Protocol.kt b/app/src/main/java/com/rosetta/messenger/network/Protocol.kt index 8f5aea6..a849982 100644 --- a/app/src/main/java/com/rosetta/messenger/network/Protocol.kt +++ b/app/src/main/java/com/rosetta/messenger/network/Protocol.kt @@ -49,11 +49,44 @@ class Protocol( private var handshakeComplete = false private var handshakeJob: Job? = null + // 🔍 Диагностика соединения + private var reconnectAttempts = 0 + private var lastStateChangeTime = System.currentTimeMillis() + private var lastSuccessfulConnection = 0L + private val scope = CoroutineScope(Dispatchers.IO + SupervisorJob()) private val _state = MutableStateFlow(ProtocolState.DISCONNECTED) val state: StateFlow = _state.asStateFlow() + /** + * 🔍 Безопасное изменение состояния с подробным логированием + */ + private fun setState(newState: ProtocolState, reason: String = "") { + val oldState = _state.value + val now = System.currentTimeMillis() + val timeSinceLastChange = now - lastStateChangeTime + + if (oldState != newState) { + log("🔄 STATE CHANGE: $oldState -> $newState (${timeSinceLastChange}ms since last change)") + if (reason.isNotEmpty()) { + log(" Reason: $reason") + } + log(" Reconnect attempts: $reconnectAttempts") + log(" Last successful: ${if (lastSuccessfulConnection > 0) "${(now - lastSuccessfulConnection)/1000}s ago" else "never"}") + + _state.value = newState + lastStateChangeTime = now + + // Сброс счетчика при успешном подключении + if (newState == ProtocolState.AUTHENTICATED) { + lastSuccessfulConnection = now + reconnectAttempts = 0 + log("✅ CONNECTION FULLY ESTABLISHED") + } + } + } + private val _lastError = MutableStateFlow(null) val lastError: StateFlow = _lastError.asStateFlow() @@ -89,10 +122,10 @@ class Protocol( // Register handshake response handler waitPacket(0x00) { packet -> if (packet is PacketHandshake) { - log("✅ Handshake response received, protocol version: ${packet.protocolVersion}") + log("✅ HANDSHAKE SUCCESS: protocol=${packet.protocolVersion}, heartbeat=${packet.heartbeatInterval}s") handshakeJob?.cancel() handshakeComplete = true - _state.value = ProtocolState.AUTHENTICATED + setState(ProtocolState.AUTHENTICATED, "Handshake response received") flushPacketQueue() // Start heartbeat with interval from server @@ -110,7 +143,7 @@ class Protocol( // Отправляем чаще - каждые 1/3 интервала (чтобы не терять соединение) val intervalMs = (intervalSeconds * 1000L) / 3 - log("💓 Starting heartbeat with server interval: ${intervalSeconds}s (sending every ${intervalMs}ms = ${intervalMs/1000}s)") + log("💓 HEARTBEAT START: server=${intervalSeconds}s, sending=${intervalMs/1000}s, state=${_state.value}") heartbeatJob = scope.launch { // ⚡ СРАЗУ отправляем первый heartbeat (как в Архиве) @@ -128,21 +161,27 @@ class Protocol( */ private fun sendHeartbeat() { try { - if (_state.value == ProtocolState.AUTHENTICATED) { + val currentState = _state.value + val socketAlive = webSocket != null + + if (currentState == ProtocolState.AUTHENTICATED) { val sent = webSocket?.send("heartbeat") ?: false if (sent) { - log("💓 Heartbeat sent") + log("💓 Heartbeat OK (socket=$socketAlive, state=$currentState)") } else { - log("💔 Heartbeat failed - socket closed or null") + log("💔 HEARTBEAT FAILED: socket=$socketAlive, state=$currentState, manuallyClosed=$isManuallyClosed") // Триггерим reconnect если heartbeat не прошёл if (!isManuallyClosed) { - log("🔄 Triggering reconnect due to failed heartbeat") + log("🔄 TRIGGERING RECONNECT due to failed heartbeat") handleDisconnect() } } + } else { + log("💔 HEARTBEAT SKIPPED: state=$currentState (not AUTHENTICATED), socket=$socketAlive") } } catch (e: Exception) { - log("💔 Heartbeat error: ${e.message}") + log("💔 HEARTBEAT EXCEPTION: ${e.message}") + e.printStackTrace() } } @@ -150,11 +189,17 @@ class Protocol( * Initialize connection to server */ fun connect() { - if (_state.value == ProtocolState.CONNECTING) { - log("Already connecting, skipping...") + val currentState = _state.value + log("🔌 CONNECT CALLED: currentState=$currentState, reconnectAttempts=$reconnectAttempts") + + if (currentState == ProtocolState.CONNECTING) { + log("⚠️ Already connecting, skipping... (preventing duplicate connect)") return } + reconnectAttempts++ + log("📊 RECONNECT ATTEMPT #$reconnectAttempts") + // Закрываем старый сокет если есть (как в Архиве) webSocket?.let { oldSocket -> try { @@ -167,10 +212,10 @@ class Protocol( webSocket = null isManuallyClosed = false - _state.value = ProtocolState.CONNECTING + setState(ProtocolState.CONNECTING, "Starting new connection attempt #$reconnectAttempts") _lastError.value = null - log("🔌 Connecting to: $serverAddress") + log("🔌 Connecting to: $serverAddress (attempt #$reconnectAttempts)") val request = Request.Builder() .url(serverAddress) @@ -178,15 +223,16 @@ class Protocol( webSocket = client.newWebSocket(request, object : WebSocketListener() { override fun onOpen(webSocket: WebSocket, response: Response) { - log("✅ WebSocket connected") - _state.value = ProtocolState.CONNECTED + log("✅ WebSocket OPEN: response=${response.code}, hasCredentials=${lastPublicKey != null}") + setState(ProtocolState.CONNECTED, "WebSocket onOpen callback") // If we have saved credentials, start handshake automatically lastPublicKey?.let { publicKey -> lastPrivateHash?.let { privateHash -> + log("🤝 Auto-starting handshake with saved credentials") startHandshake(publicKey, privateHash) } - } + } ?: log("⚠️ No saved credentials, waiting for manual handshake") } override fun onMessage(webSocket: WebSocket, bytes: ByteString) { @@ -199,23 +245,20 @@ class Protocol( } override fun onClosing(webSocket: WebSocket, code: Int, reason: String) { - // Code 3887 - кастомный код сервера, просто делаем reconnect тихо - if (code != 3887) { - log("⚠️ WebSocket closing: code=$code reason='$reason'") - } + log("⚠️ WebSocket CLOSING: code=$code reason='$reason' state=${_state.value}") } override fun onClosed(webSocket: WebSocket, code: Int, reason: String) { - // Для кода 3887 не логируем - это частое закрытие сервером - if (code != 3887) { - log("❌ WebSocket closed: code=$code reason='$reason'") - } + log("❌ WebSocket CLOSED: code=$code reason='$reason' state=${_state.value} manuallyClosed=$isManuallyClosed") handleDisconnect() } override fun onFailure(webSocket: WebSocket, t: Throwable, response: Response?) { - log("❌ WebSocket failure: ${t.message}") - log("❌ Response: ${response?.code} ${response?.message}") + log("❌ WebSocket FAILURE: ${t.message}") + log(" Response: ${response?.code} ${response?.message}") + log(" State: ${_state.value}") + log(" Manually closed: $isManuallyClosed") + log(" Reconnect attempts: $reconnectAttempts") t.printStackTrace() _lastError.value = t.message handleDisconnect() @@ -236,12 +279,12 @@ class Protocol( lastPrivateHash = privateHash if (_state.value != ProtocolState.CONNECTED && _state.value != ProtocolState.AUTHENTICATED) { - log("Not connected, will handshake after connection") + log("⚠️ HANDSHAKE DEFERRED: Not connected (state=${_state.value}), will handshake after connection") connect() return } - _state.value = ProtocolState.HANDSHAKING + setState(ProtocolState.HANDSHAKING, "Starting handshake") handshakeComplete = false val handshake = PacketHandshake().apply { @@ -366,22 +409,34 @@ class Protocol( private fun handleDisconnect() { val previousState = _state.value - _state.value = ProtocolState.DISCONNECTED + log("🔌 DISCONNECT HANDLER: previousState=$previousState, manuallyClosed=$isManuallyClosed, reconnectAttempts=$reconnectAttempts") + + setState(ProtocolState.DISCONNECTED, "Disconnect handler called from $previousState") handshakeComplete = false handshakeJob?.cancel() heartbeatJob?.cancel() - // Автоматический reconnect (простая логика как в Архиве - без счётчиков) + // Автоматический reconnect с защитой от бесконечных попыток if (!isManuallyClosed) { - log("🔄 Reconnecting silently...") + // Экспоненциальная задержка: 1s, 2s, 4s, 8s, максимум 30s + val delayMs = minOf(1000L * (1 shl minOf(reconnectAttempts - 1, 4)), 30000L) + log("🔄 SCHEDULING RECONNECT: attempt #$reconnectAttempts, delay=${delayMs}ms") + + if (reconnectAttempts > 20) { + log("⚠️ WARNING: Too many reconnect attempts ($reconnectAttempts), may be stuck in loop") + } scope.launch { - // Быстрый reconnect - 1 секунда - delay(1000L) + delay(delayMs) if (!isManuallyClosed) { + log("🔄 EXECUTING RECONNECT after ${delayMs}ms delay") connect() + } else { + log("🔄 RECONNECT CANCELLED: was manually closed during delay") } } + } else { + log("🔌 No reconnect: connection was manually closed") } } diff --git a/app/src/main/java/com/rosetta/messenger/network/ProtocolManager.kt b/app/src/main/java/com/rosetta/messenger/network/ProtocolManager.kt index e6369d2..6edb63c 100644 --- a/app/src/main/java/com/rosetta/messenger/network/ProtocolManager.kt +++ b/app/src/main/java/com/rosetta/messenger/network/ProtocolManager.kt @@ -62,9 +62,21 @@ object ProtocolManager { addLog("🚀 ProtocolManager.initialize() called") messageRepository = MessageRepository.getInstance(context) setupPacketHandlers() + setupStateMonitoring() addLog("🚀 ProtocolManager.initialize() completed") } + /** + * 🔍 Мониторинг состояния соединения + */ + private fun setupStateMonitoring() { + scope.launch { + getProtocol().state.collect { newState -> + addLog("📊 STATE MONITOR: Connection state changed to $newState") + } + } + } + /** * 🔥 Инициализация аккаунта - КРИТИЧНО для получения сообщений! * Должен вызываться после авторизации пользователя @@ -210,7 +222,7 @@ object ProtocolManager { * Connect to server */ fun connect() { - addLog("Connect requested") + addLog("🔌 CONNECT REQUESTED from ProtocolManager") getProtocol().connect() } @@ -218,9 +230,9 @@ object ProtocolManager { * Authenticate with server */ fun authenticate(publicKey: String, privateHash: String) { - addLog("Authenticate called") - addLog("PublicKey: ${publicKey.take(30)}...") - addLog("PrivateHash: ${privateHash.take(20)}...") + addLog("🔐 AUTHENTICATE called from ProtocolManager") + addLog(" PublicKey: ${publicKey.take(30)}...") + addLog(" PrivateHash: ${privateHash.take(20)}...") getProtocol().startHandshake(publicKey, privateHash) } diff --git a/app/src/main/java/com/rosetta/messenger/ui/chats/ChatViewModel.kt b/app/src/main/java/com/rosetta/messenger/ui/chats/ChatViewModel.kt index 2885d07..4918550 100644 --- a/app/src/main/java/com/rosetta/messenger/ui/chats/ChatViewModel.kt +++ b/app/src/main/java/com/rosetta/messenger/ui/chats/ChatViewModel.kt @@ -271,6 +271,7 @@ class ChatViewModel(application: Application) : AndroidViewModel(application) { lastReadMessageTimestamp = 0L readReceiptSentForCurrentDialog = false isDialogActive = true // 🔥 Диалог активен! + android.util.Log.d("ChatViewModel", "✅ Dialog active flag set to TRUE in openDialog") // 📨 Применяем Forward сообщения СРАЗУ после сброса if (hasForward) { @@ -306,7 +307,9 @@ class ChatViewModel(application: Application) : AndroidViewModel(application) { * Как setCurrentDialogPublicKeyView("") в архиве */ fun closeDialog() { + android.util.Log.d("ChatViewModel", "🔒 CLOSE DIALOG") isDialogActive = false + android.util.Log.d("ChatViewModel", "❌ Dialog active flag set to FALSE") } /** @@ -398,8 +401,13 @@ class ChatViewModel(application: Application) : AndroidViewModel(application) { // 🔥 Фоновые операции БЕЗ блокировки UI launch(Dispatchers.IO) { - // Отмечаем как прочитанные в БД - messageDao.markDialogAsRead(account, dialogKey) + // 👁️ Отмечаем как прочитанные ТОЛЬКО если диалог активен + if (isDialogActive) { + android.util.Log.d("ChatViewModel", "📖 Marking dialog as read (dialog is active)") + messageDao.markDialogAsRead(account, dialogKey) + } else { + android.util.Log.d("ChatViewModel", "⏸️ NOT marking as read (dialog not active)") + } // 🔥 Пересчитываем счетчики из messages dialogDao.updateDialogFromMessages(account, opponent) @@ -464,8 +472,13 @@ class ChatViewModel(application: Application) : AndroidViewModel(application) { hasMoreMessages = entities.size >= PAGE_SIZE currentOffset = entities.size - // Фоновые операции - messageDao.markDialogAsRead(account, dialogKey) + // 👁️ Фоновые операции - НЕ помечаем как прочитанные если диалог неактивен! + if (isDialogActive) { + android.util.Log.d("ChatViewModel", "📖 Marking dialog as read in refresh (dialog is active)") + messageDao.markDialogAsRead(account, dialogKey) + } else { + android.util.Log.d("ChatViewModel", "⏸️ NOT marking as read in refresh (dialog not active)") + } // 🔥 Пересчитываем счетчики из messages dialogDao.updateDialogFromMessages(account, opponent)