Feature - Implemented retrieve_price is too noisy

[phreddrickk]

I'm not sure if this is a bug per se, but:

> js retrievePrice(Item.get("possessed sugar cube"))

Returned: 15000

> js mallPrice(Item.get("possessed sugar cube"))

Searching for "possessed sugar cube"...
Search complete.
Returned: 15000

> js mallPrice(Item.get("possessed sugar cube"))

Returned: 15000

> js mallPrice(Item.get("sweet tooth"))

Searching for "sweet tooth"...
Search complete.
Returned: 269069

> js retrievePrice(Item.get("sweet tooth"))

Using cached search results for possessed sugar cube...
Returned: 165000

When calling retrieve_price (or retrievePrice) for an item that can be created, it'll print the "Using cached search results" message every time. This message appears to be coming from MallPriceManager.searchMall.

That does not appear to happen for mall_price.

Looking at the runtime library, mall_price calls MallPriceManager.getMallPrice (which looks like it calls searchMall, which should then print the message, which is confusing), while retrieve_price calls
InventoryManager.priceToAcquire. By default, retrieve_price doesn't tell priceToAcquire to be "exact".

I'm still wading through this, but it's not clear to me why other functions don't print this. I can keep looking into this in the morning, but I figured I'd make a post in case this is intended behavior that shouldn't be touched, or in case someone else has immediate knowledge of where to look.

 

[Veracity]

There are two databases of mall prices.

"historical" prices are maintained in MallPriceDatabase
"current" prices are maintained by MallPriceManager

This message applies only to the latter.

> ash retrieve_price(1, $item[icy-hot katana], true)

Searching for "icy-hot katana"...
Search complete.
Searching for "icy katana hilt"...
Search complete.
Searching for "hot katana blade"...
Search complete.
Returned: 728

> ash retrieve_price(1, $item[icy-hot katana], true)

Returned: 728

> ash retrieve_price(10, $item[icy-hot katana], true)

Using cached search results for icy-hot katana...
Using cached search results for icy katana hilt...
Using cached search results for hot katana blade...
Returned: 2780
Searching for katana...
Search complete.

Obviously, it doesn't print it "every time". Perhaps only when you want to retrieve more of an item than is covered by the "5th cheapest" price and it needs to re-examine the saved mall searches to see if there are enough available to do that calculation?

(Interestingly enough, both the ingredients are at mall minimum - 100 and 128 - but price for 1 is listed at +500, as is the price for 10. I wonder why? tenderizing hammer? I have one.)

Have you been having a problem with retrieve_price?
What inspired this post?

 

[Rinn]

They're seeing cli output like this when running a diet planning script

===== SHOTGLASS DIET =====
Planning to fight 67 embezzlers and run 463 adventures
1 (max 1) astral pilsner value: 68200 price: 0
Assuming MPA of 6200, Total Cost 0, Total Value 68200, Net Value 68200

Trying to acquire 0 jars of Special Seasoning; max price 6200.
Casting The Ode to Booze 1 times...
You acquire an effect: Ode to Booze (15)
The Ode to Booze was successfully cast.
Drinking 1 astral pilsner...
You gain 11 Adventures
You gain 5 Strongness
You gain 19 Mysteriousness
You gain 24 Smarm
Preference _mimeArmyShotglassUsed changed from false to true
Finished drinking 1 astral pilsner.
Searching for "long pork chop sandwiches"...
Search complete.
Searching for "long pork"...
Search complete.
Searching for "black pepper"...
Search complete.
Searching for "long pork casserole"...
Search complete.
Searching for "Gnollish casserole dish"...
Search complete.
Searching for "savory dry noodles"...
Search complete.
Searching for "dry noodles"...
Search complete.
Searching for "MSG"...
Search complete.
Searching for "sweet tooth"...
Search complete.
Searching for "possessed sugar cube"...
Search complete.
Searching for "mushroom fermenting solution"...
Search complete.
Searching for "Boletus Broletus mushroom"...
Search complete.
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Searching for "tempura cauliflower"...
Search complete.
Searching for "bubbling tempura batter"...
Search complete.
Searching for "sea cauliflower"...
Search complete.
Searching for "tempura broccoli"...
Search complete.
Searching for "sea broccoli"...
Search complete.
Searching for "Miserable Pie"...
Search complete.
Searching for "Gnollish pie tin"...
Search complete.
Searching for "Every Day is Like This Sundae"...
Search complete.
Searching for "cool whip"...
Search complete.
Searching for "Hell broth"...
Search complete.
Searching for "scrumptious reagent"...
Search complete.
Searching for "hellion cube"...
Search complete.
Searching for "haunted Hell ramen"...
Search complete.
Searching for "Hell ramen"...
Search complete.
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Searching for "possessed sugar cube"...
Search complete.
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...
Using cached search results for possessed sugar cube...

===== FULL DIET =====
Planning to fight 77 embezzlers and run 522 adventures
1 extra-greasy slider helpers: Special Seasoning value: 204600 price: 94955
1 (max 1) synthetic dog hair pill value: 0 price: 250
3 (max 3) designer sweatpants value: 0 price: 0
1 (max 1) jumping horseradish(embezzler) helpers: Special Seasoning value: 80200 (additional value: 43000) price: 15387
1 (max 1) dirt julep(embezzler) value: 65800 (additional value: 41000) price: 25200
1 (max 1) dirt julep(overlap) value: 63550 (additional value: 38750) price: 25200
2 (max 3) Ambitious Turkey(embezzler) value: 100025 (additional value: 12812.5) price: 24000
1 (max 1) Rethinking Candy(ascending) value: 24750 (additional value: 24750) price: 0
1 (max 1) Rethinking Candy(overlap) value: 24750 (additional value: 24750) price: 0
1 (max 1) Rethinking Candy(embezzler) value: 38250 (additional value: 38250) price: 0
3 (max 15) Rethinking Candy(barf) value: 74250 (additional value: 24750) price: 0
1 (max 1) Extrovermectin™ value: 186000 (additional value: 186000) price: 42900
Assuming MPA of 6200, Total Cost 227892, Total Value 862175, Net Value 634283

 

