Autostatus is firing at random times

[mrphlip]

The trick of "join the channel, then request JOIN/PART messages" mustn't be working any more, because when I restarted the bot today it sent me the autostatus message again (and presumably sent one to everyone else idling in the channel who has autostatus turned on).

Need to dig out that piece of code I had in the original autostatus implementation that would ignore JOIN messages shortly after the bot joined the channel...

[mrphlip]

Actually, it looks like this is just... happening. The bot isn't restarting, nothing seems to e particularly happening, and I just get a free status message a couple times a day, with no particular pattern in when it happens... Not sure what the solution is...

[andreasots]

Autostatus is firing on bot restarts

Can't reproduce.

Actually, it looks like this is just... happening.

There are spurious PARTs and JOINs. They happen. Don't even worry about it.

[mrphlip]

Yeah, it's just happening a lot all of a sudden. I turned autostatus off because it kept popping up, but before that, it happened 10 times in 48 hours.

The "bot restarts" theory was just that the first time it happened, the bot had been recently restarted... probably was just a coincidence.

Perhaps there's something we can do to filter out the spurious part/joins? Like, if someone parts and then joins within x minutes, don't send autostatus?

[andreasots]

I've gathered some data. Seconds from PART to next JOIN:

lrrbot; 62.853
lrrbot; 65.364
lrrbot; 60.478
lrrbot; 65.093
mrphlip; 67.016
lrrbot; 57.105
lrrbot; 69.673
mrphlip; 56.166
mrphlip; 69.681
mrphlip; 62.694
lrrbot; 70.379
lrrbot; 59.62
lrrbot; 68.484
mrphlip; 64.964
mrphlip; 67.598
lrrbot; 57.465
mrphlip; 73.704
mrphlip; 56.402
lrrbot; 55.556
mrphlip; 68.134
mrphlip; 60.888
mrphlip; 54.603
mrphlip; 52.742
lrrbot; 67.499
lrrbot; 65.38

Perhaps there's something we can do to filter out the spurious part/joins? Like, if someone parts and then joins within x minutes, don't send autostatus?

x = 90 seconds? Maybe even 80.

[AdmiralMemo]

I've gotten 3 whispers so far between 10 PM Moonbase time and 2 AM Moonbase time, while the stream's been offline.

[bunglelow]

I've done some initial investigation on this and it does seem to be triggering on restarts. The behaviour seems to follow this pattern:

1) After go live the bot receives a join messages from the server for itself joining the room:

[2016-03-28 13:18:45,876] DEBUG:irc.client:command: join, source: bunglelowbot!bunglelowbot@bunglelowbot.tmi.twitch.tv, target: #bunglelow, arguments: [], tags: None

2) A short time after that it receives join's for every member of the room and iterates through them checking for autostatus:

[2016-03-28 13:18:57,802] DEBUG:irc.client:command: join, source: bunglelowtestuser!bunglelowtestuser@bunglelowtestuser.tmi.twitch.tv, target: #bunglelow, arguments: [], tags: None ... [2016-03-28 13:18:59,488] DEBUG:irc.client:command: join, source: groverfield2!groverfield2@groverfield2.tmi.twitch.tv, target: #bunglelow, arguments: [], tags: None ... [2016-03-28 13:18:59,491] DEBUG:irc.client:command: join, source: bunglelow!bunglelow@bunglelow.tmi.twitch.tv, target: #bunglelow, arguments: [], tags: None

I've had a look through the full log (attached) to see if there was anything that triggered these joins but there wasn't anything obvious to me.

The behaviour seemed very consistent for my test case bot. I'm going to leave it running to see if i can cause any more autostatus to be triggered.

errors2.txt

[andreasots]

They weren't triggering on restarts four months ago but recently I noticed it happening it as well.

So in addition to filtering out JOINs that are less than 90 seconds after a PART, filter out JOINs that were say 90 seconds after the bot's JOIN?

[mrphlip]

I'm pretty sure we had that originally, but removed it when Twitch stopped sending a flood of JOINs on startup... now that it's doing that again, probably should dig that code out of the history and put it back in.

[bunglelow]

Left it running overnight and was also seeing some random firings. No real pattern to it

My thinking was to add a mapping of usernames to some sort of hash of show and the current day. When a join fires check to see if the show/date hash matches whats in memory, if so dont fire otherwise update the hash and send the message. Another approach would be to just map the date of last messaging and don't fire within a time period of that.

[andreasots]

What happens when you start watching something, leave for say an hour, and then come back? I think the message should fire, but it won't with your proposal.

[bunglelow]

Yeah, its a trade of between the annoyance factor vs usefulness. If you're being notified several times while watching a show you haven't left or in the chat when no show is on is that worse than coming back to a show you've previously been watching and not getting the notifications?

The simplest approach is probably a time limited one, but does result in, Memo's case for example, waking up to several notifications. A more nuanced approach may be to have scaled time factors depending on if the stream is currently live. So a shorter time to notify when its live and a much longer one when not, ie during the overnight period.