Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Feature request - shorter wait time #175

Open
Tracked by #234
doctortanuki opened this issue Apr 16, 2023 · 7 comments
Open
Tracked by #234

Feature request - shorter wait time #175

doctortanuki opened this issue Apr 16, 2023 · 7 comments
Labels
Bug Something isn't working

Comments

@doctortanuki
Copy link

doctortanuki commented Apr 16, 2023

Some game streams only last for 40 minutes to an hour and offer drops for watching for 30 minutes (Warframe is one example - they do it every week with two featured streamers after the weekly dev stream). Sometimes the stream may be longer, say, 1.5 hours, and requires watching for 40 minutes. In both cases mining often starts too late to achieve the goal and get the drop. Would it be possible to reduce the waiting time between checks from 1 hour to something shorter? Or possibly make it a custom setting?

Appreciate this wonderful program a lot, and this would make it perfect - thank you so much for making it in the first place!

EDIT: I checked the behavior in the version built from the latest source - it still persists. Warframeinternational channel is a good example - it should give one full drop per week and progress towards the next one, but it only gives some progress for the first one instead (the system is one drop for 40 minutes between that channel and official Warframe one)

@DevilXD
Copy link
Owner

DevilXD commented Apr 16, 2023

Hello o/

The thing is, the 1 hour refresh cycle is quite arbitrary - campaign start and end times are tracked in real time. That means the miner will automatically reload itself when the campaign starts already, and you can verify that by monitoring closely what it does right at the campaign start time. I'd like to not lower this 1 hour to anything shorter, because whole inventory reloads are expensive network-wise and I don't want to "hammer" Twitch with requests any more often than that. Everything needed to start and track a campaign at a specific time is already implemented and should be working - if it doesn't, that's what should be investigated, not the refresh cycle time being changed.

That being said, to tell what's happening, please provide the output from the miner with the CALL trace enabled, by passing in -vvv at startup. The period it should include is at least 5 minutes before and after an affected campaign starts.

@DevilXD DevilXD added the Bug Something isn't working label Apr 16, 2023
@doctortanuki
Copy link
Author

Thanks so much for responding! I didn't realize that is how things work.
The campaigns normally run on Thursday/Friday, so I'll just run it on Thursday, leave it until the short campaigns are done (unfortunately they happen in the middle of the night in my timezone), and then I'll paste the output here.

@doctortanuki
Copy link
Author

doctortanuki commented Apr 18, 2023

I see one potential issue with the drop already - the Prime Time campaign is scheduled to start at the exact same time that the first stream (warframeinternational) starts too:
image
image

Could this mean that if there's a slight discrepancy (e.g. the campaign becomes active a few seconds or a minute after the stream starts), the miner would wait for an hour to retry looking for a stream with available drops? Not sure if I'm explaining this correctly, and I will keep the miner running until that stream is done and post results, but just theorizing for now.

@DevilXD
Copy link
Owner

DevilXD commented Apr 18, 2023

if there's a slight discrepancy (e.g. the campaign becomes active a few seconds or a minute after the stream starts), the miner would wait for an hour to retry looking for a stream with available drops?

Not at all. Notice how the campaign lists it's ACL:
picture
This means those two channels are the only ones able to progress the campaign, and thus they should be added via previous reload to the tracked channels list up to an hour before the campaign even starts. At the start time, the entire inventory and tracked channels list is reloaded yet again, just to make sure nothing's missed, and then everything should work as expected.

In an event the channel is available already when the reload happens, the last step of the reload (channel select) should automatically start watching and progressing it. If the channel isn't immediately available, it's still added as a tracked channel (because of the ACL), and when it goes online, it'll automatically start being watched via the "channel goes online" event. Both of these situations assume that no other user condition stops it from happening, such as selecting a different channel due to the priority list, exclusion list, priority only setting, etc.

There is one case that I am aware of, where the above logic can fail, but it can only happen for campaigns without an ACL, so it doesn't apply here.

@doctortanuki
Copy link
Author

doctortanuki commented Apr 19, 2023

Here's the log from last night/this morning - again I only got 15.6% progress, because the miner only started watching at 4:59AM instead of 4:00 for some reason:

