Messageable#send() sometimes silently fails

[charlesmadere]

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]

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]

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]

• How many channels is the bot in?
  • About 40 channels
  • (also, the bot is a verified bot account)
• Dedicated account?
  • Yes (CynanBot)
• Mod in all channels?
  • Yes, I manually add CynanBot to channels after approval from the streamer themself, and ensuring the bot has mod is a part of that onboarding process.
• How busy is the bot with commands?
  • I guess I can't really say, it can sometimes be busy-ish, however everything is async, there are almost 0 blocking calls throughout the entire codebase.

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

[charlesmadere]

@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]

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]

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

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

Thank you!

[charlesmadere]

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:

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]

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]

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]

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]

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

[IAmTomahawkx]

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.