force-di icon indicating copy to clipboard operation
force-di copied to clipboard

Unit of work slower when cache is enabled.

Open ralphga opened this issue 10 months ago • 14 comments

Describe the bug Hello! We are trying to optimize our code and is looking at enabling di_Configurations__c.UsePlatformCacheToStoreBindings__c And we are noticing that the UnitOfWork newInstance is slower when cache is enabled. I might be wrong but it seems that if cache is enabled, it is adding the binding to the cache but not using the cached binding in the succeeding execution?

To Reproduce I have in total:

  • 8 domain bindings
  • 26 selector bindings
  • 19 service bindings
  • 6 unit of working bindings

In a scratch org, running the code below yields these CPU time results:  fflib_ISObjectUnitOfWork uow = new fflib_SObjectUnitOfWork();

  • Disabled cache CPU time: 222 out of 10000
  • Enabled cache CPU time (3rd execution): 585 out of 10000

Selector test with 1 id, WHERE ID IN condition List<XObject> tickets = XObjectSelector.newInstance().selectByIds(new Set<String> { 'XObjectID' });

  • Disabled cache CPU time: 254 out of 10000
  • Enabled cache Maximum CPU time: 0 out of 10000 --

Expected behavior Faster execution is our expected result which we found in both Selector and Domain. Unfortunately the UnitOfWork newInstance is slower when cache is enabled.

Screenshots and text of error observed Unit of work, cache Disabled image

Unit of work, cache Enabled (3rd Execution) image

Version yes, we have the latest

ralphga avatar Apr 20 '24 00:04 ralphga

G'day @ralphga. Thanks for bringing this up.

Can you elaborate on how you are using Force-DI to store the instance of the UOW? Are you also using the AT4DX framework? Since the fflib_ISObjectUnitOfWork is not natively stored in the platform cache via Force-DI, I need more code examples of how you are connecting the two frameworks.

Thanks for the help.

ImJohnMDaniel avatar Apr 20 '24 13:04 ImJohnMDaniel

Hello John, I appreciate your work and quick response on this.

Yes, you are right, I’m using AT4DX. Apologies for raising this issue in the wrong repo as I was focusing on the di_PlatformCache.cls

Also, I sent the incorrect line of instantiating unit of work in my code, again I apologize. Here's how I call it:

fflib_ISObjectUnitOfWork uow = Application.UnitOfWork.newInstance();

Thanks again.

ralphga avatar Apr 20 '24 19:04 ralphga

Thanks @ralphga for the extra info. Should be enough to start investigating. Having said that, given the nuances, I can't promise a quick turnaround.

Another question real quick. Has this behavior been observed in any environment other than a scratch org?

ImJohnMDaniel avatar Apr 20 '24 20:04 ImJohnMDaniel

Also, @ralphg, how many bindings for the UOW factory do you have in your org? And how many total bindings of all types is Force-DI/AT4DX currently configured with?

ImJohnMDaniel avatar Apr 20 '24 20:04 ImJohnMDaniel

No worries @ImJohnMDaniel on the turnaround time :) thank you for checking this out. I run some test on our UAT environment which is a full sandbox and yes, similar behavior when cache enabled was encountered.

Here are the total current count of bindings:

  • ApplicationFactory_DomainBinding__mdt: 114
  • ApplicationFactory_SelectorBinding__mdt: 344
  • ApplicationFactory_ServiceBinding__mdt: 224
  • ApplicationFactory_UnitOfWorkBinding__mdt: 160
  • PlatformEvents_Subscription__mdt: 34

ralphga avatar Apr 20 '24 22:04 ralphga

@ralphga thanks for the info.

Just to confirm these numbers. You have 114 domain bindings? You mentioned 8 at the beginning of the thread. You have 344 selector bindings? (You mentioned 26 at the beginning.) 224 service bindings? (19 at the start) And you have 160 UOW bindings (6 at the start).

Am I missing something?

ImJohnMDaniel avatar Apr 21 '24 01:04 ImJohnMDaniel

@ImJohnMDaniel in my initial numbers, those are from a scratch org with just the base package.

The higher numbers is from the prod environment which have much more packages. I thought you were referring to prod environment when you asked for total bindings.

Apologies for the confusion.

ralphga avatar Apr 21 '24 02:04 ralphga

The performance cpu time that I posted initially is from the scratch org with total of 59 binding configurations.

ralphga avatar Apr 21 '24 02:04 ralphga

@ralphga -- Ok, makes sense now. I am good.

ImJohnMDaniel avatar Apr 21 '24 02:04 ImJohnMDaniel

@ralphga -- can I get you to setup a test with the debug level turned up to the VSCode Salesforce Extension's Replay Debugger Levels, run the execute anonymous command on the Application.UnitOfWork.newInstance(); command, then save that log file and pass it to me please?

ImJohnMDaniel avatar Apr 21 '24 04:04 ImJohnMDaniel

...Actually, can I get two log files please? One from your scratch org test and one from your production environment.

I just sent you a LinkedIn message with my email address that you can forward these logs to.

Thanks!

ImJohnMDaniel avatar Apr 21 '24 04:04 ImJohnMDaniel

@ralphga, just checking in to see if you were able to capture those log files. Please let us know when you can. Cheers!

ImJohnMDaniel avatar Apr 30 '24 08:04 ImJohnMDaniel

Hello @ImJohnMDaniel , my apologies for the delay in my response. I cannot shared any logs due to confidentiality. We are also testing on our end and found that removal of the condition below seems to improve performance for unit of work. Will test more and see if there's anything else. Thank you

image

ralphga avatar May 06 '24 21:05 ralphga

@ralphga -- thanks for the clue on line 126 of di_PlatformCache. I can definitely reproduce the issue now. I am still investigating what the root cause is but I am making progress. More to come.

ImJohnMDaniel avatar May 15 '24 02:05 ImJohnMDaniel