search

PythonistaGuild / TwitchIO

An Async Bot/API wrapper for Twitch made in Python.
https://twitchio.dev
MIT License
791 stars 163 forks source link

Messageable#send() sometimes silently fails #388

Open charlesmadere opened 1 year ago

charlesmadere commented 1 year ago

I've sometimes been seeing an issue where doing something like

await messageable.send('some message here')

will result in no message being sent to the Twitch channel in question.

And no exception is raised either, as in trying to solve this bug myself, I have my send() code wrapped in a try/catch, where I then loop to try again if sending the message failed.

github-actions[bot] commented 1 year ago

Hello! Thanks for the issue. If this is a general help question, for a faster response consider joining the official Discord Server

Else if you have an issue with the library please wait for someone to help you here.

chillymosh commented 1 year ago

How many channels is the bot in? Dedicated account? Mod in all channels? How busy is the bot with commands?

Enabling logging.DEBUG will give you additional details such as 'sending messages too fast' or exceeding rate limit

charlesmadere commented 1 year ago

I didn't know about logging.DEBUG, I can investigate that and come back with more information soon.

charlesmadere commented 1 year ago

@chillymosh sorry, can you tell me how to set that logging.DEBUG option? I've been out of town for a while but I have some time to look at this now. Thank you!

IAmTomahawkx commented 1 year ago

twitchio uses the standard python logging module, simply grab the "twitchio" logger and pipe it to a file with the logging.DEBUG level.

alternatively, logging.basicConfig(level=logging.DEBUG)

charlesmadere commented 1 year ago

@IAmTomahawkx thank you 👍🏻 I've added this to my bot

I'll come back soon when I have more information.

Thank you!

charlesmadere commented 1 year ago

Here is an excerpt of some logs for a message that failed to send/show up in chat:

DEBUG:twitchio.websocket: > PRIVMSG #sefi :🐉 @sheam1835 !answer in 30s for 69 cuteness — Which United States President signed the Voting Rights Act of 1965? [A] Dwight D. Eisenhower [B] John F. Kennedy [C] Lyndon B. Johnson [D] Richard M. Nixon
DEBUG:twitchio.websocket:ACTION: PRIVMSG(ECHO):: sefi
DEBUG:twitchio.websocket:Dispatching event: message
DEBUG:twitchio.client:dispatching event message
DEBUG:twitchio.websocket: < @badge-info=subscriber/5;badges=subscriber/3,hype-train/2;client-nonce=0cc306943abf8318c5ac60b993c58b33;color=#1E90FF;display-name=LucentW;emotes=;first-msg=0;flags=;id=888a2861-b34b-4df8-9a3f-481d3d67bd7d;mod=0;returning-chatter=0;room-id=42515747;subscriber=1;tmi-sent-ts=1680604670364;turbo=0;user-id=30992900;user-type= :lucentw!lucentw@lucentw.tmi.twitch.tv PRIVMSG #sefi :it was before baby skip it went "?"

DEBUG:twitchio.websocket:Dispatching event: raw_data
DEBUG:twitchio.client:dispatching event raw_data
DEBUG:twitchio.websocket:ACTION: PRIVMSG:: sefi
DEBUG:twitchio.websocket:Dispatching event: message
DEBUG:twitchio.client:dispatching event message
DEBUG:twitchio.websocket: < @badge-info=;badges=;color=#B22222;display-name=Bowsette_Best_Waifu;emotes=;first-msg=0;flags=;id=2b120754-4aa3-4045-b48e-aa6da7424e09;mod=0;returning-chatter=0;room-id=42515747;subscriber=0;tmi-sent-ts=1680604678806;turbo=0;user-id=262686409;user-type= :bowsette_best_waifu!bowsette_best_waifu@bowsette_best_waifu.tmi.twitch.tv PRIVMSG #sefi :It just cut during babyskip for a bit

DEBUG:twitchio.websocket:Dispatching event: raw_data
DEBUG:twitchio.client:dispatching event raw_data
DEBUG:twitchio.websocket:ACTION: PRIVMSG:: sefi
DEBUG:twitchio.websocket:Dispatching event: message
DEBUG:twitchio.client:dispatching event message
DEBUG:twitchio.websocket: < :kattah!kattah@kattah.tmi.twitch.tv JOIN #jrp2234
:markfirebolt!markfirebolt@markfirebolt.tmi.twitch.tv JOIN #jrp2234

