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.

Links

• The limitlog plug-in on NPM
• The Plug-in code repository on Github
• The Salesforce metadata repository on Github
  
  

Related Posts

• The Org Documentor
• Generating PDFs with a Salesforce CLI Plug-in
• Adding IP Ranges from a Salesforce CLI Plug-in
  
  

Follow @bob_buzzard

Callable in Salesforce Winter 19

Introduction

The Winter 19 Salesforce release introduces the Callable interface which, according to the docs:

Enables developers to use a common interface to build loosely coupled integrations between Apex classes or triggers, even for code in separate packages. 

upon reading this I spent some time scratching my head trying to figure out when I might use it. Once I stopped thinking in terms of I and started thinking in terms of we, specifically a number of distributed teams, it made a lot more sense.

Scenario

The example scenario in this post is based on two teams working on separate workstreams in a single org, the Core team and the Finance team. The Core team create functionality used across the entire org, for the Finance team and others.

The Central Service

The core team have created a Central Service interface, defining key functionality for all teams (try not to be too impressed by the creativity behind my shared action names):

public interface CentralServiceIF {
    Object action1();
    Object action2();
}

and an associated implementation for those teams that don’t have specific additional requirements:

public class CentralServiceImpl implements CentralServiceIF {
    public Object action1() {
        return 'Interfaced Action 1 Result';
    }

    public Object action2() {
        return 'Interfaced Action 2 Result';
    }
}

The Finance Implementation

The Finance team have specific requirements around the Central Service, so they create their own implementation - in the real world this would likely delegate to the Central Service and enrich with finance data, but in this case it returns a slightly different string (artist at work eh?) :

public class CentralServiceFinanceImpl implements CentralServiceIF {
    public Object action1() {
        return 'Finance Action 1 Result';
    }

    public Object action2() {
        return 'Finance Action 2 Result';
    }
}

The New Method

Everything ticks along quite happily for a period of time, and then the Core team updates the interface to introduce a new function - the third action that everyone thought was the stuff of legend. The interface now looks like:

public interface CentralServiceIF {
    Object action1();
    Object action2();
    Object action3();
}

and the sample implementation:

public class CentralServiceImpl implements CentralServiceIF {
    public Object action1() {
        return 'Interfaced Action 1 Result';
    }

    public Object action2() {
        return 'Interfaced Action 2 Result';
    }

    public Object action3() {
        return 'Interfaced Action 3 Result';
    }
}

This all deploys okay, but when the finance team next trigger processing via their implementation, there’s something rotten in the state of the Central Service:

Line: 58, Column: 1 System.TypeException: 
Class CentralServiceFinanceImpl must implement the method: 
Object CentralServiceIF.action3()

Now obviously this was deployed to an integration sandbox, where all the code comes together to make sure it plays nicely, so the situation surfaces well away from production. However, if the Core team have updated the Central Service interface in response to an urgent request from another team, then the smooth operation of the workstreams has been disrupted. As the interface is a shared resource that is resistant to change - updating it requires coordination across all teams.

The Callable Implementations

Implementing the Core Central Service as a callable:

public class CentralService implements Callable {
   public Object call(String action, Map<String, Object> args) {
       switch on action {
           when 'action1' {
               return 'Callable Action 1 result';
           }
           when 'action2' {
               return 'Callable Action 2 result';
           }
           when else {
               return null;
           }
       }
   }
}

and the Finance equivalent:

public class CentralServiceFinance implements Callable {
    public Object call(String action, Map<String, Object> args) {
        switch on action {
            when 'action1' {
                return 'Callable Action 1 result';
            }
            when 'action2' {
                return 'Callable Action 2 result';
            }
            when else {
                return null;
           }
       }
    }
}

Now when a third method is required in the Core implementation, it’s just another entry in the switch statement:

switch on action {
    when 'action1' {
        return 'Callable Action 1 result';
    }
    when 'action2' {
        return 'Callable Action 2 result';
    }
    when 'action3' {
        return 'Callable Action 3 result';
    }
    when else {
        return null;
    }
}

while the Finance implementation can remain blissfully unaware of the new functionality until it is needed, or a task to provide support for it can be added into the Finance workstream.

Managed Packages

