cache::get_from_persist_cache could be optimised

Based on profiling runs, I made the following changes:

1) The ensure_ready_for_stats function, called via record_cache_hit (only if perfdebug is on), now does a single 'isset' check (faster than array_key_exists and especially faster than two of them) as a shortcut for the common case where it doesn't need to do anything.

2) Function calls directly inside get_from_persist_cache took a surprising amount of the profile time. I have made micro-optimisations to improve performance:

a. Replace is_array with (array)$key === $key (Eloy says it's eight times faster)

b. Replace an array_key_exists call with isset (it's faster).

c. Replace function call $this->has_a_ttl() with field access $this->hasattl; I don't object to accessor methods in general, but this seems to be wasting a bit of time in a frequently-called function. I've made the function final so that nobody can override it to change behaviour without changing the field value (which comes from the cache definition).

I evaluated these changes using a 'best-of-three' methodology: (a) switch to the old branch, then make three course page requests quickly with profiling turned on; (b) switch to the new branch, then make three requests quickly with profiling; (c) out of each set of three, select the profiling run with lowest total time; (d) compare these two profiles.

On a test course page (OU 2.4.3) there are 482 calls to cache::get_from_persist_cache. Presumably, if usage of MUC increases, this performance will become more important.

I have run the cache unit tests after this change and they still pass.

TEST: ALL CHANGES ABOVE (done twice, once again after all the others)

23.6ms --> 13.3ms (~10ms)
23.7ms --> 13.2ms (~10ms)

TEST: Change (1) only

22.9ms --> 18.6ms (~4ms)

TEST: Change (2a) only

22.7ms --> 21.7ms (~1ms)

TEST: Change (2b) only

23.1ms --> 21.7ms (~1ms)

TEST: Change (2c) only (done twice because I didn't believe the first time)

22.8ms --> 19.0ms (~3ms)
23.1ms --> 21.5ms (~2ms)

Adding Sam Hemelryk here and saying, wow, those are pretty impressive improvements.

heh, I think i overstated that, forgetting these are milliseconds

Looks OK to me.

Just a side comment/warning about the proposed array_key_exists() ==> isset() change:

I'm pretty sure that along the multiple iterations of the MUC, at some point, we discussed about that optimization but, at some point, there were NULLs involved that prevented us to do so. Note I don't remember the places nor have looked to the proposed changes here. It's just a warning for Sam that sure will know, at first sight, if there are NULLs involved there.

Thanks for the hard work, ciao

Edited: "at some point" I'll stop saying "at some point" :-P

Just for the record the story was also (probably partially, but for sure at some point written there ) told here: MDL-37472.

HTH,
Matteo

Hiya,

These changes look good, I'm glad you guys have hit on them as they are areas I've picked up as well.
There are a couple of things to note:

1. $key === (array)$key - this is very cool! The same change should be applied to is_in_persist_cache and set_in_persist_cache to keep things consistent when checking this.
2. Its worth noting you can provide null as the value for a key. This change will result in the persist cache never being used to retrieve a key with a null value. It will always go to the store. Given that this wouldn't cause a bug, that it is likely to be very rare that someone sets that a null value, and that it will only impact performance I think it is a worthwhile change to make still.

Many thanks
Sam

Thanks for review comments. I'm going to make the following changes based on Sam's review:

1. is_array perf: apply change to is_in_persist_cache and set_in_persist_cache for consistency.
2. Add comment about the null values.

Will submit for integration when ready.

Changes applied as per review, submitting for integration review.

I might leave this one for Eloy to comment on - my 2c is that I agree with all the changes except the hasattl one. While this shows a small improvement, the confusion over having a function call that is never used and set final is not worth it.

Damyon: OK, I accept that one's a bit confusing. I have revised the patch to remove the function call change. I haven't redone timings but presumably this means it would save about 7ms per page on my system instead of 10ms.

This change may fall into the category of a couple that were considered yesterday i.e. should be put on hold to consider after release. Will leave that for reviewers to decide.

Yes, i'm putting this on hold this for after release so we can focus on release blockers. Thanks

Before:
Time: 18:24, Memory: 279.25Mb

OK, but incomplete or skipped tests!
Tests: 1910, Assertions: 32119, Skipped: 5.

After:
Time: 19:17, Memory: 278.50Mb

OK, but incomplete or skipped tests!
Tests: 1910, Assertions: 32119, Skipped: 5.

(running again)

Second time, it was the reverse

Integrated to master, 25 and 24 - thanks Sam

Tested during integration and I couldn't find any problems.

Thanks for your awesome work! This has now become a part of Moodle.

Closing as fixed!