duo / matrix-wechat

A Matrix-WeChat puppeting bridge
GNU Affero General Public License v3.0
141 stars 11 forks source link

bridge bot won't even respond to `help` #26

Open kylrth opened 11 months ago

kylrth commented 11 months ago

Hi, this bridge has been working great for me for almost a year now. Recently I have an issue where the bridge bot won't respond to anything, even help. I've tried restarting the containers and I see the same behavior.

Here are the full logs from the bridge and the agent after recreating the containers and sending help to the bridge bot:

logs ``` services-bridge-wechat-1 | Ignoring incorrect config field type !!null at bridge->hs_proxy services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [INFO] Initializing matrix-wechat 0.2.1+dev.unknown (unknown with go1.20.5) services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Initializing database connection services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Initializing state store services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Initializing Matrix event processor services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Initializing Matrix event handler services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [INFO] Bridge initialization complete, starting... services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Running database upgrades services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Database/INFO] Database currently on v1, latest: v1 services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Database/StateStore/INFO] Database currently on v3, latest: v3 services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Checking connection to homeserver services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #1: GET https://matrix.kylrth.com/_matrix/client/versions?user_id=%40wechatbot%3Akylrth.com services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #1 (/versions) completed in 78.178928ms with status 200 and 857 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #2: GET https://matrix.kylrth.com/_matrix/client/v3/account/whoami?user_id=%40wechatbot%3Akylrth.com services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #2 (/v3/account/whoami) completed in 2.419218ms with status 200 and 52 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Helper/DEBUG] Initializing end-to-bridge encryption... services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #3: GET https://matrix.kylrth.com/_matrix/media/v3/config?user_id=%40wechatbot%3Akylrth.com services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Database/CryptoStore/INFO] Database currently on v8, latest: v8 services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Helper/DEBUG] Found existing device ID for bot in database: QAKKFSACOK services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #4: GET https://matrix.kylrth.com/_matrix/client/v3/login services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #3 (/_matrix/media/v3/config) completed in 2.533132ms with status 200 and 26 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #4 (/v3/login) completed in 4.045345ms with status 200 and 78 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #5: POST https://matrix.kylrth.com/_matrix/client/v3/login {"type":"m.login.application_service","identifier":{"type":"m.id.user","user":"@wechatbot:kylrth.com"},"device_id":"QAKKFSACOK","initial_device_display_name":"Wechat bridge"} services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #5 (/v3/login) completed in 5.663794ms with status 200 and 221 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] Stored credentials for @wechatbot:kylrth.com/QAKKFSACOK after login services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Helper/DEBUG] Logged in as bridge bot with device ID QAKKFSACOK services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Helper/DEBUG] Making sure keys are still on server services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #6: POST https://matrix.kylrth.com/_matrix/client/v3/keys/query {"device_keys":{"@wechatbot:kylrth.com":["QAKKFSACOK"]}} services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #6 (/v3/keys/query) completed in 11.034535ms with status 200 and 611 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Starting application service HTTP server services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Starting event processor services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Websocket proxy not configured, not starting application service websocket services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [INFO] Bridge started! services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [WeChat/INFO] WechatService starting to listen on 0.0.0.0:20002 services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Starting custom puppets services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/INFO] Listening on 0.0.0.0:17778 services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Helper/DEBUG] Starting syncer for receiving to-device messages services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [DEBUG] Updating bot profile services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #7: POST https://matrix.kylrth.com/_matrix/client/v3/user/@wechatbot:kylrth.com/filter {"account_data":{"not_types":["*"]},"presence":{"not_types":["*"]},"room":{"account_data":{"not_types":["*"]},"ephemeral":{"not_types":["*"]},"state":{"not_types":["*"]},"timeline":{"not_types":["*"]}}} services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Puppet/wxid_b5thn7dd9w8r22u/DEBUG] Starting custom puppet @kb:kylrth.com services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/@kb:kylrth.com/DEBUG] req #8: GET https://matrix.kylrth.com/_matrix/client/v3/account/whoami services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #9: GET https://matrix.kylrth.com/_matrix/client/v3/profile/@wechatbot:kylrth.com/avatar_url?user_id=%40wechatbot%3Akylrth.com services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #7 (/v3/user/@wechatbot:kylrth.com/filter) completed in 14.550717ms with status 200 and 17 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Crypto/Bot/DEBUG] req #10: GET https://matrix.kylrth.com/_matrix/client/v3/sync?filter=0&since=s1650651_115789612_920_2618231_393334_365_307754_3101571_0_55&timeout=30000 services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/@kb:kylrth.com/DEBUG] req #8 (/v3/account/whoami) completed in 16.301941ms with status 200 and 73 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Database/User/WARN] Failed to insert @kb:kylrth.com: pq: duplicate key value violates unique constraint "user_uin_key" services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [INFO] Checker for @kb:kylrth.com started, interval: 1m0s services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [WeChat/Client/@kb:kylrth.com/WARN] Failed to get login status: no agent connection avaiable services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #9 (/v3/profile/@wechatbot:kylrth.com/avatar_url) completed in 12.748506ms with status 200 and 58 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #11: GET https://matrix.kylrth.com/_matrix/client/v3/profile/@wechatbot:kylrth.com/displayname?user_id=%40wechatbot%3Akylrth.com services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [Matrix/Bot/DEBUG] req #11 (/v3/profile/@wechatbot:kylrth.com/displayname) completed in 3.477473ms with status 200 and 35 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:28] [WeChat/INFO] Agent connected from: 172.20.0.3:47607 services-wechat-agent-1 | Start agent manager... services-wechat-agent-1 | Start vnc... services-wechat-agent-1 | Start agent... services-wechat-agent-1 | /usr/bin/xauth: file /home/user/.Xauthority does not exist services-wechat-agent-1 | services-wechat-agent-1 | New Xtigervnc server '812f6792c6a4:5 (user)' on port 5905 for display :5. services-wechat-agent-1 | Use xtigervncviewer -SecurityTypes VncAuth,TLSVnc -passwd /home/user/.vnc/passwd 812f6792c6a4:5 to connect to the VNC server. services-wechat-agent-1 | services-wechat-agent-1 | time="2023-12-06 21:50:28" level=info msg="Manager starting to listen on 127.0.0.1:22222" services-bridge-wechat-1 | [Dec 6, 2023 21:50:41] [Matrix/DEBUG] Starting handling of transaction 282765 () services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Matrix/DEBUG] Starting handling of transaction 282768 (1 EDUs (unstable)) services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Matrix/DEBUG] Starting handling of transaction 282770 (1 EDUs (unstable)) services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Matrix/DEBUG] Starting handling of transaction 282772 (1 EDUs (unstable)) services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Matrix/DEBUG] Starting handling of transaction 282773 (1 PDUs) services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Matrix/DEBUG] Decrypting $LDR7h_77BreudcRNjMmkRinOVBAg9WOf72lIGjjNHY4 (4E7T5f/CAkgUf6LCVBgt09+NGVvDVulyBk1h0akik8w) services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Crypto/Bot/DEBUG] req #12: POST https://matrix.kylrth.com/_matrix/client/v3/keys/query {"device_keys":{"@wechatbot:kylrth.com":[]}} services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Crypto/Bot/DEBUG] req #12 (/v3/keys/query) completed in 6.842048ms with status 200 and 611 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:45] [Matrix/DEBUG] Successfully decrypted $LDR7h_77BreudcRNjMmkRinOVBAg9WOf72lIGjjNHY4 services-bridge-wechat-1 | [Dec 6, 2023 21:50:58] [Crypto/Bot/DEBUG] req #10 (/v3/sync) completed in 30.015143233s with status 200 and 227 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:50:58] [Crypto/Bot/DEBUG] req #13: GET https://matrix.kylrth.com/_matrix/client/v3/sync?filter=0&since=s1650655_115790510_930_2618240_393334_365_307755_3101571_0_55&timeout=30000 services-bridge-wechat-1 | [Dec 6, 2023 21:51:28] [WeChat/DEBUG] Send request message #2 is_login services-bridge-wechat-1 | [Dec 6, 2023 21:51:28] [WeChat/DEBUG] Receive response message #2 is_login services-bridge-wechat-1 | [Dec 6, 2023 21:51:28] [WeChat/Client/@kb:kylrth.com/WARN] Failed to get login status: PROCESS_FAILED: client not found services-bridge-wechat-1 | [Dec 6, 2023 21:51:28] [Crypto/Bot/DEBUG] req #13 (/v3/sync) completed in 30.005961935s with status 200 and 227 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:51:28] [Crypto/Bot/DEBUG] req #14: GET https://matrix.kylrth.com/_matrix/client/v3/sync?filter=0&since=s1650655_115790539_930_2618240_393335_365_307755_3101571_0_55&timeout=30000 services-bridge-wechat-1 | [Dec 6, 2023 21:51:58] [Crypto/Bot/DEBUG] req #14 (/v3/sync) completed in 30.009742492s with status 200 and 227 bytes of application/json body services-bridge-wechat-1 | [Dec 6, 2023 21:51:58] [Crypto/Bot/DEBUG] req #15: GET https://matrix.kylrth.com/_matrix/client/v3/sync?filter=0&since=s1650655_115790649_931_2618241_393335_365_307755_3101571_0_55&timeout=30000 ```

I think the relevant lines are the following:

[Database/User/WARN] Failed to insert @kb:kylrth.com: pq: duplicate key value violates unique constraint "user_uin_key"
[INFO] Checker for @kb:kylrth.com started, interval: 1m0s
[WeChat/Client/@kb:kylrth.com/WARN] Failed to get login status: no agent connection avaiable
...
[WeChat/Client/@kb:kylrth.com/WARN] Failed to get login status: PROCESS_FAILED: client not found

Any ideas for how to fix?

duo commented 10 months ago

[WeChat/Client/@kb:kylrth.com/WARN] Failed to get login status: no agent connection avaiable

This represents an issue with the matrix-wechat-agent, you can VNC it and nvestigate what the problem for WeChat client