diff --git a/lib/core/services/streaming_helper.dart b/lib/core/services/streaming_helper.dart index e9fd374..085d5a1 100644 --- a/lib/core/services/streaming_helper.dart +++ b/lib/core/services/streaming_helper.dart @@ -307,24 +307,12 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ void channelLineHandlerFactory(String channel) { void handler(dynamic line) { try { - DebugLogger.log( - 'Channel $channel received line: ${line.toString().length > 50 ? line.toString().substring(0, 50) + "..." : line.toString()}', - scope: 'streaming/helper', - ); if (line is String) { final s = line.trim(); socketWatchdog?.ping(); // Enhanced completion detection matching OpenWebUI patterns if (s == '[DONE]' || s == 'DONE' || s == 'data: [DONE]') { - DebugLogger.log( - 'Received completion signal: $s', - scope: 'streaming/helper', - ); try { - DebugLogger.log( - 'Unregistering channel handler for: $channel (completion)', - scope: 'streaming/helper', - ); socketService?.offEvent(channel); } catch (_) {} try { @@ -434,25 +422,13 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ } try { - DebugLogger.log( - 'Registering channel handler for: $channel', - scope: 'streaming/helper', - ); socketService?.onEvent(channel, handler); } catch (_) {} socketWatchdog?.ping(); // Increased timeout to match our more generous streaming timeouts // OpenWebUI doesn't have such aggressive channel timeouts Future.delayed(const Duration(minutes: 12), () { - DebugLogger.log( - 'Channel handler timeout reached for $channel', - scope: 'streaming/helper', - ); try { - DebugLogger.log( - 'Unregistering channel handler for: $channel (timeout)', - scope: 'streaming/helper', - ); socketService?.offEvent(channel); } catch (_) {} socketWatchdog?.stop(); @@ -464,10 +440,6 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ void Function(dynamic response)? ack, ) { try { - DebugLogger.log( - 'Received chat event: ${ev.keys.join(", ")}', - scope: 'streaming/helper', - ); final data = ev['data']; if (data == null) return; final type = data['type']; @@ -681,58 +653,19 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ disposeSocketSubscriptions(); finishStreaming(); } else if (type == 'chat:message:follow_ups' && payload != null) { - DebugLogger.log( - 'Received follow-ups event: $payload', - scope: 'streaming/helper', - ); final followMap = _asStringMap(payload); if (followMap != null) { final followUpsRaw = followMap['follow_ups'] ?? followMap['followUps']; final suggestions = _parseFollowUpsField(followUpsRaw); final targetId = _resolveTargetMessageId(messageId, getMessages); - DebugLogger.log( - 'Processing follow-ups: ${suggestions.length} suggestions for message $targetId', - scope: 'streaming/helper', - ); - // Debug: show current message IDs in state - try { - final currentMessages = getMessages(); - final messageIds = currentMessages - .map((m) => '${m.id} (${m.role})') - .join(', '); - DebugLogger.log( - 'Current messages in state: $messageIds', - scope: 'streaming/helper', - ); - } catch (e) { - DebugLogger.error( - 'Error getting messages in follow-ups handler', - scope: 'streaming/helper', - error: e, - ); - } if (targetId != null) { - DebugLogger.log( - 'Follow-ups: calling setFollowUps for target $targetId', - scope: 'streaming/helper', - ); setFollowUps(targetId, suggestions); updateMessageById(targetId, (current) { final metadata = {...?current.metadata, 'followUps': suggestions}; return current.copyWith(metadata: metadata); }); - } else { - DebugLogger.log( - 'Follow-ups: targetId is null, cannot set follow-ups', - scope: 'streaming/helper', - ); } - } else { - DebugLogger.log( - 'Failed to parse follow-ups payload as string map', - scope: 'streaming/helper', - ); } } else if (type == 'chat:title' && payload != null) { final title = payload.toString(); @@ -839,33 +772,15 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ // Incremental message content over socket final content = payload['content']?.toString() ?? ''; if (content.isNotEmpty) { - DebugLogger.log( - 'Appending socket content: "${content.length > 30 ? content.substring(0, 30) + "..." : content}"', - scope: 'streaming/helper', - ); appendToLastMessage(content); updateImagesFromCurrentContent(); - } else { - DebugLogger.log( - 'Socket delta event with empty content', - scope: 'streaming/helper', - ); } } else if ((type == 'chat:message' || type == 'replace') && payload != null) { // Full message replacement over socket final content = payload['content']?.toString() ?? ''; if (content.isNotEmpty) { - DebugLogger.log( - 'Replacing socket content: "${content.length > 30 ? content.substring(0, 30) + "..." : content}"', - scope: 'streaming/helper', - ); replaceLastMessageContent(content); - } else { - DebugLogger.log( - 'Socket replace event with empty content', - scope: 'streaming/helper', - ); } } else if ((type == 'chat:message:files') && payload != null) { // Alias for files event used by web client @@ -993,12 +908,6 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ appendToLastMessage(content); updateImagesFromCurrentContent(); } - } else { - // Debug unknown event types to catch missing handlers - DebugLogger.log( - 'Unknown chat event type: $type (payload keys: ${payload is Map ? payload.keys.join(", ") : "not a map"})', - scope: 'streaming/helper', - ); } } catch (_) {} } @@ -1008,10 +917,6 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ void Function(dynamic response)? ack, ) { try { - DebugLogger.log( - 'Received channel event: ${ev.keys.join(", ")}', - scope: 'streaming/helper', - ); final data = ev['data']; if (data == null) return; final type = data['type']; @@ -1022,21 +927,11 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ appendToLastMessage(content); updateImagesFromCurrentContent(); } - } else { - // Debug channel events that might include follow-ups - DebugLogger.log( - 'Channel event type: $type (payload keys: ${payload is Map ? payload.keys.join(", ") : "not a map"})', - scope: 'streaming/helper', - ); } } catch (_) {} } if (socketService != null) { - DebugLogger.log( - 'Creating socket subscriptions for conversationId: $activeConversationId, sessionId: $sessionId', - scope: 'streaming/helper', - ); final chatSub = socketService.addChatEventHandler( conversationId: activeConversationId, sessionId: sessionId, @@ -1052,23 +947,10 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ handler: channelEventsHandler, ); socketSubscriptions.add(channelSub); - DebugLogger.log( - 'Created ${socketSubscriptions.length} socket subscriptions', - scope: 'streaming/helper', - ); - } else { - DebugLogger.log( - 'No socket service available - using polling only', - scope: 'streaming/helper', - ); } final subscription = persistentController.stream.listen( (chunk) { - DebugLogger.log( - 'Received chunk: "${chunk.length > 100 ? chunk.substring(0, 100) + "..." : chunk}"', - scope: 'streaming/helper', - ); var effectiveChunk = chunk; if (webSearchEnabled && !isSearching) { if (chunk.contains('[SEARCHING]') || @@ -1103,30 +985,15 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ } }, onDone: () async { - DebugLogger.log('Stream completed normally', scope: 'streaming/helper'); - // Unregister from persistent service persistentService.unregisterStream(streamId); // Only finish streaming if no socket subscriptions are active // This indicates a polling-driven flow where the stream ending means completion // For socket flows, completion should be handled by socket events (done: true) - DebugLogger.log( - 'Stream onDone - socketSubscriptions.length: ${socketSubscriptions.length}', - scope: 'streaming/helper', - ); if (socketSubscriptions.isEmpty) { - DebugLogger.log( - 'No socket subscriptions - finishing polling-based stream', - scope: 'streaming/helper', - ); finishStreaming(); Future.microtask(refreshConversationSnapshot); - } else { - DebugLogger.log( - 'Socket subscriptions active - keeping stream alive for socket events', - scope: 'streaming/helper', - ); } }, onError: (error) async { @@ -1153,11 +1020,6 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ error.toString().contains('HandshakeException'); if (isRecoverable && socketService != null) { - DebugLogger.log( - 'Attempting to recover from recoverable stream error', - scope: 'streaming/helper', - ); - // Try to recover via socket connection if available try { await socketService.ensureConnected( @@ -1172,18 +1034,8 @@ ActiveSocketStream attachUnifiedChunkedStreaming({ } disposeSocketSubscriptions(); - DebugLogger.log( - 'Finishing streaming and scheduling conversation refresh', - scope: 'streaming/helper', - ); finishStreaming(); - Future.microtask(() { - DebugLogger.log( - 'Executing conversation refresh after streaming finished', - scope: 'streaming/helper', - ); - refreshConversationSnapshot(); - }); + Future.microtask(refreshConversationSnapshot); socketWatchdog?.stop(); }, ); diff --git a/lib/features/chat/providers/chat_providers.dart b/lib/features/chat/providers/chat_providers.dart index 13d90c4..f9f62a5 100644 --- a/lib/features/chat/providers/chat_providers.dart +++ b/lib/features/chat/providers/chat_providers.dart @@ -389,10 +389,6 @@ class ChatMessagesNotifier extends Notifier> { } void setMessageStream(StreamSubscription stream) { - DebugLogger.log( - 'Setting new message stream, cancelling previous', - scope: 'chat/provider', - ); _cancelMessageStream(); _messageStream = stream; @@ -404,10 +400,6 @@ class ChatMessagesNotifier extends Notifier> { List subscriptions, { VoidCallback? onDispose, }) { - DebugLogger.log( - 'Setting ${subscriptions.length} socket subscriptions, cancelling previous', - scope: 'chat/provider', - ); cancelSocketSubscriptions(); _socketSubscriptions.addAll(subscriptions); _socketTeardown = onDispose; @@ -430,10 +422,6 @@ class ChatMessagesNotifier extends Notifier> { } void addMessage(ChatMessage message) { - DebugLogger.log( - 'addMessage: ${message.role} message (id: ${message.id}, streaming: ${message.isStreaming})', - scope: 'chat/provider', - ); state = [...state, message]; if (message.role == 'assistant' && message.isStreaming) { _touchStreamingActivity(); @@ -498,31 +486,13 @@ class ChatMessagesNotifier extends Notifier> { String messageId, ChatMessage Function(ChatMessage current) updater, ) { - DebugLogger.log( - 'updateMessageById called for message $messageId', - scope: 'chat/provider', - ); final index = state.indexWhere((m) => m.id == messageId); - if (index == -1) { - DebugLogger.log( - 'updateMessageById: message $messageId not found in state (${state.length} messages)', - scope: 'chat/provider', - ); - return; - } + if (index == -1) return; final original = state[index]; final updated = updater(original); if (identical(updated, original)) { - DebugLogger.log( - 'updateMessageById: no changes made to message $messageId', - scope: 'chat/provider', - ); return; } - DebugLogger.log( - 'updateMessageById: updating message $messageId at index $index', - scope: 'chat/provider', - ); final next = [...state]; next[index] = updated; state = next; @@ -536,15 +506,7 @@ class ChatMessagesNotifier extends Notifier> { } void setFollowUps(String messageId, List followUps) { - DebugLogger.log( - 'setFollowUps called for message $messageId with ${followUps.length} follow-ups', - scope: 'chat/provider', - ); updateMessageById(messageId, (current) { - DebugLogger.log( - 'setFollowUps: updating message with follow-ups: ${followUps.join(", ")}', - scope: 'chat/provider', - ); return current.copyWith(followUps: List.from(followUps)); }); } @@ -582,32 +544,15 @@ class ChatMessagesNotifier extends Notifier> { } void appendToLastMessage(String content) { - DebugLogger.log( - 'appendToLastMessage called with: "${content.length > 30 ? content.substring(0, 30) + "..." : content}"', - scope: 'chat/provider', - ); - if (state.isEmpty) { - DebugLogger.log( - 'appendToLastMessage: state is empty', - scope: 'chat/provider', - ); return; } final lastMessage = state.last; if (lastMessage.role != 'assistant') { - DebugLogger.log( - 'appendToLastMessage: last message is not assistant (${lastMessage.role})', - scope: 'chat/provider', - ); return; } if (!lastMessage.isStreaming) { - DebugLogger.log( - 'appendToLastMessage: last message is not streaming', - scope: 'chat/provider', - ); // Ignore late chunks when streaming already finished return; } @@ -624,10 +569,6 @@ class ChatMessagesNotifier extends Notifier> { } final newContent = current.isEmpty ? content : current + content; - DebugLogger.log( - 'appendToLastMessage: updating UI with new content length: ${newContent.length}', - scope: 'chat/provider', - ); state = [ ...state.sublist(0, state.length - 1), lastMessage.copyWith(content: newContent), @@ -636,25 +577,12 @@ class ChatMessagesNotifier extends Notifier> { } void replaceLastMessageContent(String content) { - DebugLogger.log( - 'replaceLastMessageContent called with: "${content.length > 30 ? content.substring(0, 30) + "..." : content}"', - scope: 'chat/provider', - ); - if (state.isEmpty) { - DebugLogger.log( - 'replaceLastMessageContent: state is empty', - scope: 'chat/provider', - ); return; } final lastMessage = state.last; if (lastMessage.role != 'assistant') { - DebugLogger.log( - 'replaceLastMessageContent: last message is not assistant (${lastMessage.role})', - scope: 'chat/provider', - ); return; } @@ -668,10 +596,6 @@ class ChatMessagesNotifier extends Notifier> { if (sanitized.startsWith(searchBanner)) { sanitized = sanitized.substring(searchBanner.length); } - DebugLogger.log( - 'replaceLastMessageContent: updating UI with sanitized content length: ${sanitized.length}', - scope: 'chat/provider', - ); state = [ ...state.sublist(0, state.length - 1), lastMessage.copyWith(content: sanitized), @@ -680,23 +604,10 @@ class ChatMessagesNotifier extends Notifier> { } void finishStreaming() { - DebugLogger.log('finishStreaming called', scope: 'chat/provider'); - if (state.isEmpty) { - DebugLogger.log( - 'finishStreaming: state is empty', - scope: 'chat/provider', - ); - return; - } + if (state.isEmpty) return; final lastMessage = state.last; - if (lastMessage.role != 'assistant' || !lastMessage.isStreaming) { - DebugLogger.log( - 'finishStreaming: last message is not streaming assistant (role: ${lastMessage.role}, streaming: ${lastMessage.isStreaming})', - scope: 'chat/provider', - ); - return; - } + if (lastMessage.role != 'assistant' || !lastMessage.isStreaming) return; // Also strip any leftover typing indicator before finalizing const ti = '[TYPING_INDICATOR]'; @@ -709,10 +620,6 @@ class ChatMessagesNotifier extends Notifier> { cleaned = cleaned.substring(searchBanner.length); } - DebugLogger.log( - 'finishStreaming: setting isStreaming=false and content length: ${cleaned.length}', - scope: 'chat/provider', - ); state = [ ...state.sublist(0, state.length - 1), lastMessage.copyWith(isStreaming: false, content: cleaned),