I can also see a lot of use cases for this if you have common code distributed via managed packages to a number of orgs. You can include new functions in a release of your package without requiring every installation to update their code to the latest interface version - as you can’t update a global interface once published, you have to shift everything to a new interface (typically using a V<release> naming convention), which may cause some churn across the codebase.

Conclusion

So is this something that I’ll be using on a regular basis? Probably not. In the project that I’m working on at the moment I can think of one place where this kind of loose coupling would be helpful, but it obviously makes the code more difficult to read and understand, especially if the customer’s team doesn’t have a lot of development expertise.

My Evil Co-Worker likes the idea of building a whole application around a single Callable class - everything else would be a thin facade that hands off to the single Call function. They claim it's a way to obfuscate code, but I think it's just to annoy everyone.

Related

• Emp API in Winter 19
• Winter 19 Release Notes for Callable

 

Lighting Component Attributes - Expect the Unexpected

 

Introduction

A couple of weeks ago my BrightGen colleague, Firoz Mirza, described some unexpected (by us at least) behaviour when dealing with Lightning Component attributes. I was convinced that there must be something else going on so spent some time creating a couple of simple tests, only to realise that he was absolutely correct and attributes work a little differently to how I thought, although if I’m honest, I’ve never really thought about it.

Tales of the Unexpected 1

The basic scenario was assigning a Javascript variable to the result of extracting the attribute via component.get(), then calling another method that also extracted the value of the attribute, but crucially also changed it and set it back into the component. A sample component helper that works like this is:

({
    propertyTest : function(cmp) {
	var testVar=cmp.get('v.test');
        alert('Local TestVar = ' + JSON.stringify(testVar));
        this.changeAttribute(cmp);
        alert('Local TestVar after leaving it alone = ' + JSON.stringify(testVar));
    },
    changeAttribute : function(cmp) {
        var differentVar=cmp.get('v.test');
        differentVar.value1='value1';
        cmp.set('v.test', differentVar);
    }
})

The propertyTest function gets the attribute from the component and assigns it to testVar. After showing the value, it then invokes changeAttribute, which gets the attribute and assigns it to a new variable, updates it and then sets it back into the component.

Executing this shows the value of the property is empty, as expected to begin with:

but after the attribute has been updated elsewhere, my local variable reflects this:

 

Tales of the Unexpected 2

After a bit more digging, I came across something that I expected even less - updating a local variable that stored the result of the component.get() for the attribute, changed the value in the component. So I updated my sample component to test this:

    propertyTest2: function(cmp) {
	var test2=cmp.get('v.test');
        test2.value2='value2';
        alert('Local test2 = ' + JSON.stringify(test2));
        this.checkAttribute(cmp);
    },
    checkAttribute: function(cmp) {
        var otherVar=cmp.get('v.test');
        alert('Other var = ' + JSON.stringify(otherVar));
    }

Executing this shows my local property value being updated as expected:

but then retrieving this via another variable showed that it appeared to have been updated in the component:

“Maybe it’s just because everything is happening in the same request” I thought, but after this request completed I executed the first test, so extracting the value in a separate request (transaction) showed that the attribute had indeed been updated in a way that persisted across requests:

Checking the Docs

Convinced that I must have missed this in the docs, I went back to the Lightning Components Developer Guide, Working with Attribute Values in JavaScript section, but only found the following:

component.get(String key) and component.set(String key, Object value) retrieves and assigns values associated with the specified key on the component.

which didn’t add anything to what I already knew. 

Asking the Experts

I then asked the question of Salesforce, with my sample components, and received the following response:

The behavior you’re seeing is expected. 

component.set() is a signal to the framework that you’ve changed a value. The framework then fires change handlers, rerenders, and so forth. 

The underlying value is a JavaScript object, array, primitive, or otherwise. JavaScript object’s and arrays are mutable. Aura’s model requires that you send that signal when you mutate an object or array.

Conclusion

So there you have it - a local variable assigned the result of component.get() gives you a live hook to the component attribute, and if it’s mutable then any changes you make to the local variable update the attribute regardless of whether you call component.set() or not. Good to know!

I think the docs could certainly use with some additional information to make this clear. It’s written down here, at least, so hopefully more people will know going forward!

Related Posts

• Lightning experience utility bar - add an app for that
• Lightning Components - New Tab, New You
• Deploying Lightning Components - Go Big or Go Missing
• Lightning Component Events - Change Types with Care

 

 Follow @bob_buzzard