LagrangeDev/Lagrange.Core

[Bug?]: 某些情况下，转发文件给Bot会报错

Opened this issue · 0 comments

pk5ls20 commented

请确保您已阅读以上注意事项，并勾选下方的确认框。

  • 我已经仔细阅读上述内容
  • 我已经使用 最新构建 测试过，问题依旧存在。
  • 我已经在 Issue Tracker 中找过我要提出的问题，没有找到相同问题的ISSUE。
  • 我已知晓并同意，此处仅用于汇报程序中存在的问题。若这个 Issue 是关于其他非程序本身问题，则我的 Issue 可能会被无条件自动关闭或/并锁定。（其它疑问请考虑加入TG群询问或在discussions中提问）

Lagrange项目

OneBot

所使用/依赖的Lagrange项目对应的commit

0.0.3+60144421c6aff0c41cea37fdb315be5e316cd7e3

运行环境

Windows

运行架构

x64

连接方式

No response

重现步骤

No response

期望的结果是什么？

正常解析文件事件

实际的结果是什么？

见下

简单的复现代码/链接（可选）

No response

Trace 级别日志记录（可选）

Case 1 
C:\Users\pk5ls\AppData\Local\Programs\Rider\plugins\dpa\DotFiles\JetBrains.DPA.Runner.exe --handle=15212 --backend-pid=38684 --etw-collect-flags=67108622 --detach-event-name=dpa.detach.15212 C:/Users/pk5ls/Desktop/Projects/NTQQ/Lagrange.Core/Lagrange.OneBot/bin/Debug/net7.0/Lagrange.OneBot.exe
Lagrange.OneBot Version: 0.0.3+60144421c6aff0c41cea37fdb315be5e316cd7e3

warn: Lagrange.OneBot.Utility.MusicSigner[0]
      MusicSignServer is not available, sign may be failed
info: Lagrange.OneBot.LagrangeAppBuilder[0]
      Indexing in the database...
info: Lagrange.OneBot.LagrangeAppBuilder[0]
      The first indexing of the old database will load the entire database into memory.
info: Lagrange.OneBot.LagrangeAppBuilder[0]
      If this is the first time creating an index for the old database, please restart the application
dbug: Microsoft.Extensions.Hosting.Internal.Host[1]
      Hosting starting
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.OneBot\bin\Debug\net7.0
dbug: Microsoft.Extensions.Hosting.Internal.Host[2]
      Hosting started
info: Lagrange.OneBot.LagrangeApp[0]
      Lagrange.OneBot Implementation has started
info: Lagrange.OneBot.LagrangeApp[0]
      Protocol:  | 3.2.10-25765
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://60.29.238.126:8080/ Latency: 10
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://220.194.118.230:8080/ Latency: 7
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://123.125.0.210:8080/ Latency: 8
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://111.206.149.85:8080/ Latency: 5
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://123.125.0.161:8080/ Latency: 6
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [WtExchangeLogic] [INFORMATION]: Session has not expired, using session to login and register status
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://111.206.149.168:8080/ Latency: 7
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [ServiceContext] [DEBUG]: Outgoing SSOFrame: trpc.qq_new_tech.status_svc.StatusService.Register
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://125.39.196.158:8080/ Latency: 8
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://220.194.118.236:8080/ Latency: 6
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://60.29.242.161:8080/ Latency: 9
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [SocketContext] [VERBOSE]: Server: http://123.125.0.195:8080/ Latency: 7
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [ServiceContext] [DEBUG]: Incoming SSOFrame: trpc.qq_new_tech.status_svc.StatusService.Register
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [WtExchangeLogic] [INFORMATION]: Register Status: register success
info: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:16] [WtExchangeLogic] [INFORMATION]: AutoReLogin Enabled, session would be refreshed in 15 days period
info: Lagrange.OneBot.LagrangeApp[0]
      Bot Online: <hidden>
