Saturday 26 June 2021

Extracting Limits Information from Test Debug Logs

(The follow up to No Limits by 2Unlimited)

Introduction

In large enterprise Salesforce implementations there's often a particular piece of functionality that is limit-poor - it consumes most of one or more limits as a matter of course.  It might have to retrieve information from myriad standard and custom objects, update a whole load of other objects and do a bunch of processing in between that consumes a lot of CPU time, and when it is invoked with a large number of records it flies close to the maximum values like Icarus flying too close to the sun. Often these areas will have unit tests so that unlike Icarus they don't fall into the sea and drown if the code is changed to add a few more SOQL queries.

Often these tests will try to ensure the published maximum number of records can still be handled, but the problem there is that by the time the test fails you have nowhere to go. Another approach is to determine how much of each limit is currently consumed and fail the test if it goes over, which leads to brittle tests that fail for minor changes or, in the case of CPU time, flappy tests that sometimes pass and sometimes fail  even though the code hasn't changed, depending on what else is happening on the Salesforce instance. 

Ideally there would be some way to figure out when the consumed limits change, but without the nuclear option of failing the unit test. In Apex everything that tests do is rolled back when the test completes, regardless of success or failure, sending notifications isn't an option, nor is saving the limit information to an object. This is something I've been wrestling with for years and haven't been able to come up with a solution for. Until now. And in a turn of events that will surprise nobody, it involves a Salesforce CLI plug-in.

The Plug-in

The limitlog plug-in executes the unit test supplied by the user, then relies on the fact that unit tests always generate a debug log - from the Salesforce help on Debug Logs Order of Precedence :

If you don’t have active trace flags, synchronous and asynchronous Apex tests execute with the default logging levels.

The most recent log for the user is then retrieved, and the limits information parsed from it. There's a bit of a wrinkle around this if your org has a namespace, so the plug-in allows you to specify one if you need something other than the default.

The limits information is then returned in JSON format or written to a Salesforce custom object - you can find the metadata for this at the limitlogsalesforce Github repository. 

The metadata also includes a flow that checks the limit information from the previous run for the unit test and sends me an email if anything is different:

So now I can add the plug-in to my continuous integration operations and get notified if the limits consumption has gone up, without having to force unit test failures. 

Installing and Executing

If you want to capture the limit information in Salesforce, the first thing to do is spin up a scratch org or developer edition, clone the limitlogsalesforce Github repository and push/deploy to this org. Make sure to authenticate against it via the CLI.

Next, identify or create a unit test that has some limit impact - this can be in the same developer/scratch org or a different one.

The install the plug-in into your CLI :

    sfdx plugins:install limitlog

Then execute the test command from the plug-in as follows:

sfdx bblimlog:test -n LimitLogSample -r KABDEV -t LimitLogSampleTest.DoWorkTest -s KAB_TUTORIAL -u LIMITLOG -w

where:

  • -n LimitLogSample is the unique name for this test - the flow uses this to find the previous record and figure out if anything has changed.
  • -r KABDEV is the username to run the tests as. If your tests are in the same org as you are writing the data, you can omit this.
  • -t LimitLogSampleTest.DoWorkTest is the unit test method to run
  • -s KAB_TUTORIAL is the namespace of my dev org - if you don't have a namespace, omit this to pick up the default
  • -u LIMITLOG is the username for the org where the test information will be written to
  • -w says to write the limits objects to Salesforce. If you don't supply this, make sure to add the --json switch to see the output.

You will then see output similar to the following:

Executing test LimitLogSampleTest.DoWorkTest
Retrieving test log file
Extracting limits information
Writing limits information to Salesforce
Limits information written to Salesforce

and the limits record will be available in the Salesforce UI:


and here's the list of records in my org that caused the notifications to be sent when the limits increased:


In future blogs I'll go through how this works under the hood, but this feels like enough for now. As this is the first version of the plug-in I'm sure there will be some scenarios it doesn't handle - if you come across one of these, please raise an issue in the plug-in source repo and I'll see what I can do.

No comments:

Post a Comment