fix(qr+logging): resolve QR race condition, URL double messages, and EF Core log pollution

TelegramSearchBot.Common/LoggerHolders.cs

@@ -0,0 +1,11 @@
+using Serilog;
+
+namespace TelegramSearchBot.Common {
+    /// <summary>
+    /// Shared logger holder for EF Core logging.
+    /// Initialized by TelegramSearchBot.Program and used by Database project.
+    /// </summary>
+    public static class LoggerHolders {
+        public static Serilog.ILogger EfCoreLogger { get; set; } = null!;
+    }
+}

TelegramSearchBot.Common/TelegramSearchBot.Common.csproj

@@ -7,5 +7,6 @@
   <ItemGroup>
     <PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="10.0.7" />
     <PackageReference Include="Newtonsoft.Json" Version="13.0.4" />
+    <PackageReference Include="Serilog" Version="4.3.1" />
   </ItemGroup>
 </Project>

TelegramSearchBot.Database/Model/DataDbContext.cs

@@ -13,7 +13,9 @@ public class DataDbContext : DbContext {
         public DataDbContext(DbContextOptions<DataDbContext> options) : base(options) { }
         protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder) {
             // 日志配置
-            optionsBuilder.LogTo(Log.Logger.Information, LogLevel.Information);
+            optionsBuilder.LogTo(
+                (TelegramSearchBot.Common.LoggerHolders.EfCoreLogger ?? Log.Logger).Information, 
+                LogLevel.Information);
 
             // 数据库配置应该由外部通过DbContextOptions提供
             // 不要在这里配置默认数据库

TelegramSearchBot.Database/Model/SearchCacheDbContext.cs

@@ -8,7 +8,9 @@ public class SearchCacheDbContext : DbContext {
         public SearchCacheDbContext(DbContextOptions<SearchCacheDbContext> options) : base(options) { }
 
         protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder) {
-            optionsBuilder.LogTo(Log.Logger.Information, LogLevel.Information);
+            optionsBuilder.LogTo(
+                (TelegramSearchBot.Common.LoggerHolders.EfCoreLogger ?? Log.Logger).Information, 
+                LogLevel.Information);
         }
 
         protected override void OnModelCreating(ModelBuilder modelBuilder) {

TelegramSearchBot/AppBootstrap/QRBootstrap.cs

@@ -24,11 +24,22 @@ public static async Task Process(string[] args) {
                     continue;
                 }
                 var task = db.ListLeftPop("QRTasks").ToString();
+                if (string.IsNullOrWhiteSpace(task)) {
+                    Log.Logger.Warning("Empty task from QRTasks queue — skipping");
+                    continue;
+                }
                 var photoPath = db.StringGetDelete($"QRPost-{task}").ToString();
+                if (string.IsNullOrWhiteSpace(photoPath)) {
+                    Log.Logger.Warning("Empty QRPost key for task {task} — data not yet available or already consumed", task);
+                    continue;
+                }
                 string response = string.Empty;
+                Log.Logger.Information("QR processing started: task={task}, path={path}", task, photoPath);
                 try {
                     response = await qr.ExecuteAsync(photoPath);
+                    Log.Logger.Information("QR result: task={task}, len={len}, content={preview}", task, response?.Length ?? -1, response?.Length > 100 ? response.Substring(0, 100) + "..." : response);
                 } catch (Exception ex) {
+                    Log.Logger.Warning(ex, "QR processing failed for task {task}", task);
                 }
 
                 db.StringSet($"QRResult-{task}", response);

TelegramSearchBot/Controller/AI/QR/AutoQRController.cs

@@ -58,6 +58,9 @@ public async Task ExecuteAsync(PipelineContext p) {
             if (p.BotMessageType != BotMessageType.Message) {
                 return;
             }
+            _logger.LogInformation("AutoQR processing started for {ChatId}/{MessageId}",
+                e.Message.Chat.Id, e.Message.MessageId);
+
             try {
                 var filePath = IProcessPhoto.GetPhotoPath(e);
                 if (filePath == null) {
@@ -67,10 +70,13 @@ public async Task ExecuteAsync(PipelineContext p) {
                 var qrStr = await _autoQRService.ExecuteAsync(filePath);
 
                 if (string.IsNullOrWhiteSpace(qrStr)) {
+                    _logger.LogInformation("No QR code detected for {ChatId}/{MessageId}",
+                        e.Message.Chat.Id, e.Message.MessageId);
                     return;
                 }
 
-                _logger.LogInformation("QR Code recognized for {ChatId}/{MessageId}. Content: {QrStr}", e.Message.Chat.Id, e.Message.MessageId, qrStr);
+                _logger.LogInformation("QR Code recognized for {ChatId}/{MessageId}. Content: {QrStr}, Length: {QrStrLen}",
+                    e.Message.Chat.Id, e.Message.MessageId, qrStr, qrStr.Length);
 
                 // Add QR result to processing results
                 p.ProcessingResults.Add($"[QR识别结果] {qrStr}");

TelegramSearchBot/Extension/IDatabaseAsyncExtension.cs

@@ -2,17 +2,45 @@
 using System.Collections.Generic;
 using System.Linq;
 using System.Text;
+using System.Threading;
 using System.Threading.Tasks;
 using StackExchange.Redis;
 
 namespace TelegramSearchBot.Extension {
     public static class IDatabaseAsyncExtension {
-        public static async Task<string> StringWaitGetDeleteAsync(this IDatabaseAsync db, string key) {
+        /// <summary>
+        /// Waits for a Redis key to appear and returns its value, then deletes the key.
+        /// Uses a polling approach with configurable timeout (default 30 seconds).
+        /// </summary>
+        /// <param name="db">The IDatabaseAsync instance.</param>
+        /// <param name="key">The Redis key to wait for.</param>
+        /// <param name="timeout">Maximum time to wait. Defaults to 30 seconds if null.</param>
+        /// <param name="cancellationToken">Cancellation token to abort the operation.</param>
+        /// <returns>The string value of the key.</returns>
+        /// <exception cref="OperationCanceledException">Thrown when cancellation is requested.</exception>
+        /// <exception cref="TimeoutException">Thrown when the timeout elapses before the key appears.</exception>
+        public static async Task<string> StringWaitGetDeleteAsync(
+            this IDatabaseAsync db,
+            string key,
+            TimeSpan? timeout = null,
+            CancellationToken cancellationToken = default)
+        {
+            var effectiveTimeout = timeout ?? TimeSpan.FromSeconds(30);
+            var startTime = DateTime.UtcNow;
+
             while (true) {
+                cancellationToken.ThrowIfCancellationRequested();
+
+                var elapsed = DateTime.UtcNow - startTime;
+                if (elapsed > effectiveTimeout) {
+                    throw new TimeoutException($"Timeout waiting for Redis key: {key}");
+                }
+
                 if (!( await db.StringGetAsync(key) ).Equals(RedisValue.Null)) {
+                    // Note: check-then-delete is not atomic but acceptable here since only one consumer polls this key
                     return ( await db.StringGetDeleteAsync(key) ).ToString();
                 } else {
-                    await Task.Delay(1000);
+                    await Task.Delay(500, cancellationToken);
                 }
             }
         }

TelegramSearchBot/Program.cs

@@ -11,6 +11,15 @@
 namespace TelegramSearchBot {
     class Program {
         static async Task Main(string[] args) {
+            // Separate logger for EF Core - writes only to logs/efcore-.txt
+            LoggerHolders.EfCoreLogger = new LoggerConfiguration()
+                .MinimumLevel.Information()
+                .WriteTo.File(
+                    $"{Env.WorkDir}/logs/efcore-.txt",
+                    rollingInterval: RollingInterval.Day,
+                    outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss} {Level:u3}] [EF] {Message:lj}{NewLine}{Exception}")
+                .CreateLogger();
+
             Log.Logger = new LoggerConfiguration()
             .MinimumLevel.Information() // 设置最低日志级别
             .MinimumLevel.Override("Microsoft.EntityFrameworkCore.Database.Command", Serilog.Events.LogEventLevel.Debug) // SQL 语句只在 Debug 级别输出

TelegramSearchBot/Service/Abstract/SubProcessService.cs

@@ -4,6 +4,7 @@
 using System.Text;
 using System.Threading.Tasks;
 using Microsoft.Extensions.DependencyInjection;
+using Serilog;
 using StackExchange.Redis;
 using TelegramSearchBot.Attributes;
 using TelegramSearchBot.Common;
@@ -22,10 +23,20 @@ public SubProcessService(IConnectionMultiplexer connectionMultiplexer) {
         public async Task<string> RunRpc(string payload) {
             var db = connectionMultiplexer.GetDatabase();
             var guid = Guid.NewGuid();
-            await db.ListRightPushAsync($"{ForkName}Tasks", $"{guid}");
-            await db.StringSetAsync($"{ForkName}Post-{guid}", payload);
-            await AppBootstrap.AppBootstrap.RateLimitForkAsync([ForkName, $"{Env.SchedulerPort}"]);
-            return await db.StringWaitGetDeleteAsync($"{ForkName}Result-{guid}");
+            Log.Information("RunRpc started: ForkName={ForkName}, guid={guid}, payloadLen={payloadLen}",
+                ForkName, guid, payload?.Length ?? -1);
+            try {
+                await db.StringSetAsync($"{ForkName}Post-{guid}", payload);
+                await db.ListRightPushAsync($"{ForkName}Tasks", $"{guid}");
+                await AppBootstrap.AppBootstrap.RateLimitForkAsync([ForkName, $"{Env.SchedulerPort}"]);
+                var result = await db.StringWaitGetDeleteAsync($"{ForkName}Result-{guid}");
+                Log.Information("RunRpc completed: ForkName={ForkName}, guid={guid}, resultLen={resultLen}",
+                    ForkName, guid, result?.Length ?? -1);
+                return result;
+            } catch (Exception ex) {
+                Log.Error(ex, "RunRpc failed: ForkName={ForkName}, guid={guid}", ForkName, guid);
+                throw;
+            }
         }
     }
 }

TelegramSearchBot/Service/BotAPI/SendMessageService.cs

@@ -53,17 +53,15 @@ public async Task TrySendMessageWithFallback(long chatId, int messageId, string
 
             try {
                 if (isEdit) {
-                    Message editedMessage = null;
-                    await Send.AddTask(async () => {
-                        editedMessage = await botClient.EditMessageText(
+                    var editedMessage = await Send.AddTaskWithResult<Message>(async () => {
+                        return await botClient.EditMessageText(
                             chatId: chatId, messageId: messageId, parseMode: currentParseMode, text: textToSend, linkPreviewOptions: linkPreviewOptions);
                     }, isGroup);
 
                     if (editedMessage != null && editedMessage.MessageId > 0) { logger.LogInformation($"Edited message {editedMessage.MessageId} successfully with {currentParseMode}."); } else { logger.LogWarning($"Editing message {messageId} with {currentParseMode} failed silently. Edit will be skipped."); }
                 } else {
-                    Message sentMsg = null;
-                    await Send.AddTask(async () => {
-                        sentMsg = await botClient.SendMessage(
+                    var sentMsg = await Send.AddTaskWithResult<Message>(async () => {
+                        return await botClient.SendMessage(
                             chatId: chatId, text: textToSend, parseMode: currentParseMode,
                             replyParameters: new ReplyParameters() { MessageId = replyToMessageId },
                             linkPreviewOptions: linkPreviewOptions);