TwitchDropsMiner joined streams much later, some time after the streams had already started

[An-Argon-Girl]

Hi there! I'm new to having a GitHub account and stuff, so apologies if this is already a known thing that someone has written about. I noticed that with the app, with some Warframe Twitch streams that were today(they weren't set as "campaigns" on Twitch that involves the campaign section, just typical timed drops from watching streams), I noticed later on today that the miner had joined today's streams much later than they had started up on, causing a lost reward, which threw me off until I checked the time that the app joined the streams. My priority mode was set to "Priority list only", and my only game listed in the list is Warframe. My app was minimized to tray while the streams were running as well. While checking into the issue a bit, I noticed in the Output terminal that it had been outputting messages about there being no active streams, campaigns, or drops to mine for, which made me wonder if that has to do with how often the app is sending in requests to see which streams are available at the time of sending in a request to the Twitch API. I noticed a bit of a variance in frequency in when the app is sending the output messages about there being no currently active stuff as well, so I thought I'd check up here to make sure that there isn't something that's being caused on my end. This issue also happened to my friend as well today, so I suspect that it's less likely to be something on my end, but I could always be wrong, though. I appreciate you having made this awesome app! I'm glad to have an app that doesn't require you to have Twitch open in a tab at all, and the idea of saving bandwidth is always a welcome thing for sure too! I'm just hoping to be able to hopefully fix the issue and stuff :)

[An-Argon-Girl]

Apologies again if this is already a known issue or if others have already written about this issue! I couldn't find a whole lot on the issue directly myself that came up for me, so I thought I'd make this issue ticket myself in case anyone else hasn't already :)

[DevilXD]

the miner had joined today's streams much later than they had started up on, causing a lost reward

Twitch used to pre-announce upcoming campaigns before they start, and there's leftover logic in the miner that'd handle a case like that more efficiently. However, they've stopped doing that about a year ago or so (I've found a mention of it stopping working on 28th of October 2023). Now, we're relying on the miner's maintenance task doing a reload about once every hour, that re-fetches the list of campaigns and checks if something can be watched now. The nature of doing this means it may miss up to ~60 minutes off the start of a campaign, especially if a reload happens right before the campaign starts.

Besides chasing the new campaign appearing and starting, the miner also needs to find a live channel to watch. This is also done during the reload process, by fetching a list of valid live channels with drops enabled. However, this also has a chance of not working, if no live channels happens to exist at the time the reload happens. Picture this situation - a reload happens, the miner discovers a new campaign that has already started 23 minutes ago, fetches a list of live channels but finds none, so it switches to idle for the next 60 minutes. 4 minutes after the reload, a single channel goes online, and can be used to progress the new campaign, but the miner has already missed it and switched to idle, so it's not going to do anything, until another reload happens 60 minutes after the first.

There isn't really a good way to handle short campaigns with infrequently available channels. There's no fix for this either, as it'd require refreshing the inventory more often than once every hour, and that'd require a rewrite of the maintenance task at the very least. The best you can do, if you know that a campaign and a live channel are available, is to manually reload the miner by using the button on the Settings tab. The miner works the best when a live channel for a campaign already exists at the time of the reload, so it's best suited for longer campaigns with many possible channels to watch.

[jordyamc]

This problem can also be applied for ongoing campaigns,

There's 2 drops, the first one having a higher priority (ending today) and only 1 channel, and other with lower priority (ending in a week) with multiple channels.

If the first drop channel is not active the second one will be chosen, but if in the middle of the stream the first channel start streaming, the farmer will wait until the current drop is finished to change stream, if the first channel is doing a short stream or the second drop is long the first drop could be missed.

Maybe if you're in time priority mode and the current mining drop is not at the top priority the script could check channel availability for higher priority drops every 15-30 min to avoid missing them

[DevilXD]

If the first drop channel is not active the second one will be chosen, but if in the middle of the stream the first channel start streaming, the farmer will wait until the current drop is finished to change stream

That's not how it works, or at least not how it's supposed to work. Detecting a situation like this is relatively easy, and the existing logic should already handle it. At the end of the reload process, the miner iterates over the existing channels list, determining if any channel can be watched and should be switched to:

TwitchDropsMiner/twitch.py

Lines 840 to 853 in 66c3611

	# other channels additionally need to have a good reason
	# for a switch (including the watching one)
	# NOTE: we need to sort the channels every time because one channel
	# can end up streaming any game - channels aren't game-tied
	for channel in sorted(channels.values(), key=self.get_priority):
	if self.can_watch(channel) and self.should_switch(channel):
	new_watching = channel
	break
	watching_channel = self.watching_channel.get_with_default(None)
	if new_watching is not None:
	# if we have a better switch target - do so
	self.watch(new_watching)
	# break the state change chain by clearing the flag
	self._state_change.clear()

