search

ehForwarderBot / efb-wechat-slave

A channel for EH Forwarder Bot.
GNU Affero General Public License v3.0
459 stars 62 forks source link

[BUG] 近期频繁被登出 #148

Closed zeXtreme closed 10 months ago

zeXtreme commented 11 months ago

版本信息 Version Info

EH Forwarder Bot
Version: 2.1.1

Master channel:
    blueset.telegram, 2.3.1

Slave channel:
    blueset.wechat, 2.0.7

问题描述 Describe the bug

从上周开始频繁提示 EWS User Auth:WeChat server has logged you out. Please log in again when you are ready. 重新登陆后最长不超过24小时再次出现提示，最快几分钟就出现提示。尝试过升级主端、从端，均会出现此问题。

重现步骤 To Reproduce

正常启动EFB后，过十多分钟提示被登出。

截图 Screenshots

Verbose 日志 Log

Verbose 日志 ``` 请在下方贴出您的 Verbose 日志。如果您对隐私有所顾虑，您可以自行 隐去隐私信息、或 GPG 加密至 BD6B65EC00638DC9083781D5D4B65BB1A106200A。 【贴在下面】 2023-08-07 22:13:13,276 [DEBUG]: urllib3.connectionpool (connectionpool._make_request; connectionpool.py:452) https://webpush.wx.qq.com:443 "GET /cgi-bin/mmwebwx-bin/synccheck?r=1691417568028&skey=&sid=Tgawq5Vk4W15kG74&uin=421845635&deviceid=e689367306445592&synckey=1_823914929%7C2_823915365%7C3_823915198%7C11_823915312%7C19_33638%7C23_1691416528%7C24_1691417544%7C27_1175843%7C201_1691417544%7C203_1691415493%7C206_101%7C1000_1691413261%7C1001_1691413323&_=1691416539337 HTTP/1.1" 200 43 2023-08-07 22:13:14,647 [DEBUG]: efb_wechat_slave.vendor.wxpy.utils.puid_map (puid_map.dump; puid_map.py:243) Attempting to overwrite PUID mapping. 2023-08-07 22:13:14,647 [DEBUG]: efb_wechat_slave.vendor.wxpy.utils.puid_map (puid_map.dump; puid_map.py:245) Write PUID mapping to /home/zerozwy/.ehforwarderbot/profiles/default/blueset.wechat/wxpy_puid.pkl.lvO5zB20skE. 2023-08-07 22:13:14,649 [DEBUG]: efb_wechat_slave.vendor.wxpy.utils.puid_map (puid_map.dump; puid_map.py:248) Remove old PUID mapping at /home/zerozwy/.ehforwarderbot/profiles/default/blueset.wechat/wxpy_puid.pkl 2023-08-07 22:13:14,649 [DEBUG]: efb_wechat_slave.vendor.wxpy.utils.puid_map (puid_map.dump; puid_map.py:250) Move new PUID mapping from /home/zerozwy/.ehforwarderbot/profiles/default/blueset.wechat/wxpy_puid.pkl.lvO5zB20skE to /home/zerozwy/.ehforwarderbot/profiles/default/blueset.wechat/wxpy_puid.pkl 2023-08-07 22:13:14,649 [DEBUG]: efb_wechat_slave.vendor.wxpy.utils.puid_map (puid_map.dump; puid_map.py:252) PUID mapping overwrite completed. 2023-08-07 22:13:22,464 [DEBUG]: telegram.bot (bot.get_updates; bot.py:3151) No new updates found. 2023-08-07 22:13:22,464 [DEBUG]: telegram.bot (bot.decorator; bot.py:135) [] 2023-08-07 22:13:22,464 [DEBUG]: telegram.bot (bot.decorator; bot.py:136) Exiting: get_updates 2023-08-07 22:13:22,464 [DEBUG]: telegram.bot (bot.decorator; bot.py:133) Entering: get_updates 2023-08-07 22:13:32,689 [DEBUG]: telegram.bot (bot.get_updates; bot.py:3151) No new updates found. 2023-08-07 22:13:32,689 [DEBUG]: telegram.bot (bot.decorator; bot.py:135) [] 2023-08-07 22:13:32,689 [DEBUG]: telegram.bot (bot.decorator; bot.py:136) Exiting: get_updates 2023-08-07 22:13:32,689 [DEBUG]: telegram.bot (bot.decorator; bot.py:133) Entering: get_updates 2023-08-07 22:13:38,521 [DEBUG]: urllib3.connectionpool (connectionpool._make_request; connectionpool.py:452) https://webpush.wx.qq.com:443 "GET /cgi-bin/mmwebwx-bin/synccheck?r=1691417593277&skey=&sid=Tgawq5Vk4W15kG74&uin=421845635&deviceid=e501077462636282&synckey=1_823914929%7C2_823915365%7C3_823915198%7C11_823915312%7C19_33638%7C23_1691416528%7C24_1691417544%7C27_1175843%7C201_1691417544%7C203_1691415493%7C206_101%7C1000_1691413261%7C1001_1691413323&_=1691416539338 HTTP/1.1" 200 43 2023-08-07 22:13:38,714 [DEBUG]: urllib3.connectionpool (connectionpool._make_request; connectionpool.py:452) https://webpush.wx.qq.com:443 "GET /cgi-bin/mmwebwx-bin/synccheck?r=1691417618521&skey=&sid=Tgawq5Vk4W15kG74&uin=421845635&deviceid=e151053062373940&synckey=1_823914929%7C2_823915365%7C3_823915198%7C11_823915312%7C19_33638%7C23_1691416528%7C24_1691417544%7C27_1175843%7C201_1691417544%7C203_1691415493%7C206_101%7C1000_1691413261%7C1001_1691413323&_=1691416539339 HTTP/1.1" 200 44 2023-08-07 22:13:38,714 [DEBUG]: itchat (login.sync_check; login.py:373) Unexpected sync check result: window.synccheck={retcode:"-1",selector:"0"} 2023-08-07 22:13:38,714 [DEBUG]: plugins.blueset.wechat.WeChatChannel (__init__.exit_callback; __init__.py:266) Calling exit callback... 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.slave_message (slave_message.send_message; slave_message.py:91) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] Slave message delivered to ETM. >@ [Text]: WeChat server has logged you out. Please log in again when you are ready.; __reauth__.ecadb175-8b13-455f-9221-787ad22b264c> 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.chat_object_cache (chat_object_cache.update_chat_obj; chat_object_cache.py:146) Trying to update key ('blueset.wechat', '__ews_user_auth__') with object . Full update: False 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.chat_object_cache (chat_object_cache.update_chat_obj; chat_object_cache.py:148) Key ('blueset.wechat', '__ews_user_auth__') is not in cache. Do compound enrol. 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.chat_object_cache (chat_object_cache.compound_enrol; chat_object_cache.py:53) Compound enrol 2 members of 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.chat_object_cache (chat_object_cache.enrol; chat_object_cache.py:65) Enrolling key ('blueset.wechat', '__ews_user_auth__') with value 2023-08-07 22:13:38,715 [DEBUG]: peewee (peewee.execute_sql; peewee.py:3243) ('SELECT "t1"."slave_uid", "t1"."master_uid" FROM "chatassoc" AS "t1" WHERE ("t1"."slave_uid" = ?)', ['blueset.wechat __ews_user_auth__']) 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.slave_message (slave_message.get_slave_msg_dest; slave_message.py:245) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] The message should deliver to None 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.slave_message (slave_message.get_slave_msg_dest; slave_message.py:253) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] Message is in chat 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.slave_message (slave_message.get_slave_msg_dest; slave_message.py:264) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] Message is sent to Telegram chat 348015404, with header " EWS User Auth:". 2023-08-07 22:13:38,715 [DEBUG]: efb_telegram_master.slave_message (slave_message.slave_message_text; slave_message.py:318) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] Sending as a text message. 2023-08-07 22:13:38,715 [DEBUG]: telegram.bot (bot.decorator; bot.py:133) Entering: send_chat_action 2023-08-07 22:13:39,160 [INFO]: efb_wechat_slave.vendor.wxpy.api.bot (bot._listen; bot.py:522) : stopped 2023-08-07 22:13:39,543 [DEBUG]: telegram.bot (bot.decorator; bot.py:135) True 2023-08-07 22:13:39,543 [DEBUG]: telegram.bot (bot.decorator; bot.py:136) Exiting: send_chat_action 2023-08-07 22:13:39,543 [DEBUG]: telegram.bot (bot.decorator; bot.py:133) Entering: send_message 2023-08-07 22:13:40,739 [DEBUG]: telegram.bot (bot.decorator; bot.py:135) {'date': 1691417620, 'delete_chat_photo': False, 'entities': [], 'channel_chat_created': False, 'supergroup_chat_created': False, 'new_chat_photo': [], 'caption_entities': [], 'new_chat_members': [], 'text': ' EWS User Auth:\nWeChat server has logged you out. Please log in again when you are ready.', 'reply_markup': {'inline_keyboard': [[{'text': 'Log in again', 'callback_data': '0'}]]}, 'message_id': 939963, 'group_chat_created': False, 'photo': [], 'chat': {'first_name': 'ᴢᴇxᴛʀᴇᴍᴇ', 'type': 'private', 'id': 348015404}, 'from': {'first_name': 'wechatDog', 'username': 'wechatdog_bot', 'is_bot': True, 'id': 596236213}} 2023-08-07 22:13:40,739 [DEBUG]: telegram.bot (bot.decorator; bot.py:136) Exiting: send_message 2023-08-07 22:13:40,739 [DEBUG]: efb_telegram_master.slave_message (slave_message.slave_message_text; slave_message.py:338) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] Processed and sent as text message 2023-08-07 22:13:40,739 [DEBUG]: efb_telegram_master.slave_message (slave_message.dispatch_message; slave_message.py:219) [__reauth__.ecadb175-8b13-455f-9221-787ad22b264c] Message is sent to the user with telegram message id 348015404.939963. 2023-08-07 22:13:40,740 [DEBUG]: efb_telegram_master.db (db.add_or_update_message_log; db.py:384) [348015404.939963] Received message logging request of __reauth__.ecadb175-8b13-455f-9221-787ad22b264c 2023-08-07 22:13:40,740 [DEBUG]: peewee (peewee.execute_sql; peewee.py:3243) ('SELECT "t1"."master_msg_id", "t1"."master_msg_id_alt", "t1"."slave_message_id", "t1"."text", "t1"."slave_origin_uid", "t1"."slave_origin_display_name", "t1"."slave_member_uid", "t1"."slave_member_display_name", "t1"."media_type", "t1"."mime", "t1"."file_id", "t1"."file_unique_id", "t1"."msg_type", "t1"."pickle", "t1"."sent_to", "t1"."time" FROM "msglog" AS "t1" WHERE ("t1"."master_msg_id" = ?) LIMIT ? OFFSET ?', ['348015404.939963', 1, 0]) 2023-08-07 22:13:40,740 [DEBUG]: efb_telegram_master.db (db.add_or_update_message_log; db.py:401) [348015404.939963] Message record is not found in database, insert it 2023-08-07 22:13:40,740 [DEBUG]: peewee.sqliteq (sqliteq.execute; sqliteq.py:175) received query INSERT INTO "msglog" ("master_msg_id", "master_msg_id_alt", "slave_message_id", "text", "slave_origin_uid", "slave_member_uid", "media_type", "mime", "file_id", "file_unique_id", "msg_type", "pickle", "sent_to", "time") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) 2023-08-07 22:13:40,740 [DEBUG]: peewee (peewee.execute_sql; peewee.py:3243) ('INSERT INTO "msglog" ("master_msg_id", "master_msg_id_alt", "slave_message_id", "text", "slave_origin_uid", "slave_member_uid", "media_type", "mime", "file_id", "file_unique_id", "msg_type", "pickle", "sent_to", "time") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)', ['348015404.939963', None, '__reauth__.ecadb175-8b13-455f-9221-787ad22b264c', 'WeChat server has logged you out. Please log in again when you are ready.', 'blueset.wechat __ews_user_auth__', 'blueset.wechat __ews_user_auth__ __ews_user_auth__', 'Text', None, None, None, 'Text', , 'blueset.telegram', datetime.datetime(2023, 8, 7, 22, 13, 40, 740548)]) 2023-08-07 22:13:40,743 [DEBUG]: efb_telegram_master.db (db.add_or_update_message_log; db.py:420) [348015404.939963] Database insert/update outcome: 1 2023-08-07 22:13:42,915 [DEBUG]: telegram.bot (bot.get_updates; bot.py:3151) No new updates found. 2023-08-07 22:13:42,916 [DEBUG]: telegram.bot (bot.decorator; bot.py:135) [] 2023-08-07 22:13:42,916 [DEBUG]: telegram.bot (bot.decorator; bot.py:136) Exiting: get_updates 2023-08-07 22:13:42,916 [DEBUG]: telegram.bot (bot.decorator; bot.py:133) Entering: get_updates 2023-08-07 22:13:53,140 [DEBUG]: telegram.bot (bot.get_updates; bot.py:3151) No new updates found. 2023-08-07 22:13:53,140 [DEBUG]: telegram.bot (bot.decorator; bot.py:135) [] 【贴在上面】 ```

备注 Additional context

zeXtreme commented 11 months ago

似乎是没有获取到skey参数