info: Lagrange.OneBot.Core.Network.LagrangeWebSvcCollection[1]
      [LagrangeWebSvcCollection]: Multi Connection has been configured
info: Lagrange.OneBot.Core.Network.Service.ReverseWSService[1002]
      [ReverseWSService] Reconnecting 0bfb4ab8-683c-4e4a-ad0b-513fc3776c0c at interval of 5000
warn: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:20] [BusinessContext] [WARNING]: Error while handling msf push: 12 trpc.msg.olpush.OlPushService.MsgPush
warn: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:20] [BusinessContext] [WARNING]: Exception of type 'System.Exception' was thrown.
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:20] [BusinessContext] [DEBUG]: <hidden>
warn: Lagrange.Core.BotContext[0]
      [2024-08-24 10:55:20] [BusinessContext] [WARNING]:    at Lagrange.Core.Message.MessagePacker.ParsePrivateFile(PushMsgBody message) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Message\MessagePacker.cs:line 174
         at Lagrange.Core.Internal.Service.Message.PushMessageService.Parse(Span`1 input, BotKeystore keystore, BotAppInfo appInfo, BotDeviceInfo device, PushMessageEvent& output, List`1& extraEvents) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Internal\Service\Message\PushMessageService.cs:line 40
         at Lagrange.Core.Internal.Service.BaseService`1.Lagrange.Core.Internal.Service.IService.Parse(Span`1 input, BotKeystore keystore, BotAppInfo appInfo, BotDeviceInfo device, ProtocolEvent& output, List`1& extraEvents) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Internal\Service\BaseService.cs:line 26
         at Lagrange.Core.Internal.Context.ServiceContext.ResolveEventByPacket(SsoPacket packet) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Internal\Context\ServiceContext.cs:line 102
         at Lagrange.Core.Internal.Context.BusinessContext.HandleServerPacket(SsoPacket packet) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Internal\Context\BusinessContext.cs:line 183
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...
info: Lagrange.OneBot.LagrangeApp[0]
      Lagrange.OneBot Implementation has stopped
dbug: Microsoft.Extensions.Hosting.Internal.Host[3]
      Hosting stopping
dbug: Microsoft.Extensions.Hosting.Internal.Host[4]
      Hosting stopped

进程已结束，退出代码为 0。
Case 2 
C:\Users\pk5ls\AppData\Local\Programs\Rider\plugins\dpa\DotFiles\JetBrains.DPA.Runner.exe --handle=656 --backend-pid=38684 --etw-collect-flags=67108622 --detach-event-name=dpa.detach.656 C:/Users/pk5ls/Desktop/Projects/NTQQ/Lagrange.Core/Lagrange.OneBot/bin/Debug/net7.0/Lagrange.OneBot.exe
Lagrange.OneBot Version: 0.0.3+60144421c6aff0c41cea37fdb315be5e316cd7e3

warn: Lagrange.OneBot.Utility.MusicSigner[0]
      MusicSignServer is not available, sign may be failed
info: Lagrange.OneBot.LagrangeAppBuilder[0]
      Indexing in the database...
info: Lagrange.OneBot.LagrangeAppBuilder[0]
      The first indexing of the old database will load the entire database into memory.
info: Lagrange.OneBot.LagrangeAppBuilder[0]
      If this is the first time creating an index for the old database, please restart the application
dbug: Microsoft.Extensions.Hosting.Internal.Host[1]
      Hosting starting
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.OneBot\bin\Debug\net7.0
dbug: Microsoft.Extensions.Hosting.Internal.Host[2]
      Hosting started
info: Lagrange.OneBot.LagrangeApp[0]
      Lagrange.OneBot Implementation has started
info: Lagrange.OneBot.LagrangeApp[0]
      Protocol:  | 3.2.10-25765
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://111.206.149.168:8080/ Latency: 11
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://220.194.118.230:8080/ Latency: 11
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [ServiceContext] [DEBUG]: Outgoing SSOFrame: trpc.qq_new_tech.status_svc.StatusService.Register
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://60.29.242.161:8080/ Latency: 11
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://111.206.149.85:8080/ Latency: 5
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://123.125.0.195:8080/ Latency: 12
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://123.125.0.161:8080/ Latency: 6
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://125.39.196.158:8080/ Latency: 12
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [SocketContext] [VERBOSE]: Server: http://220.194.118.236:8080/ Latency: 11
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [ServiceContext] [DEBUG]: Incoming SSOFrame: trpc.qq_new_tech.status_svc.StatusService.Register
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [WtExchangeLogic] [INFORMATION]: Register Status: register success
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:35] [WtExchangeLogic] [INFORMATION]: AutoReLogin Enabled, session would be refreshed in 15 days period
info: Lagrange.OneBot.LagrangeApp[0]
      Bot Online: <hidden>
info: Lagrange.OneBot.Core.Network.LagrangeWebSvcCollection[1]
      [LagrangeWebSvcCollection]: Multi Connection has been configured
info: Lagrange.OneBot.Core.Network.Service.ReverseWSService[1002]
      [ReverseWSService] Reconnecting 9769691b-9371-4235-9858-0a34451ade0a at interval of 5000
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Incoming SSOFrame: trpc.msg.olpush.OlPushService.MsgPush
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Outgoing SSOFrame: OidbSvcTrpcTcp.0xe37_1200
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Incoming SSOFrame: trpc.msg.olpush.OlPushService.MsgPush
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Outgoing SSOFrame: OidbSvcTrpcTcp.0xe37_1200
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Incoming SSOFrame: OidbSvcTrpcTcp.0xe37_1200
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Outgoing SSOFrame: OidbSvcTrpcTcp.0xfd4_1
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Outgoing SSOFrame: OidbSvcTrpcTcp.0xfd4_1
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Incoming SSOFrame: OidbSvcTrpcTcp.0xe37_1200
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Incoming SSOFrame: OidbSvcTrpcTcp.0xfd4_1
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [MessagingLogic] [VERBOSE]: [MessageChain(<hidden>)] [File] Grimes,Lizzy Wizzy - Delicate Weapon.mp3 (9213165): http://122.97.71.119:80/asn.com/qqdown
loadftnv5?ver=2&openid=3767830885&rkeycodec=base62&rkey=oAYCsgbAAgqeAUQ2RUFVQUJGQ012dms0b0JFaFNGVTNiaaEJJNEZLSUN5MldQMk1WVmliaeEJCU21oanRxYklFSUtFZktMem9wTFlHTVA2MTZBTTRpYWliaaWFh
b3dKQUEwZ0JjYmY3NDQxMWY5NWIwOWRmNGRlMzVlYTFjNzgzYzM2OF82MDkzMjg4YS02MWI2LTExZWYtYTc0ZS04YjEzNzA1ZGE2YzVaEhSFU3bhBI4FKICy2WP2MVVibxBBSmhgBIOWS0oQOKO2psgQwoR84iaicbqgwFCQPehGBQunHE6kmR7E7YsMDmLQ3hlS0EmNrOBxoPgH2pn9Wd8loSxUboFSnHhHNwoCjnxQeIGUl9fXeuskwSXTpxKDkZUTjVLPWM0MTA1MjlhUL3opLYGWhduamMtZG93bmxvYWQuZnRuLnFxLmNvbXAA&fileType=4001&isthumb=0
trce: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [ServiceContext] [DEBUG]: Incoming SSOFrame: OidbSvcTrpcTcp.0xfd4_1
info: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [MessagingLogic] [VERBOSE]: [MessageChain(<hidden>)] [File] Grimes,Lizzy Wizzy - Delicate Weapon.mp3 (9213165): http://122.97.71.121:80/asn.com/qqdown
loadftnv5?ver=2&openid=3767830885&rkeycodec=base62&rkey=oAYCsgbAAgqeAUQ2RUFVQUJGQ012dms0b0JFaFNGVTNiaaEJJNEZLSUN5MldQMk1WVmliaeEJCU21oanRxYklFSUtFZktMem9wTFlHTVA2MTZBTTRpYWliaaWFh
b3dKQUEwZ0JjYmY3NDQxMWY5NWIwOWRmNGRlMzVlYTFjNzgzYzM2OF82MDkzMjg4YS02MWI2LTExZWYtYTc0ZS04YjEzNzA1ZGE2YzVaEhSFU3bhBI4FKICy2WP2MVVibxBBSmhgBIOWS0oQOKO2psgQwoR84ia77OowxCQGCY4ToHSkB3SJHIkH5V2fqvkoaViaVkTy9K0icHjNdVRDAdibZOcbkl25UnD6291zf8lLB9PcsnE0fvhDrgb7ZXUFKDkZUTjVLPWM0MTA1MjlhUL3opLYGWhduamMtZG93bmxvYWQuZnRuLnFxLmNvbXAA&fileType=4001&isthumb=0
fail: Lagrange.Core.BotContext[0]
      [2024-08-24 09:15:40] [EventInvoker] [EXCEPTION]:    at LiteDB.Engine.IndexService.AddNode(CollectionIndex index, BsonValue key, PageAddress dataBlock, Byte level, IndexNode last)
         at LiteDB.Engine.IndexService.AddNode(CollectionIndex index, BsonValue key, PageAddress dataBlock, IndexNode last)
         at LiteDB.Engine.LiteEngine.InsertDocument(Snapshot snapshot, BsonDocument doc, BsonAutoId autoId, IndexService indexer, DataService data)
         at LiteDB.Engine.LiteEngine.<>c__DisplayClass7_0.<Insert>b__0(TransactionService transaction)
         at LiteDB.Engine.LiteEngine.AutoTransaction[T](Func`2 fn)
         at LiteDB.Engine.LiteEngine.Insert(String collection, IEnumerable`1 docs, BsonAutoId autoId)
         at LiteDB.LiteCollection`1.Insert(BsonValue id, T entity)
         at Lagrange.OneBot.Message.MessageService.OnFriendMessageReceived(BotContext bot, FriendMessageEvent e) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.OneBot\Message\MessageService.cs:line 68
         at Lagrange.Core.Event.EventInvoker.<>c__DisplayClass3_0.<.ctor>b__6(FriendMessageEvent e) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Event\EventInvoker.cs:line 24
         at Lagrange.Core.Event.EventInvoker.<>c__DisplayClass4_0`1.<RegisterEvent>b__0(EventBase e) in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Event\EventInvoker.cs:line 45
         at Lagrange.Core.Event.EventInvoker.<>c__DisplayClass5_0.<PostEvent>b__0() in C:\Users\pk5ls\Desktop\Projects\NTQQ\Lagrange.Core\Lagrange.Core\Event\EventInvoker.cs:line 53
Cannot insert duplicate key in unique index '_id'. The duplicate value is '41095658'.
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...
info: Lagrange.OneBot.LagrangeApp[0]
      Lagrange.OneBot Implementation has stopped
dbug: Microsoft.Extensions.Hosting.Internal.Host[3]
      Hosting stopping
dbug: Microsoft.Extensions.Hosting.Internal.Host[4]
      Hosting stopped

进程已结束，退出代码为 0。

补充说明（可选）

Case 1

  1. 发送端为9.9.15-26909、9.0.90.18890时，转发未下载的文件时复现

Case 2

  1. 当且仅当转发已下载的文件时可以复现
  2. 以上仅在发送端为9.9.15-26909复现，发送端为9.0.90.18890未能复现
  3. 这种情况下tx确实会下发两个data完全相同的数据包
  4. 数据库报错盲猜是因为收到了拉格兰解析了两个data完全相同的数据包而导致的