18:58:47: Logging level: CALL
18:58:47: INFO: Checking login
18:58:47: INFO: Restoring session from cookie
18:58:48: INFO: Login successful, user ID: [removed by me when pasting log]
18:58:48: INFO: Websocket[0] connecting...
18:58:49: INFO: Websocket[0] connected.
18:58:55: No active campaigns to mine drops for. Waiting for an active campaign...
18:58:55: CALL: Maintenance task waiting until: 19:28:55 (Points)
19:28:55: CALL: Maintenance task waiting until: 19:58:55 (Points)
19:58:55: CALL: Maintenance task requests a reload
19:59:00: No active campaigns to mine drops for. Waiting for an active campaign...
19:59:00: CALL: Maintenance task waiting until: 20:29:00 (Points)
20:29:00: CALL: Maintenance task waiting until: 20:59:00 (Reload)
20:59:00: CALL: Maintenance task requests a reload
20:59:05: No active campaigns to mine drops for. Waiting for an active campaign...
20:59:05: CALL: Maintenance task waiting until: 21:29:05 (Points)
21:29:05: CALL: Maintenance task waiting until: 21:59:05 (Reload)
21:59:05: CALL: Maintenance task waiting until: 21:59:05 (Reload)
21:59:05: CALL: Maintenance task requests a reload
21:59:09: No active campaigns to mine drops for. Waiting for an active campaign...
21:59:09: CALL: Maintenance task waiting until: 22:29:09 (Points)
22:29:09: CALL: Maintenance task waiting until: 22:59:09 (Points)
22:59:09: CALL: Maintenance task requests a reload
22:59:13: No active campaigns to mine drops for. Waiting for an active campaign...
22:59:13: CALL: Maintenance task waiting until: 23:29:13 (Points)
23:29:13: CALL: Maintenance task waiting until: 23:59:13 (Reload)
23:59:13: CALL: Maintenance task waiting until: 23:59:13 (Reload)
23:59:13: CALL: Maintenance task requests a reload
23:59:18: No active campaigns to mine drops for. Waiting for an active campaign...
23:59:18: CALL: Maintenance task waiting until: 00:29:18 (Points)
00:29:18: CALL: Maintenance task waiting until: 00:59:18 (Reload)
00:59:18: CALL: Maintenance task waiting until: 00:59:18 (Reload)
00:59:18: CALL: Maintenance task requests a reload
00:59:23: No active campaigns to mine drops for. Waiting for an active campaign...
00:59:23: CALL: Maintenance task waiting until: 01:29:23 (Points)
01:29:23: CALL: Maintenance task waiting until: 01:59:23 (Points)
01:59:23: CALL: Maintenance task requests a reload
01:59:27: No active campaigns to mine drops for. Waiting for an active campaign...
01:59:27: CALL: Maintenance task waiting until: 02:29:27 (Points)
02:21:45: WARNING: Websocket[0] requested reconnect.
02:21:45: WARNING: Websocket[0] reconnecting...
02:21:45: INFO: Websocket[0] connected.
02:29:27: CALL: Maintenance task waiting until: 02:59:27 (Reload)
02:50:59: WARNING: Websocket[0] requested reconnect.
02:50:59: WARNING: Websocket[0] reconnecting...
02:50:59: INFO: Websocket[0] connected.
02:59:27: CALL: Maintenance task requests a reload
02:59:32: No active campaigns to mine drops for. Waiting for an active campaign...
02:59:32: CALL: Maintenance task waiting until: 03:29:32 (Points)
03:09:57: WARNING: Websocket[0] requested reconnect.
03:09:57: WARNING: Websocket[0] reconnecting...
03:09:58: INFO: Websocket[0] connected.
03:29:32: CALL: Maintenance task waiting until: 03:59:32 (Reload)
03:59:33: CALL: Maintenance task requests a reload
03:59:38: CALL: Maintenance task waiting until: 04:00:00 (Cleanup)
03:59:38: No available channels to watch. Waiting for an ONLINE channel...
04:00:00: CALL: Maintenance task requests channels cleanup
04:00:00: CALL: Maintenance task waiting until: 04:30:00 (Points)
04:00:00: No available channels to watch. Waiting for an ONLINE channel...
04:30:00: CALL: Maintenance task waiting until: 04:59:38 (Reload)
04:59:38: CALL: Maintenance task waiting until: 04:59:38 (Reload)
04:59:38: CALL: Maintenance task requests a reload
04:59:43: CALL: Maintenance task waiting until: 05:29:43 (Points)
04:59:43: Watching: WarframeInternational
04:59:48: CALL: Drop update from websocket: Lotus Noggle (Warframe, 1/45)
05:00:48: CALL: Drop update from websocket: Lotus Noggle (Warframe, 2/45)
05:01:47: CALL: Drop update from websocket: Lotus Noggle (Warframe, 2/45)
05:02:47: CALL: Drop update from websocket: Lotus Noggle (Warframe, 3/45)
05:03:45: CALL: Drop update from websocket: Lotus Noggle (Warframe, 4/45)
05:04:45: CALL: Drop update from websocket: Lotus Noggle (Warframe, 5/45)
05:05:45: CALL: Drop update from websocket: Lotus Noggle (Warframe, 6/45)
05:06:44: CALL: Drop update from websocket: Lotus Noggle (Warframe, 7/45)
05:07:33: WarframeInternational goes OFFLINE, switching...
05:07:34: CALL: Channel update from websocket: WarframeInternational
05:09:34: CALL: WarframeInternational stays OFFLINE
05:29:43: CALL: Maintenance task waiting until: 05:59:43 (Reload)

EDIT: just checked warframeinternational, and the stream did run for an hour plus:
image

@DevilXD
Copy link
Owner

DevilXD commented Apr 20, 2023

According to the log, a channel cleanup happened exactly at 4 AM. The cleanup should've checked the online status of all channels on the list, and subscribed to their status updates. The websocket connection would then be responsible for receiving those updates within the next hour, and if one of the channels would come online, the websocket would then generate an event that would cause a channel switch to happen and start watching as expected.

But that never happened, until a reload doing another channel cleanup happened at 04:59:38 - this isn't even related to inventory being updated, but to websocket never receiving the "channel goes ONLINE" event. And that is/could be possible, because the current websocket system has no confirmations setup for the topics it subscribes to. The topic subscription message is sent, but the feedback message telling the miner it got received properly, is never handled beyond simply ignoring the returning feedback message:

elif msg_type == "RESPONSE":
# no special handling for these (for now)
pass

During websocket implementation, there was an incentive on my part to create a system where this confirmation would be handled properly, but I was having trouble synchronizing the whole thing, and the websocket was simply getting stuck and preventing the program from, well, working at all. So my solution was to simply postpone this until "later" when a need for this would arise (like it does now), and until then, simply send a request for subscription and "assume" it got through properly.

This thing has a related issue of #110, so when #110 is closed, this one should be closed as well, and vice versa. I'm leaving it open for anyone that possibly ends up with the same issue, so they can find the exact cause.

@doctortanuki
Copy link
Author

I see - thanks for looking at this and it's great to hear that the solution is in sight! Unti this is solved, I can always just launch the browser with a task scheduler to make sure I get the drops if I really want a particular one :D

@DevilXD DevilXD mentioned this issue Jun 18, 2023
10 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants