stash refreshing 1000+ times
I've been experiencing a strange issue the last couple of days.
contains 2 debug logs which were both produced in this way,
Start Debug Log
Tools > Refresh session
Stop Debug Log
The first log (labeled as 'full' in the file name) is ~45 MB was made with all of the options in Preferences > Extra Debugging enabled.
In an effort to reduce the log file size, I disabled the option "Verbosely log communication between KoLmafia and browser" and ran the test again (labeled, as 'non_verbose' in the file name). This log was ~50 MB. So!
If there is some way I can make a less lengthy log for you please advise me of the procedure to make it.
In any event, in the first log (full):
The line "Refreshing stash contents..." appears 1061 times according to Notepad++.
The line "Requesting: https://www.kingdomofloathing.com/clan_stash.php" appears 1053 times.
The second log is similar.
I'm not sure what is triggering this behavior but it seems to appear later in a session (perhaps, after switching clans a few times?). However, once it starts I am able to reproduce it with the "Refresh session" link.
Maybe a static variable somewhere getting set false/true and never being set back?
Interestingly, executing the line "ash refresh_stash()" in the cli does NOT trigger this behavior and behaves normally.
Obviously, this can take several minutes to reproduce, but eventually it does resolve itself and mafia's final idea of the stash contents seems accurate.
One other thing I noted was that trying to interrupt this behavior by mashing the ESC key one, or more, times, seems to leave mafia in an unresponsive state. IE, I had to exit and restart. Or, perhaps I was too impatient to wait long enough. I also noted that memory usage (I use the javaw.exe) appeared totally normal while this is going on.
After just watching my rollover script run, I have some more observations. I am thinking that multiple clan changes during the execution of a single script may be what is triggering this.
My rollover script hopped to BAFH to collect a buff and that transition happened normally. Then it hopped back to my home clan and the multiple refreshing happened. A bit later in the script it hopped back to BAFH to collect the free MP from the shower and the multiple refreshing happened for what appeared even more times...and then a fourth hop back home and the multiple refreshing happened for what appeared even more times. (ie Each transition seemed to cause a greater number of stash refreshes.) I can't be more specific because I can't scroll back the cli far enough to see all of these transitions again. And the session log didn't capture them at all (it just reflects a normal switching of clans.)
These clan transitions are accomplished via Bale's old clanhop script which is around here somewhere.
Last edited by AlbinoRhino; 01-22-2019 at 03:32 AM.
So, I guess this is something thread related involving types of Java functions that go over my head.
Essentially it appears to create (and register) 1000's of stash requests, and then it submits them to KOL. We don't mark stash as received until the first reply.
Maybe we need to set a refreshingStash flag in when we create a stash refresh request, clear it upon parsing stash, and check for it before running a request ?
It seems above my head as well. Another observation, is that changing clans through the browser didn't trigger it. Maybe that doesn't cause a stash request? But "Refresh Session" still will. I dunno? The only thing I can think of that might be submitting a ton of requests is the chat panel? I did recently add that to "open in tabs" in mafia config. I think I closed that tab when I made the debug logs? To reduce noise.
I was actually kind of surprised that, with the preoccupation with conserving server hits, that any duplicate request like that was allowed through so many times in such a short period. Probably things I'm not considering though.
This is a recent development and I have been racking my brain to think if I've changed anything important. We did lose power a couple of times recently...and mafia was open, but idle. Maybe a setting of some kind could have got borked?
My recollection is that clan hopping has always been dicey with mafia, in the sense that there was once difficulty in detecting that it was happening and spamming the server with "what is my clan?" requests was never a solution. Consequently I am not surprised that something weird happens with a lot of hopping.
Originally Posted by AlbinoRhino
Reveling in ignorance derived from not looking at the code (but I hope to soon) I wonder whether some kind of lazy initialization for the stash would work? Conceptually mafia only needs the contents of the stash for "item" functions so rather than fetch the contents when a clan is entered, the contents are fetched when they are first needed.
I can also imagine some kind of baroque, over-engineered scheme where an on going clan change blocks (or cancels) outstanding stash requests OR an outstanding clan request blocks a clan change.
And there may be something "fundamental" that could/should be revisited to better support clan hopping.
Originally Posted by Veracity
Well....if I am the only one experiencing it, then it makes me think there is something local that has gotten borked. But, if Refresh Session will trigger it, then I guess my ASH scripts aren't involved. If there is some setting involved, then I'm unaware of it. Just weird.
I don't have much useful to add, since I just returned from vacation, but Easyfax is having trouble and it does multiple clan hops in a single script. My trouble is that the fax machine sometimes isn't seen.
I did a quick look. Everything dealing with clans goes through ClanManager. That is an abstract class and everything of significance is static. This means you can only deal with one clan at a time and anything that is pending and not aborted or not explicitly cleared when clans are changed has the potential to bleed over.
Looking at the code, the lounge, rumpus and hot dog data is not reset when changing clans. That was done in 2017 by lost with a comment about not rechecking when you return to a clan.
With the exception of the above, everything else is cleared. The bleed potential exists because there are several requests that are issued on behalf of the current clan but they are never cancelled or waited on. Thus a long running request from one clan could update ClanManager after it had been reset for another.
One solution would be to have ClanManager track pending requests and not reset itself (clear data) until the requests are finished. Some kind of synchronizing/blocking might have a similar effect. A kludge might be to insert a delay before actually clearing the cache. Users could be advised to manage how fast they change clans. I can see the latter two causing angst for faxbots.
Just musing. If this is the first time this has occurred, I'm not sure there is much benefit in addressing it.
Thanks for looking into this. I've had the same trouble multiple times (2-3) recently. I've also had some messages about server side lag, so it is possible that's why it suddenly started. I just added a small delay into my code which might help.
The not clearing some data is because it is stored for all clans you have been in, not just current clan. Confused me for a while too.
I think this might be an issue in ClanStashRequest, which is what managed to queue up 1000 stash requests! (Probably via the RefreshConcoctions code in Clan Manager)