feat: add better logging, thought handling improvements

src/commands/ai.ts

@@ -37,6 +37,7 @@ import { getStrings } from "../plugins/checklang"
 import { languageCode } from "../utils/language-code"
 import axios from "axios"
 import { rateLimiter } from "../utils/rate-limiter"
+import { logger } from "../utils/log"
 
 const spamwatchMiddleware = spamwatchMiddlewareModule(isOnSpamWatch)
 //const model = "qwen3:0.6b"
@@ -55,7 +56,7 @@ export function sanitizeForJson(text: string): string {
 
 async function getResponse(prompt: string, ctx: TextContext, replyGenerating: Message) {
   const Strings = getStrings(languageCode(ctx))
-  
+
   if (!ctx.chat) return {
     "success": false,
     "error": Strings.unexpectedErr.replace("{error}", "No chat found"),
@@ -72,43 +73,24 @@ async function getResponse(prompt: string, ctx: TextContext, replyGenerating: Me
 
     let fullResponse = ""
     let thoughts = ""
-    let thinking = false
     let lastUpdate = Date.now()
     
     for await (const chunk of aiResponse.data) {
       const lines = chunk.toString().split('\n')
       for (const line of lines) {
         if (!line.trim()) continue
-        if (line.includes("\u003cthink\u003e")) {
+        let ln = JSON.parse(line)
-          // intercept thoughts
+        
-          console.log("thinking started")
+        if (ln.response.includes("<think>")) { logger.logThinking(true) } else if (ln.response.includes("</think>")) { logger.logThinking(false) }
-          thinking = true
-          thoughts += line
-          continue
-        } else if (line.includes("\u003c/think\u003e")) {
-          // thinking finished
-          thinking = false
-          console.log("thinking finished")
-          continue
-        }
 
         try {
           const now = Date.now()
-          let data = JSON.parse(line)
           
-          if (data.response && !thinking) {
+          if (ln.response) {
-            fullResponse += data.response
+            const patchedThoughts = ln.response.replace("<think>", "`Thinking...`").replace("</think>", "`Finished thinking`")
-            if (now - lastUpdate >= 1000) {
+            thoughts += patchedThoughts
-              await rateLimiter.editMessageWithRetry(
+            fullResponse += patchedThoughts
-                ctx,
+
-                ctx.chat.id,
-                replyGenerating.message_id,
-                fullResponse,
-                { parse_mode: 'Markdown' }
-              )
-              lastUpdate = now
-            }
-          } else if (data.response && thinking) {
             if (now - lastUpdate >= 1000) {
               await rateLimiter.editMessageWithRetry(
                 ctx,
@@ -201,6 +183,9 @@ export default (bot: Telegraf<Context>) => {
     const reply_to_message_id = replyToMessageId(textCtx)
     const Strings = getStrings(languageCode(textCtx))
     const message = textCtx.message.text
+    const author = ("@" + ctx.from?.username) || ctx.from?.first_name
+
+    logger.logCmdStart(author)
 
     if (!process.env.ollamaApi) {
       await ctx.reply(Strings.aiDisabled, {
@@ -215,12 +200,23 @@ export default (bot: Telegraf<Context>) => {
       ...({ reply_to_message_id })
     })
 
+    const fixedMsg = message.replace(/\/ask /, "")
+    if (fixedMsg.length < 1) {
+      await ctx.reply(Strings.askNoMessage, {
+        parse_mode: 'Markdown',
+        ...({ reply_to_message_id })
+      })
+      return
+    }
+
+    logger.logPrompt(fixedMsg)
+
     const prompt = sanitizeForJson(
 `You are a helpful assistant named Kowalski, who has been given a message from a user.
 
 The message is:
 
-${message}`)
+${fixedMsg}`)
     const aiResponse = await getResponse(prompt, textCtx, replyGenerating)
     if (!aiResponse) return
 
@@ -243,6 +239,7 @@ ${message}`)
         error,
         { parse_mode: 'Markdown' }
       )
+      console.error("[!] Error sending response:", aiResponse.error)
     }
   })
 }

src/utils/log.ts

@@ -41,27 +41,25 @@ class Logger {
     return Logger.instance
   }
 
+  logCmdStart(user: string): void {
+    console.log(`[START] Received /ask from ${user}`)
+  }
+
+  logThinking(thinking: boolean): void {
+    if (thinking) {
+      console.log("[THINKING] Started")
+    } else {
+      console.log("[THINKING] Ended")
+    }
+  }
+
   logChunk(chatId: number, messageId: number, text: string, isOverflow: boolean = false): void {
-    const prefix = isOverflow ? '[OVERFLOW]' : '[CHUNK]'
+    const prefix = isOverflow ? "[OVERFLOW]" : "[CHUNK]"
-    console.log(`${prefix} [${chatId}:${messageId}] ${text.length} chars: ${text.substring(0, 50)}${text.length > 50 ? '...' : ''}`)
+    console.log(`${prefix} [${chatId}:${messageId}] ${text.length} chars`)
   }
 
   logPrompt(prompt: string): void {
-    console.log(`[PROMPT] ${prompt.length} chars: ${prompt.substring(0, 50)}${prompt.length > 50 ? '...' : ''}`)
+    console.log(`[PROMPT] ${prompt.length} chars: ${prompt.substring(0, 50)}${prompt.length > 50 ? "..." : ""}`)
-  }
-
-  logThinkingStart(): void {
-    if (!this.thinking) {
-      console.log('[THINKING] started')
-      this.thinking = true
-    }
-  }
-
-  logThinkingEnd(): void {
-    if (this.thinking) {
-      console.log('[THINKING] ended')
-      this.thinking = false
-    }
   }
 
   logError(error: any): void {
@@ -69,14 +67,14 @@ class Logger {
       const retryAfter = error.response.parameters?.retry_after || 1
       console.error(`[RATE_LIMIT] Too Many Requests - retry after ${retryAfter}s`)
     } else if (error.response?.error_code === 400 && error.response?.description?.includes("can't parse entities")) {
-      console.error('[PARSE_ERROR] Markdown parsing failed, retrying with plain text')
+      console.error("[PARSE_ERROR] Markdown parsing failed, retrying with plain text")
     } else {
       const errorDetails = {
         code: error.response?.error_code,
         description: error.response?.description,
         method: error.on?.method
       }
-      console.error('[ERROR]', JSON.stringify(errorDetails, null, 2))
+      console.error("[ERROR]", JSON.stringify(errorDetails, null, 2))
     }
   }
 }