DEBUG:twitchio.websocket:Dispatching event: raw_data
DEBUG:twitchio.client:dispatching event raw_data
DEBUG:twitchio.websocket:ACTION: JOIN:: jrp2234
DEBUG:twitchio.websocket:Dispatching event: join
DEBUG:twitchio.client:dispatching event join
DEBUG:twitchio.websocket:ACTION: JOIN:: jrp2234
DEBUG:twitchio.websocket:Dispatching event: join
DEBUG:twitchio.client:dispatching event join
DEBUG:twitchio.websocket: < @badge-info=;badges=premium/1;client-nonce=2217def8fecea912e5b661fad1a72729;color=;display-name=sheam1835;emotes=;first-msg=0;flags=;id=daa118a6-3d8b-4bed-b959-a22d9986d3b6;mod=0;returning-chatter=0;room-id=42515747;subscriber=0;tmi-sent-ts=1680604687430;turbo=0;user-id=217081909;user-type= :sheam1835!sheam1835@sheam1835.tmi.twitch.tv PRIVMSG #sefi :is my trivia going to redeem? owO

DEBUG:twitchio.websocket:Dispatching event: raw_data
DEBUG:twitchio.client:dispatching event raw_data
DEBUG:twitchio.websocket:ACTION: PRIVMSG:: sefi
DEBUG:twitchio.websocket:Dispatching event: message
DEBUG:twitchio.client:dispatching event message
DEBUG:twitchio.websocket: > PRIVMSG #sefi :🐉 Sorry @sheam1835, you're out of time. 😿 The correct answer is: [C] Lyndon B. Johnson
DEBUG:twitchio.websocket:ACTION: PRIVMSG(ECHO):: sefi
DEBUG:twitchio.websocket:Dispatching event: message
DEBUG:twitchio.client:dispatching event message

Here is a screenshot of the actual chat during this:

image

Here is my code for sending messages. If Messageable#send() had thrown an exception, my code would catch that, sleep briefly, and then try again.

However, in an effort to track down this bug, I actually log every single message that CynanBot sends in every channel, with the number of attempts/retries that the message required before sending. I have never seen Messageable#send() ever throw an exception, and so, my logs for the above dropped chat message claim that the message had sent successfully without any issue:

2023/04/04 10:38:39.778 — 🐉 @sheam1835 !answer in 30s for 69 cuteness — Which United States President signed the Voting Rights Act of 1965? [A] Dwight D. Eisenhower [B] John F. Kennedy [C] Lyndon B. Johnson [D] Richard M. Nixon
2023/04/04 10:39:09.835 — 🐉 Sorry @sheam1835, you're out of time. 😿 The correct answer is: [C] Lyndon B. Johnson
charlesmadere commented 1 year ago

Please let me know if you need any more logs or anything from me, I can provide the (gigantic) log file if need be.

IAmTomahawkx commented 1 year ago

Looks like twitch dropped the message without response. Unfortunately not much the library can do. Even when they do provide an error message, there's no way to attribute it to which message was sent.

Gouvernathor commented 1 year ago

I have a case where sending "/announcegreen something" in a channel fails because, after following the logging instructions above, DEBUG:twitchio.websocket: < @msg-id=unrecognized_cmd :tmi.twitch.tv NOTICE #gouvernathor :Unrecognized command: /announcegreen Whatever the reason why it failed, TwitchIO got the info, so it should raise an exception or a minima emit a warning that can then be caught.

charlesmadere commented 8 months ago

This issue still happens pretty regularly on the latest version of TwitchIO (v2.8.2 as of the time of this writing).

IAmTomahawkx commented 8 months ago

There's nothing we can do to inform you of messages being dropped, as twitch doesn't provide any actual state information that can be linked back to the specific message. Twitch is moving to an HTTP based message sending system, which will be able to provide such data. That system will be implemented in twitchio 3 once it's available.