Drops not advancing

[OrbitalCannon]

Describe the bug

Marbles on Stream drops are not progressing despite following appropriate channels and restarting container. It progresses and collects other drops fine.

Steps to reproduce

1. Check current MoS drop %. https://www.twitch.tv/drops/inventory
2. Add any drop enabled Marbles on Stream to miner list. https://www.twitch.tv/directory/game/Marbles%20on%20Stream?tl=DropsEnabled
3. Wait 2-5 mins.
4. Check current MoS drop %. https://www.twitch.tv/drops/inventory

Expected behavior

Marbles on Stream drop progresses with watch time.

Operating system

DISM 7.1.1

Python version

3.11.4

Miner version

1.8.1

Other relevant software versions

No response

Logs

Two error entries regarding Inventory/drops.

28/05/23 07:31:23 - ERROR - [post_gql_request]: Error with GQLOperations (Inventory): HTTPSConnectionPool(host='gql.twitch.tv', port=443): Max retries exceeded with url: /gql (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f8990185850>: Failed to establish a new connection: [Errno 113] No route to host'))
09/06/23 20:07:29 - ERROR - [post_gql_request]: Error with GQLOperations (DropsHighlightService_AvailableDrops): HTTPSConnectionPool(host='gql.twitch.tv', port=443): Max retries exceeded with url: /gql (Caused by ConnectTimeoutError(<urllib3.connection.HTTPSConnection object at 0x7fbd50173e10>, 'Connection to gql.twitch.tv timed out. (connect timeout=None)'))

Additional context

No response

[rdavydov]

Logs?

[Ismaw34]

I have some recent logs from yesterday.
Its quite huge and i dont really know if there is some sensible data on there.
Is there a way to send the log file more privately?

[Ismaw34]

On the log appears to be some kind of thing with [send_minute_watched_events] because it appears like a couple of times but then even with the stream ON the is no more messages. Status: 204.

[OrbitalCannon]

Logs?

Apologies. Updated OP with two errors I see that might be related. I've since updated to 1.8.2. No error, but still not incrementing drops. If I specify a single streamer to watch it will increment the drop. But not if I have a streamer list and have it pick based off my standard priority list:

priority=[                                  
        Priority.STREAK,                    
        Priority.DROPS,                     
        Priority.SUBSCRIBED,
        Priority.ORDER  
]

In looking at the container log, it's in the chat for the user with the drop, but isn't watching as it's collecting channel points in 2 other chats.

[OrbitalCannon]

New set of errors which look like they might be related to deciding if a drop is available, or if the username already has the drop in inventory. DNS appearing to be the common denominator. That being said, there are currently drops which it's not collecting and those errors were a while ago.

10/06/23 03:23:05 - ERROR - [post_gql_request]: Error with GQLOperations (DropsHighlightService_AvailableDrops): Expecting value: line 2 column 1 (char 1)
10/06/23 02:26:38 - ERROR - [send_minute_watched_events]: Error while trying to send minute watched: HTTPSConnectionPool(host='video-edge-2cd9f3.pdx01.abs.hls.ttvnw.net', port=443): Max retries exceeded with url: /v1/segment/C... TRUNCATED_URL... V.ts (Caused by NameResolutionError("<urllib3.connection.HTTPSConnection object at 0x7f1ac06bd5d0>: Failed to resolve 'video-edge-2cd9f3.pdx01.abs.hls.ttvnw.net' ([Errno -3] Temporary failure in name resolution)"))
10/06/23 02:26:42 - ERROR - [update_client_version]: Error with update_client_version: HTTPSConnectionPool(host='www.twitch.tv', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f1ac036eed0>: Failed to establish a new connection: [Errno 113] No route to host'))
10/06/23 02:26:42 - ERROR - [post_gql_request]: Error with GQLOperations (Inventory): HTTPSConnectionPool(host='gql.twitch.tv', port=443): Max retries exceeded with url: /gql (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f1ac06bc5d0>: Failed to establish a new connection: [Errno 113] No route to host'))
10/06/23 02:27:42 - ERROR - [update_client_version]: Error with update_client_version: HTTPSConnectionPool(host='www.twitch.tv', port=443): Max retries exceeded with url: / (Caused by NameResolutionError("<urllib3.connection.HTTPSConnection object at 0x7f1ad09fbed0>: Failed to resolve 'www.twitch.tv' ([Errno -3] Temporary failure in name resolution)"))
10/06/23 02:27:42 - ERROR - [post_gql_request]: Error with GQLOperations (Inventory): HTTPSConnectionPool(host='gql.twitch.tv', port=443): Max retries exceeded with url: /gql (Caused by NameResolutionError("<urllib3.connection.HTTPSConnection object at 0x7f1ac054c0d0>: Failed to resolve 'gql.twitch.tv' ([Errno -3] Temporary failure in name resolution)"))
10/06/23 02:28:42 - ERROR - [update_client_version]: Error with update_client_version: HTTPSConnectionPool(host='www.twitch.tv', port=443): Max retries exceeded with url: / (Caused by NameResolutionError("<urllib3.connection.HTTPSConnection object at 0x7f1ad0158c50>: Failed to resolve 'www.twitch.tv' ([Errno -3] Temporary failure in name resolution)"))
10/06/23 02:28:42 - ERROR - [post_gql_request]: Error with GQLOperations (Inventory): HTTPSConnectionPool(host='gql.twitch.tv', port=443): Max retries exceeded with url: /gql (Caused by NameResolutionError("<urllib3.connection.HTTPSConnection object at 0x7f1ad1d864d0>: Failed to resolve 'gql.twitch.tv' ([Errno -3] Temporary failure in name resolution)"))

[Ismaw34]

I've sent you the logs on Telegram.
Hope you can see something useful there.
And again sorry for contacting you directly that way.

[Ismaw34]

@OrbitalCannon I got a response, turns out that i was blind, You can only watch 2 concurrent channels, so maybe you are using those slots and the program don't gets the watch time for those drops.
If you really want one drop, just disable the following list and add your desired channel.

[OrbitalCannon]

@OrbitalCannon I got a response, turns out that i was blind, You can only watch 2 concurrent channels, so maybe you are using those slots and the program don't gets the watch time for those drops. If you really want one drop, just disable the following list and add your desired channel.

Correct, only 2 channels can be watched at a time. With the priority list I posted above, it should be watching streak, then drops, then subscribed, then order, and I assume followed list after that. But that's not the behavior I'm seeing.

[jabbink]

I have the same issue (not sure since when). In the past I added a bunch of streamers to the config with follow_raid=False, claim_drops=True , watch_streak=False with Drops having high priority, on top of fetching all followers, and it would then claim drops from these people despite me not following them, if they had campaigns, but this seems to have stopped and it now only looks at followed streamers for the Drop prioritization. Not sure if I have to update my config somehow, or if this feature was never intended or is broken now

[OrbitalCannon]

Update on this issue. It applies to all drops. Unless the miner happens to be watching a channel already, or I specifically tell it to watch one or two channels it's hit or miss if it catches them. Almost like it either can't tell there are drops, or it doesn't know if I need drops. The errors mentioned in #284 (comment) continue to repeat occasionally.

[jabbink]

I checked the log and noticed a changed sha256 for the DropsHighlightService_AvailableDrops call, so I updated it locally, but still it doesn't work. Don't really have time to dig deeper into this

20/07/23 15:54:10 - DEBUG - TwitchChannelPointsMiner.classes.Twitch - [post_gql_request]: Data:
{'operationName': 'DropsHighlightService_AvailableDrops', 'extensions': {'persistedQuery': {'version': 1, 'sha256Hash': '9a62a09bce5b53e26e64a671e530bc599cb6aab1e5ba3cbd5d85966d3940716f'}}, 'variables': {'channelID': '136785688'}}
, Status code: 200,
Content:
{"data":{"channel":{"id":"136785688","viewerDropCampaigns":[],"__typename":"Channel"}},"extensions":{"durationMilliseconds":86,"operationName":"DropsHighlightService_AvailableDrops","requestID":"-removed-"}}

channel is 24/7 live with drops, request when Twitch UI does it returns

{"data":{"channel":{"id":"136785688","viewerDropCampaigns":[{"id":"","name":"Drops Week 6","game":{"id":"496916","name":"BattleBit Remastered","__typename":"Game"},"detailsURL":"https://joinbattlebit.com/","endAt":"2023-07-27T17:00:00Z","imageURL":"https://static-cdn.jtvnw.net/twitch-drops-assets-prod/CAMPAIGN-022e432a-a3fc-4f23-b049-9b8ad43faf28.png","eventBasedDrops":[],"timeBasedDrops":[a whole lot removed here],"__typename":"DropCampaign"}],"__typename":"Channel"}},"extensions":{"durationMilliseconds":92,"operationName":"DropsHighlightService_AvailableDrops","requestID":"-removed-"}}

Almost like it either can't tell there are drops

Pretty sure that's exactly it

EDIT: after debugging this locally with just one channel in the config, the GQL endpoint started to return the correct data again, both with the changed sha256 and the one currently listed in constants.py and it somehow works again now

[rdavydov]

I see, most likely related to DevilXD/TwitchDropsMiner#189 (comment)

We can try the temporary fix too, by removing the drop_tags requirement in drops_condition in Streamer.py.

I'll add the code, or maybe even release a temporary fix version soon.

[jabbink]

Funny, was about to comment that I got it fixed by removing the drops_tags requirement.

VideoPlayerStreamInfoOverlayChannel doesn't seem to return any tags anymore (besides the other issue I mentioned above, although that fixed itself) and checking some gql requests the website makes, it seems to get tags from a separate RealtimeStreamTagList call

I am too unfamiliar with how this is supposed to work but wouldn't the positive confirmation from DropsHighlightService_AvailableDrops be enough to be sure the drop is actually active?

[rdavydov]

I am too unfamiliar with how this is supposed to work but wouldn't the positive confirmation from DropsHighlightService_AvailableDrops be enough to be sure the drop is actually active?

I am also unfamiliar. ;) Looks like so.

I guess __get_campaign_ids_from_streamer should be enough then.

[rdavydov]

Please confirm that 8596d2e and 4fca577 work for you, so I can release a new version with those fixes.

[OrbitalCannon]

Please confirm that 8596d2e and 4fca577 work for you, so I can release a new version with those fixes.

I made these two changes to a test container. But the drop isn't being incremented. I did have a single error pop up, unsure if related. Most recent line at top.

EDIT: I'll monitor over the weekend to confirm fix, but it eventually did pickup a drop.

[jabbink]

After running it for a day, it seems to work, and I now see why the tag check was in there before.

Right now (with the drops_tags check removed) it will try to get drops that are set for the future (startAt in the future) and are ineligible to get. I guess at some point a filter in Twitch.__get_campaign_ids_from_streamer would be needed to filter these out (or re-use the Drops class which already parses this data)

[jabbink]

I'm far from familiar with writing Python, but something like this (I tried using the Campaign class, but some expected fields are missing), hopefully this is readable enough to understand the goal, not as pull request because it can probably be written cleaner

diff --git a/TwitchChannelPointsMiner/classes/Twitch.py b/TwitchChannelPointsMiner/classes/Twitch.py
--- a/TwitchChannelPointsMiner/classes/Twitch.py	(revision 4fca577e8b703ae32619fe489f08f9f933485b04)
+++ b/TwitchChannelPointsMiner/classes/Twitch.py	(date 1690037213547)
@@ -672,14 +672,21 @@
         json_data["variables"] = {"channelID": streamer.channel_id}
         response = self.post_gql_request(json_data)
         try:
-            return (
-                []
-                if response["data"]["channel"]["viewerDropCampaigns"] is None
-                else [
-                    item["id"]
-                    for item in response["data"]["channel"]["viewerDropCampaigns"]
-                ]
-            )
+            if response["data"]["channel"]["viewerDropCampaigns"] is None:
+                return []
+            else:
+                campaigns = []
+                for item in response["data"]["channel"]["viewerDropCampaigns"]:
+                    if "timeBasedDrops" in item:
+                        drops = list(map(lambda x: Drop(x), item["timeBasedDrops"]))
+                        drops = list(
+                            filter(lambda x: x.dt_match is True and x.is_claimed is False, drops)
+                        )
+                        if drops:
+                            campaigns.append(item["id"])
+                    else:
+                        campaigns.append(item["id"])
+                return campaigns
         except (ValueError, KeyError):
             return []
 

for someone else looking into this, a current campaign is active, but most drops are time locked for a week from now

[OrbitalCannon]

Please confirm that 8596d2e and 4fca577 work for you, so I can release a new version with those fixes.

I made these two changes to a test container. But the drop isn't being incremented. I did have a single error pop up, unsure if related. Most recent line at top.

EDIT: I'll monitor over the weekend to confirm fix, but it eventually did pickup a drop.

Did not fix. Have a drop that hasn't incremented for 2 days.

[rdavydov]

@jabbink have you tried applying your code with the filter to your miner? Did it work, any issues?

[jabbink]

Yes, the code from 2 comments above works perfectly fine for me. Had no issues until 2 or 3 days ago when claiming drops stopped working (unrelated to this change though, time keeps on increasing)

[OrbitalCannon]

Updated to 1.8.4 today and switched to the latest example.py. So far I have 2 drops that should be advancing but are not. The miner is reporting gaining points on other channels. No errors in the log. The miner seems to be present in the streamer's channel, but is collecting points elsewhere. I assume points and drop % are both triggered off the same activity?

[rdavydov]

@OrbitalCannon I'm tired of answering this. It is in the README and in the Twitch.py:
"""
Twitch has a limit - you can't watch more than 2 channels at one time.
We take the first two streamers from the list as they have the highest priority (based on order or WatchStreak).
"""

[rdavydov]

I'm not so familiar with the whole drops logic, but there is also a useful comment:
"""
Remember, you can only earn progress towards a time-based Drop on one participating channel at a time. [ ! ! ! ]
You can also check your progress towards Drops within a campaign anytime by viewing the Drops Inventory.
For time-based Drops, if you are unable to claim the Drop in time, you will be able to claim it from the inventory page until the Drops campaign ends.
"""

[OrbitalCannon]

@OrbitalCannon I'm tired of answering this. It is in the README and in the Twitch.py: """ Twitch has a limit - you can't watch more than 2 channels at one time. We take the first two streamers from the list as they have the highest priority (based on order or WatchStreak). """

My comment wasn't directed at collecting points in every single channel, the miner can only collect points in any 2 channels at one time as mentioned in the README which I've read and understand. My priority list seems to be getting ignored or drops aren't being detected and the miner is in other channels when it should be in the drop channels.

Example: There is an overwatch2 drop and a Marbles on Stream drop currently available for me. The miner is instead in two unrelated Zoo channels which I'm following.

I'm not so familiar with the whole drops logic, but there is also a useful comment: """ Remember, you can only earn progress towards a time-based Drop on one participating channel at a time. [ ! ! ! ] You can also check your progress towards Drops within a campaign anytime by viewing the Drops Inventory. For time-based Drops, if you are unable to claim the Drop in time, you will be able to claim it from the inventory page until the Drops campaign ends. """

Correct, I'm aware for any one drop you can only collect progress from one channel. Meaning if there are 2 drops and I have a Chrome/Firefox tab open for each of them it will advance both drops. If there is 1 drop and 2 tabs, it will increment at the rate of 1 tab. This works the same with the miner.

[jabbink]

after the issues I've had over the past weeks I looked a little bit more into the drop algorithm, and it's not necessarily ideal

https://github.com/rdavydov/Twitch-Channel-Points-Miner-v2/blob/master/TwitchChannelPointsMiner/classes/Twitch.py#L438

for example it will add 2 streamers to the list of watching streams despite it already being known you can only advance one at a time; furthermore there is no prioritization on drops expiring sooner; then the issue from a few comments above (about it trying to advance locked drops currently)
not sure if the goal is to have this "point miner" fixed or leave a better algorithm to a dedicated project like DevilXD/TwitchDropsMiner

[jabbink]

@OrbitalCannon from the above comment, maybe run the code in a debugger to see why it's not picking up the expected streams by putting a breakpoint in that function. It's the selection algorithm.

Possibly an idea to add debug logging for this to be able to see it in the logfile by default without checking for the minutes sent log line (giving no reason on how it was selected)

[OrbitalCannon]

after the issues I've had over the past weeks I looked a little bit more into the drop algorithm, and it's not necessarily ideal

https://github.com/rdavydov/Twitch-Channel-Points-Miner-v2/blob/master/TwitchChannelPointsMiner/classes/Twitch.py#L438

for example it will add 2 streamers to the list of watching streams despite it already being known you can only advance one at a time; furthermore there is no prioritization on drops expiring sooner; then the issue from a few comments above (about it trying to advance locked drops currently) not sure if the goal is to have this "point miner" fixed or leave a better algorithm to a dedicated project like DevilXD/TwitchDropsMiner

DevilXD refuses to offer a console only or Docker integration unfortunately.

[rdavydov]

@OrbitalCannon I see. I was referring to this

The miner seems to be present in the streamer's channel, but is collecting points elsewhere.

and instantly thought about the 2 streamer limit. Now that you've explained the priority issue, it is getting clearer, thanks.

There is a wider issue with campaigns #333 (comment) which I'm trying to fix now.

[OrbitalCannon]

@OrbitalCannon I see. I was referring to this

The miner seems to be present in the streamer's channel, but is collecting points elsewhere.

and instantly thought about the 2 streamer limit. Now that you've explained the priority issue, it is getting clearer, thanks.

There is a wider issue with campaigns #333 (comment) which I'm trying to fix now.

Ah yeah, I could see the confusion there. When I said that I was meaning the miner denotes a Join IRC Chat message for the desired channel(s) as expected for every ONLINE channel as set by chat=ChatPresence.ONLINE. So the miner is joining the channel to increase watchtime, but isn't present enough to collect points or advance drops in the desired channels. From the DevilXD project it sounds like there's a Minutes Watched event that gets sent out to Twitch to advance drops, which also as a byproduct in their project adds channel points.

I have observed the issue with not claiming drops automatically as of recent as well as mentioned in #333 , keeping an eye on that one as well.

[jabbink]

@OrbitalCannon joining the IRC channel does nothing besides notify you when you get mentioned (and set that up in the config) and give you "points" on channels that use third party bots to do so (e.g. streamelements)

a common issue I've heard from people trying to debug drops is that they have watch streak as highest priority followed by drops, and when you then start the bot, it will get 7 minutes of watch time for every channel that is live right now, because it attempts to get the watch_streak point event (which won't happen, as you already got the streak before you restarted the bot).

So before you even start gathering any drops with this (with the priorities set up as I mentioned), you would have to wait 7 minutes x amount of online streamers in your config (+ potentially followed streams) / 2

[OrbitalCannon]

@OrbitalCannon joining the IRC channel does nothing besides notify you when you get mentioned (and set that up in the config) and give you "points" on channels that use third party bots to do so (e.g. streamelements)

a common issue I've heard from people trying to debug drops is that they have watch streak as highest priority followed by drops, and when you then start the bot, it will get 7 minutes of watch time for every channel that is live right now, because it attempts to get the watch_streak point event (which won't happen, as you already got the streak before you restarted the bot).

So before you even start gathering any drops with this (with the priorities set up as I mentioned), you would have to wait 7 minutes x amount of online streamers in your config (+ potentially followed streams) / 2

Well that's interesting. That is the config I have at present STREAK, DROPS, SUBSCRIBED, ORDER with around 100 followed channels. With 17 currently live channels that would be 59.5mins before the miner would start working on drops plus any additional channels that come online during that time period. If left running for 6 hrs the miner should easily catch up even if all 100 channels come online in that period. I can try disabling the STREAK priority and see if it changes over to the drops. Appreciate the info.

I wonder if there is a way to shorten the watch streak time. When a streamer goes live I get the notification about the watch streak within a minute or two.

[jabbink]

I wonder if there is a way to shorten the watch streak time.

Twitch-Channel-Points-Miner-v2/TwitchChannelPointsMiner/classes/Twitch.py

Line 432 in 8124724

and streamers[index].stream.minute_watched < 7

has the 7 minutes used for waiting just in case for the watch_streak event

a sidenote I forgot to mention earlier: if you're also watching in a real browser, it overrides the minutes watched sent from this tool, so e.g. you are actually watching someone, and then this tool watches one stream for the "streak", and another for the "drop", you might override the "drop" stream with your real human activity. You can see this in the log via discrepancy under sending minutes watched and getting the +10 channel point logs (mentioning different channels)

[OrbitalCannon]

I wonder if there is a way to shorten the watch streak time.

Twitch-Channel-Points-Miner-v2/TwitchChannelPointsMiner/classes/Twitch.py

Line 432 in 8124724

and streamers[index].stream.minute_watched < 7

has the 7 minutes used for waiting just in case for the watch_streak event

a sidenote I forgot to mention earlier: if you're also watching in a real browser, it overrides the minutes watched sent from this tool, so e.g. you are actually watching someone, and then this tool watches one stream for the "streak", and another for the "drop", you might override the "drop" stream with your real human activity. You can see this in the log via discrepancy under sending minutes watched and getting the +10 channel point logs (mentioning different channels)

Curious if that could be lowered to 1 or 2 mins and still catch streak bonus. Would significantly decrease the amount of time spent catching streaks.

I have seen the discrepancy if watching on a browser and running the miner. Mostly having the miner take up my 2 view slots and not being able to earn channel points and drop minutes in a browser.

So far, removing STREAK from priority seems to have fixed the issue I might modify Twitch.py to drop the amount of time it watches to catch streaks and see if that resolves my issue.

[OrbitalCannon]

So removing STREAK lets the miner function as desired aside from not catching streaks.

Twitch-Channel-Points-Miner-v2/TwitchChannelPointsMiner/classes/Twitch.py

Lines 413 to 418 in 8124724

	"""
	Check if we need need to change priority based on watch streak
	Viewers receive points for returning for x consecutive streams.
	Each stream must be at least 10 minutes long and it must have been at least 30 minutes since the last stream ended.
	Watch at least 6m for get the +10
	"""

Sanity check. Has this been tested at lower values? I figured I'd start with 1min in there to see if a lower value would work.

[OrbitalCannon]

Preliminary tests seem to indicate setting this to 1 works. I'll let it run for a few days and follow up.

Twitch-Channel-Points-Miner-v2/TwitchChannelPointsMiner/classes/Twitch.py

Line 432 in 8124724

and streamers[index].stream.minute_watched < 7

[OrbitalCannon]

Running over the weekend changing

Twitch-Channel-Points-Miner-v2/TwitchChannelPointsMiner/classes/Twitch.py

Line 432 in 8124724

and streamers[index].stream.minute_watched < 7

to
and streamers[index].stream.minute_watched < 1
has functioned as desired.

[Yorik-Code]

Running over the weekend changing

Twitch-Channel-Points-Miner-v2/TwitchChannelPointsMiner/classes/Twitch.py

Line 432 in 8124724

and streamers[index].stream.minute_watched < 7

to
and streamers[index].stream.minute_watched < 1
has functioned as desired.

I am additionally testing this. I have started now and will watch how it performs over the weekend and into next week.

[OrbitalCannon]

Still functioning as desired. Part of me wonders how low we could go with it. But 1 min seems fine. I'll submit a fork and pull request.