[Veracity]

Uh huh. A "sweet tooth" is created by multi-using 11 "possessed sugar cube". Since 11 is greater than 5, KoLmafia has to make sure it has enough mall search results to get 11 of them.

> ash retrieve_price(1, $item[sweet tooth], true)

Searching for "sweet tooth"...
Search complete.
Searching for "possessed sugar cube"...
Search complete.
Returned: 250000

> ash retrieve_price(1, $item[sweet tooth], true)

Using cached search results for possessed sugar cube...
Returned: 250000

Looks like the script asked for the retrieve_price of a "sweet tooth" - 110 times.

 

[Rinn]

okay then, i don't really have a strong enough opinion either way here so I'll drop it

 

[Veracity]

My own diet planner - vcon - also uses retrieve_price. It never calls it more than once for the same top-level consumable, but if multiple consumables use one or more ingredients in common, I see "using cached results" for the ingredients.

One could argue that this other diet planner could be improved by only getting the retrieve price once for a "sweet tooth", rather than 110 times.

I could see putting the "cached" message under a logging conditional. It would allow turning it back on when trying to debug apparent issues, rather than having to re-insert temporary code.

 

[Rinn]

I suppose, but one could also argue that since the results of retrieve_price are cached writing another cache on top of that to not call it over and over seems like an additional layer of complexity where the benefit is reducing text output rather than server hits. I expect the assumption here was that it would operate the same way as mall_price and return immediately without side effects if the item and/or it's components were already searched for.

 

[Veracity]

OK, fine. I'll put it under a setting, then - especially since I now want to investigate that situation I mentioned above about a SMITH recipe.

 

[phreddrickk]

I think a setting is just fine; I would prefer not to have to cache the results of this script-side if only for its inconsistency with retrieve_price

 

[gausie]

 

[Veracity]

I suppose, but one could also argue that since the results of retrieve_price are cached writing another cache on top of that to not call it over and over seems like an additional layer of complexity where the benefit is reducing text output rather than server hits.

Also CPU complexity. The retrieve_price function depends on acquireCost which depends on costToMake vs. costToBuy. It recursively looks at concoctions and ingredient lists and makes the same determination. Our internal mall price cache cuts out the requests, but it’s still an expensive operation.

Adding your own cache of retrieve_price results means you eliminate a ton of CPU processing in exchange for O(1) cpu for a hash table lookup and O(N) memory for the hash table.

Not my job to assess your algorithm’s complexity for you, but the benefit is NOT just “reducing text output”.

I expect the assumption here was that it would operate the same way as mall_price and return immediately without side effects if the item and/or it's components were already searched for.

mall_price has a cache. retrieve_price does not.

Your assumption is false.

 

[Veracity]

So this is making me think more.
Tell me if I have this right.

Your script calls retrieve_price on “sweet tooth”.
That depends on the price of 11 possessed sugar cubes.
You get a result which is the min(5th cheapest mall price of sweet tooth, mall price of 11 possessed sugar cube).
Cool, cool.
You then ask 110 more times for the mall price of a sweet tooth.
KoLmafia goes through the identical calculations but, fortunately, makes no additional mall searches.
It mentions in passing that it skipped those mall searches for possessed sugar cube.

Which is to say, it mentioned in passing that you have added to the cpu complexity of your script by making an extra 110 calls to a method you’d called earlier, just in case you’d get a different result, no mall searches having been made to invalidate the earlier results.

And your response Is to say “don’t tell me about the extra complexity in my script. Please suppress the message so I can ignore it.”

Do I have that right?

 

[Rinn]

look idk what to tell you I didn't write this script, honestly I wish I hadn't brought this up at all

 

[Ryo_Sangnoir]

And your response Is to say “don’t tell me about the extra complexity in my script. Please suppress the message so I can ignore it.”

Do I have that right?

Yes.

I think most people complaining about this aren't authors of the scripts in question, and don't have the ability to change the script in the first place. And based on the discussion in this thread, there was thought that retrieve_price maintained its own internal cache, which was incorrect.

I think for most scripts server-side request times completely dwarf local processing, to the point where the latter isn't noticeable. If the extra CPU hits cost about a second overall, it won't be worth worrying about for most users. However, users can be concerned by what appears to be duplicated CLI messages. They might indicate a place where the script can be more efficient, but this isn't relevant to most people running the script, as they don't know the code.

 

[Veracity]

Well, I am adding the setting to suppress the message.

I figured out the issue with smithing items. It takes a turn, unless you have Innabox, and valueOfAdventure is 500.
And the bug is that it takes an adventure per item smithed, but we were only accounting for the value of a single adventure.

So I do have something to fix, at least.

 

[Veracity]

priceToAcquire should account for valueOfAdventure for all adventures spent by Veracity0 · Pull Request #923 · kolmafia/kolmafia

And I also added the suppressMallPriceCacheMessages property. I considered calling it suppressSuperIrritatingAndAnnoyingMallPriceCacheMessages but I thought better of it.

github.com