raid-toolkit / raid-toolkit-sdk

MIT License
40 stars 13 forks source link

RTK response time #33

Closed WOROTH closed 2 years ago

WOROTH commented 2 years ago

Greetings!

I'm developing a bot script fof Raid. Couple of features are based on a Raid Extractor. Up to version 253 of a game the standalone Extractor worked just perfect, but for now both Extractor and RTK (heroes json) return delay may take up to 25 secs, that totally ruins the concept. Is there any hope for me , that the response time will be reduced?

Thanks!

dnchattan commented 2 years ago

thanks for the feedback! that seems a really high for response time so I might need to investigate a little deeper to find the root cause. It should be much, much faster than that.

For reference, I did a quick check on how long it takes to get a response when loading the data into raidchamps, and it's just under a second. image

@WOROTH couple questions:

WOROTH commented 2 years ago

Oh, i, probably, I didn 't say enough. My english is far from perfect, sorry. Both of them are honestly writing thier outputs to disk with a correct interval, but the content data is still the same. The actual data, that represents current ingame situation appears in 15-25 sec later.

I guess, the answer is somewhere inside your last point. 10 secs in quiet enough for services that provide acc info for the customer, mine requires an instant response on request, but infrequently.

Thanks!

dnchattan commented 2 years ago

Thanks for the clarification! That explains it perfectly :)

I think what I can do in the short-term is this:

Longer term, you'll be better off using the API directly from RTK instead of using extractor-- but I haven't written a Py library for it yet. I'll add this as a separate feature request, see #35

WOROTH commented 2 years ago

Great thanks! You are awesome! )) The Py lib can solve it all!

dnchattan commented 2 years ago

I've pushed a change that should make this work better now, a new update should be showing up very soon for you :). By default it will now scan every 100ms when there is an active connection to RTK, and will continue for 60 seconds after the last connection is closed.

You can configure these defaults by creating an appsettings.json file with the following settings:

{
    "app": {
        "DataSettings": {
            // refresh every 10s when idle
            "IdleIntervalMs": 10000,
            // refresh every 100ms when active
            "ActiveIntervalMs": 100,
            // keep active for 60s after last connection is closed
            "ActiveCooldownMs": 60000
        }
    }
}

Hopefully this will fix your scenario. One thing to note is that if no game data was updated, you'll see the lastUpdated property will not change-- it only updates when there is some sort of change in the game data that gets processed by RTK.

WOROTH commented 2 years ago

Oh yeah!!!! Initiating tests!!! Thank you!!!! )))

30.462944507598877 30.435094833374023 30.43527388572693

No changes, unfortunately (((

dnchattan commented 2 years ago

30.462944507598877 30.435094833374023 30.43527388572693

what are these numbers?

WOROTH commented 2 years ago

Delays between the file content changes. Thing that really wonders - resources json updates right in time, and always up to date.

Maybe, there is a way to cut the unneeded data from the game's output? For example, i use heroes and resources only, someone may not need resources at all.

dnchattan commented 2 years ago

Ah!

I think I might know the problem. There's a additional optimization in there to not refresh heroes or artifacts unless certain markers change to indicate they have new data-- but it might be missing something. It forces a refresh every 30 sec of those data sets, so that would align with the timings you're seeing.

For example the code that handles this for heroes is here: SDK/Service/Account/HeroesFacet.cs

This only refreshes if you added or ascended a new champion, which obviously isn't everything that can change.

Do you have any code you can share to reproduce this that I can use to verify it fixes it for your scenario?

WOROTH commented 2 years ago

There are tons of dependencies from user settings/media/relative paths/etc... Firstly i just picked a certain champ by id, promoted him once, and watched for the json content to change. Then i just looped a code to read the creation time of the file and print the difference, and promoted a champs in parallel. Timespans are equal.

Ascended champ reduces delay to 10 sec :)

dnchattan commented 2 years ago

Perfect, thanks. I'll put a fix together for this first thing tomorrow 😄

WOROTH commented 2 years ago

Really appreciate! Thx! )

dnchattan commented 2 years ago

alright... I think it will show a noticeable improvement now. Here's the changes I made:

Running a quick test spamming the API directly I'm getting updates showing up within 1s for most cases, and never more than 2s, so the updates are much quicker now; however when using Extractor I am seeing it take a couple seconds to run and dump the data each time around-- I'm guessing this is due to the boot cost of the .net exe every time it is run, which we might be able to improve, but for your scenario directly using the API via Py is definitely going to be preferred-- hopefully will have something you can use there soon.

Let me know if you're seeing an improvement with the latest bits, and definitely re-open this issue again if you're still seeing problems.

WOROTH commented 2 years ago

Hi and thanks! For now, heroes json does not show up. It's just missing in file list. Other jsons seem to operate fine.

Contents of the index:

{ "facets":{ "account":{"lastUpdated":"2021-11-14T16:03:13.2471447Z"}," arena":{"lastUpdated":"2021-11-14T16:03:13.2955121Z"}, "artifacts":{"lastUpdated":"2021-11-14T16:03:13.6275824Z"}, "resources":{"lastUpdated":"2021-11-14T16:06:17.0953091Z"}}, @ i suspect it might be here @ "lastUpdated":"2021-11-14T16:06:17.0953091Z" }

dnchattan commented 2 years ago

the index is updated only on the first update of each of those facets, so it may not be updated if the heroes data hasn't been updated yet. If you upgrade a hero does the index update with the new timestamp?

WOROTH commented 2 years ago

Upgrading a champ causes 'index' to update immediately.

"resources":{"lastUpdated":"2021-11-14T16:19:52.4060023Z"}}, "lastUpdated":"2021-11-14T16:19:52.4060023Z"}