should_switch verifies that the checked channel has a higher priority than the one currently being watched, and if so, allows for the switch to happen. Note that priorities are now based on list indexes, so 0 is highest, 1 is 2nd highest, etc.:

TwitchDropsMiner/twitch.py

Lines 1005 to 1020 in 66c3611

	def should_switch(self, channel: Channel) -> bool:
	"""
	Determines if the given channel qualifies as a switch candidate.
	"""
	watching_channel = self.watching_channel.get_with_default(None)
	if watching_channel is None:
	return True
	channel_order = self.get_priority(channel)
	watching_order = self.get_priority(watching_channel)
	return (
	# this channel's game is higher order than the watching one's
	channel_order < watching_order
	or channel_order == watching_order # or the order is the same
	# and this channel is ACL-based and the watching channel isn't
	and channel.acl_based > watching_channel.acl_based
	)

[notNSANE]

I was going to post about this. It's a known issue but still... not great. I have no issues with other games, thankfully.

[DevilXD]

There isn't really a good and efficient way of solving this. The miner assumes that a campaign won't appear just before the stream starts, and even if so, it'll last longer than an hour or two. This has been happening since Twitch has removed the ability to see upcoming campaigns.

There was a "partial reload" flow being discussed under one of the already-closed past issues, that could help reduce the possibility of missing very short campaigns. However, the shorter a campaign is, the more often Twitch would need to be queried, and at doing so too often may and will annoy Twitch eventually. Getting down to 15-20 minutes per partial reload shouldn't be too much of a problem though.

A partial reload functionality would require quite a substantial rewrite of the existing reload flow though, so this may be more suited for #220.

[liveuser1]

Besides chasing the new campaign appearing and starting, the miner also needs to find a live channel to watch. This is also done during the reload process, by fetching a list of valid live channels with drops enabled. However, this also has a chance of not working, if no live channels happens to exist at the time the reload happens. Picture this situation - a reload happens, the miner discovers a new campaign that has already started 23 minutes ago, fetches a list of live channels but finds none, so it switches to idle for the next 60 minutes. 4 minutes after the reload, a single channel goes online, and can be used to progress the new campaign, but the miner has already missed it and switched to idle, so it's not going to do anything, until another reload happens 60 minutes after the first.

Why this is a case, I mean, the whole purpose of websocket is to know channel goes online moment it is. And currently program knows when channel goes online, it makes log entry.
There is example (see screenshots) - campaign starts at 09:00:00 14 december. There is partial log from program. Despite the fact that the notification of stream start has come at 17:46:58 14 dec, "watching" begins only at 18:20:13, after reload. Why not start watching immediately? Program knows there is campaign, program know what channels to monitor (and doing so via websocket), program gets channel stream start event. This shouldn't be a problem, no reload needed.

[DevilXD]

@liveuser1 Your case looks like something entirely different - no issue with channel existence for tracking is there. Instead, it looks like the channel went ONLINE, but in a state that was invalid for the miner to switch to it (either can_watch returned False, or it was already handling some other campaign and should_switch returned False), and then later on the reload has refreshed the channel status into a valid state, causing it to start mining.

There's two systems designed to detect channel changes, both relying on the websocket connection. One of them listens for a "channel goes OFFLINE/ONLINE" change, and the other listens for "channel changed it's settings" event. Both use the Channel.check_online() method, which waits 30 seconds after the event (to let the user do multiple changes, and let Twitch settle down on the game, title, tags, etc.), and then fetches the new stream data. This new stream data eventually ends up being ran through Twitch.on_channel_update(channel, before_stream, after_stream), which does all the logic on deciding what to do with the channel changing it's status.

I've taken a quick look at it, and it surprisingly looks like there's not much logic for a case where a channel goes from ONLINE to ONLINE (stays ONLINE), but has been updated in some other way (including game changes, and the "drops enabled" flag):

TwitchDropsMiner/twitch.py

Lines 1139 to 1144 in 2c5f56b

	# Channel is and stays ONLINE, but has been updated
	logger.info(
	f"{channel.name} status has been updated "
	f"(🎁: {stream_before.drops_enabled and '✔' or '❌'} -> "
	f"{stream_after.drops_enabled and '✔' or '❌'})"
	)

This very well qualifies it as a bug. Running a git blame points towards a commit made on 13th of December 2022, over two years ago by now, in which this bug was introduced: b6bc2e1

The 651d73a commit fixes (or at least should fix) this issue.

The original problem this issue describes still remains here.

[liveuser1]

Seems like issue with channel drops_enabled not correctly detected after update from websocket.
Next 2 screenshots were made at 18:05.
Drops campaign on channel newmultishow is well underway, in fact it is nearly complete from previous stream:

channel newmultishow goes online 17:36, but "wathing" does not start, looks like program thinks drops are not enabled for this channel. "wathing" finally started only after reload at 18.25.

[DevilXD]

@liveuser1 Please make sure you're using the latest version of the miner, a long-present bug has been fixed 9 days ago, that could cause exactly the issues you're describing: 651d73a

[JourneyOver]

Going by his screenshots he is running commit 651d73a (which is the last commit so far) at least going by the title bar of TDM.

[liveuser1]

@liveuser1 Please make sure you're using the latest version of the miner, a long-present bug has been fixed 9 days ago, that could cause exactly the issues you're describing: 651d73a

I have latest build 651d73a, with corrections you made after my previous report 9 days ago. It did not fix the issue.

To troubleshoot it would be nice to add log records like "new campaign .. detected, dates are..", "drops ... claimed for campaign ..", "drops enabled (disabled) on channel .. (after channel status check)", maybe save gql response if drops are not enabled on channel with active campaign.

[DevilXD]

There's currently no way to detect new campaigns, the whole inventory is thrown away and replaced with new inventory on every reload. Unless you want to get 50+ messages about detected campaigns, I think it's not a good idea to add that. Drops being claimed are also not happening, since that's not been a thing since Twitch removed the claim-available websocket event - now, drops are claimed during the inventory rebuild process at the beginning of each reload. Drops getting enabled or disabled are already a thing, and it not printing anything here suggests to me that the channel simply haven't enabled those:

TwitchDropsMiner/twitch.py

Lines 1140 to 1144 in 651d73a

	logger.info(
	f"{channel.name} status has been updated "
	f"(🎁: {stream_before.drops_enabled and '✔' or '❌'} -> "
	f"{stream_after.drops_enabled and '✔' or '❌'})"
	)

If they were enabled, then the current method of detecting if drops are enabled or not is faulty, and there's no other way to detect this, so this isn't fixable. No amount of saving GQL responses will help here. If the current method doesn't work, I see nothing I can do here to help it.

[liveuser1]

How and why this is happening? I mean, campaign is active, campaign have only one eligible channel, this channel been streaming during this campaign with drops enabled. And now it start streaming again and drop disabled on channel? Is it something streamer control or twitch? Is it possible twitch enables drops in more than 30s after stream start - maybe making bigger delay before stream status check will help? Maybe make this delay a configurable option.

[DevilXD]

This piece of code is responsible for checking for the drops_enabled flag:

TwitchDropsMiner/channel.py

Lines 273 to 286 in 651d73a

	if not stream.drops_enabled:
	try:
	available_drops_campaigns: JsonType = await self._twitch.gql_request(
	GQL_OPERATIONS["AvailableDrops"].with_variables({"channelID": str(self.id)})
	)
	except MinerException:
	logger.log(CALL, f"AvailableDrops GQL call failed for channel: {self._login}")
	else:
	stream.drops_enabled = any(
	bool(campaign["timeBasedDrops"])
	for campaign in (
	available_drops_campaigns["data"]["channel"]["viewerDropCampaigns"] or []
	)
	)

You're right about the flag state being altered after stream start - Twitch doesn't seem to include it's status change in the channel status update event. The event handler runs every time a new stream information is fetched, including when game, title and tags are changed. Note that since the drops_enabled flag isn't a tag anymore since over a year by now, it's not included in the channel status update event. This essentially means that it's indeed possible for a channel to disable the tag, start the stream, the miner updates the channel status 20s later, and then after that, enable the flag, without Twitch sending an update about it. After that, the tag is enabled on the server side, but disabled on the miner side. This is entirely on Twitch for not sending an update when the flag status is changed.

Normally people don't disable the flag though, so this is quite an over-exaggerated scenario. They'd need to have a reason to keep toggling it constantly. I could increase the delay back to the 2 minutes it was before 06d495c. I see no point in making it a configurable option, I decreased it hoping that full 2 minutes aren't needed to start mining on a channel once it gets online, but it looks like it actually matters a little. I'll just bring it back to the 2 minutes it was before.

EDIT: The commit was reverted: 1cd408f