And it's affecting those two.

WOROTH commented 2 years ago

File appeared. But it dos not react any manipulations on champs.

upd: 'Heroes' updates independently once in 15 min.

dnchattan commented 2 years ago

weird. that might be an issue with the game behavior.. will have to debug that one a little further

WOROTH commented 2 years ago

And should we now stop the disk IO, since using this wonderful PyLib? Or it will not bother?

dnchattan commented 2 years ago

Can you check your logs folder and see if you find any errors that look like the following? It might explain why heroes wasn't updating:

fail: Raid.Service.RaidInstance[AccountUpdateFailed] @ 2021-11-14T17:48:02.5461186-05:00
      Failed to update account facet 'heroes'
System.NullReferenceException: Object reference not set to an instance of an object.
   at Raid.Service.HeroesFacet.Merge(ModelScope scope, IReadOnlyDictionary`2 previous) in D:\git\github\raid-toolkit\raid-toolkit-sdk\SDK\Service\Account\HeroesFacet.cs:line 30
   at Raid.Service.FacetBase`3.Raid.Service.IFacet.Merge(ModelScope scope, Object previous) in D:\git\github\raid-toolkit\raid-toolkit-sdk\SDK\Service\Account\Base\Facet.cs:line 12
   at Raid.Service.RaidInstance.Update() in D:\git\github\raid-toolkit\raid-toolkit-sdk\SDK\Service\Runtime\RaidInstance.cs:line 64
WOROTH commented 2 years ago

A lots of. But the last seen more then 24 hours ago. Today's readings are 'debug' and 'info' strings only.

dnchattan commented 2 years ago

And should we now stop the disk IO, since using this wonderful PyLib? Or it will not bother?

RE: the disk IO, RTK will still keep the latest always stored in its data directory so that it is always up to date across restarts, etc.; the python lib just allows you to read the data directly from RTK instead of using Extractor. I will probably make some changes given the speed of the updates when a tool is connected so that it maybe writes less frequently while still maintaining the latest info in memory.

A lots of. But the last seen more then 24 hours ago. Today's readings are 'debug' and 'info' strings only.

I am guessing this is why updates were delayed. If a hero is consumed, sometimes it leaves a null pointer in the heroes map in the game data, which was causing this error. I've added a workaround and it seems to be working more reliably now. I'm running and seeing hero updates are now nearly instant when polling.

dnchattan commented 2 years ago

Try 1.3.12.24379 and let me know if it is working better with that update.

WOROTH commented 2 years ago

Recieved. Proceeding.

Resulting:

Now it's MUCH faster, about 30-40 sec.

dnchattan commented 2 years ago

that still seems a bit slow for updates. Can you attach your most recent log file?

WOROTH commented 2 years ago

20211115-000.log

dnchattan commented 2 years ago

something is really off about your settings, based on this log output:

dbug: Raid.Service.MainService[0] @ 2021-11-15T02:16:38.9921019+03:00
      Scheduling next update in 60000ms (active=True;until=2021-11-14T23:16:44.6064473Z)

If it is active=True, then it should be using the ActiveIntervalMs for the polling rate which defaults to 100ms, but this indicates it's using a value of 60000! 😮

This suggests that the value of app\DataSettings\ActiveIntervalMs in appsettings.json is set to 60000? do you have a custom appsettings.json file saved next to the exe? If so I suspect that's why it's taking that long to refresh.

WOROTH commented 2 years ago

Sorry, was playing with it, and forgot to restore defaults. Instantly for now, not much then a sec. You are victorious! )))

dnchattan commented 2 years ago

woohoo!!!! 🎉

thanks for all the feedback, I'm excited to see how your project turns out. Please share a link when you release anything and I can link to it from the main page 😄

you can also join the discord here if you're so inclined: https://discord.gg/qFNWuESB

WOROTH commented 2 years ago

That's just in time! Have two key questions for reverse engineering. And now i'm studying QA Engineering, that could be useful for ya.

Wow! Great party there :) How can i find YOU? )))