1

I have a fresh case of strange Apex behavior that is throwing me for an absolute loop.

I have a trigger on after insert and after update that needs to cycle through some records. It will update those that are determined to be valid, and toss out those that aren't by tagging them with addError(String). It is written to do this in a for loop but in practice (and this unit test) the trigger never gets invoked with an actual List of records, just a single one.

The weird part is, debug logs being enabled or disabled seems to be directly changing how this trigger will work when tested.

When logs are enabled, all is fine. The test runs, invokes the trigger, addError(String) is called, the test catches the exception and asserts true.

When logs are disabled, which is super convenient because I am now blind to what is executed, the test runs, I think the trigger runs, but then the test hits its System.assert(false), a line I added to detect when, just like this, the exception was expected but didn't happen.

I first noticed this behavior after successfully testing, with debug logs enabled, in VSCode with the SFDX extensions and Salesforce CLI. After uploading it as a change set and running a validation, that is when I saw the tests fail, and when I noticed that they began failing in VSCode/SFDX extensions conveniently after the timer on my debug logs ran out, I tried a few more runs with and without logs to confirm this was the variable in question.

Of course none of this means anything without some code to reference; obfuscated for privacy and snipped for relevance but here is what I am working with:

Apex Trigger

final List<Id> RECORD_TYPE_IDS = new Id[] 
{
    '0123456789abcdef01', '0123456789abcdef02' // and more
};

Map<Id, Account> accountMap = new Map<Id, Account>([SELECT Id FROM Account]);

for (Custom_Object__c customRecord : (List<Custom_Object__c>) Trigger.New)
{
    Account acc = accountMap.get(customRecord.Account_Name__c);

    if (RECORD_TYPE_IDS.contains(customRecord.RecordTypeId)) 
    {
        // Note: Year__c is actually stored as a String, not a number.
        List<Custom_Object__c> otherCustomRecords = 
        [
            SELECT Year__c, RecordTypeId 
            FROM Custom_Object__c 
            WHERE Id != :customRecord.Id
            AND Account_Name__c = :acc.Id 
            AND Year__c LIKE :'%' + customRecord.Year__c + '%'
            AND RecordTypeId IN :RECORD_TYPE_IDS 
        ];

        if (otherCustomRecords.size() > 0)
        {
            customRecord.Year__c.addError('Custom Record already exists for the year ' + customRecord.Year__c);
        }
    }
}

Test Class

@TestSetup
static void setup()
{
    Account acct = new Account(Name = 'Test Account');
    insert acct;

    // The first record for a year
    Custom_Object__c testRecord = new Custom_Object__c
    (
        RecordTypeId = '0123456789abcdef01',
        Account_Name__c = acct.Id,
        Year__c = '1999'
    );
    insert testRecord;
}

@IsTest 
static void test()
{
    Test.startTest();
    Account acct = [SELECT Id FROM Account LIMIT 1];

    try
    {
        Custom_Object__c customRecord = new Custom_Object__c
        (
            RecordTypeId = '0123456789abcdef01',
            Account_Name__c = acct.Id,
            Year__c = '1999'                
        ); 
        insert customRecord;
        System.assert(false);
    }
    catch (Exception e)
    {
        // addError(String) should cause an Exception to be thrown
        System.assert(true);
    }

    Test.stopTest();
}

So, details established, the big two questions:

  1. Why on Earth would enabling debug logs affect how this test is behaving like this? Am I on the right track that it's something up with the addError(String) method or is the problem outside of that?

  2. How do I go about fixing this, and what are some things to look for in the future to prevent this?

Additional detail: Moving Test.startTest() and Test.stopTest() around so that the trigger invocation was not inside them had no effect.

Updates/Attempts: Anything that I have tried from recommendations here

  • Attempted to swap from after trigger to before trigger, since addError(String) is intended for before triggers. Appeared at first to fix it, but instead was just giving a new fail reason because the trigger was not properly converted from after to before yet. After properly adjusting field assignments and removing update statements, the old behavior (no debug logs = fail assertion, debug logs = pass assertion) returned.
  • From where are you running these tests? Apex test execution, deployment, developer console, IDE? – Kris Goncalves Nov 5 '19 at 17:40
  • @KrisGoncalves Tests are running from the SFDX/VSCode extensions. They use the Salesforce CLI to invoke everything. – A stacked cube Nov 5 '19 at 17:41
  • What event have you written your trigger on? Is it a before insert or an after insert. Please specify. Are you sure your trigger is being invoked? Also the setup method although written in your test class is not being used at all. What is the purpose? – Jigar Shah Nov 5 '19 at 18:57
  • @JigarShah The trigger is configured to fire on After Insert and After Update. I have no way to confirm it is being invoked, other than debug logs, which is a problem because enabling them causes the assertion to start passing. How is the setup method not used? A TestSetup annotated method is automatically called by the test runner prior to IsTest methods, typically so you can generate test records that are required by all IsTest methods, so you don't rewrite the same record creation process over and over. – A stacked cube Nov 5 '19 at 19:09
  • 1
    Those recommendations seem to contradict the issue at hand (not debugging). Because of what you are stating is happening, I would guess the addError(message) method is dependent on UI output or debug in this case in order to function properly in an after trigger. Documentation states: "When used on Trigger.new in before insert and before update triggers, and on Trigger.old in before delete triggers, the error message is displayed in the application interface.". Why aren't you using a before trigger in this case? Does it work correctly using after trigger (outside of test coverage)? – Glen De Marcos Nov 5 '19 at 20:29
1

After some annoying debugging using a special logging tool we built that writes logs as records, I found the culprit was in List.contains(Object).

This method does not know how to deal with an Id parameter when it's template type is also Id .

My first step was to replace:

if (RECORD_TYPE_IDS.contains(customRecord.RecordTypeId))

with...

for (Id i : RECORD_TYPE_IDS) 
{
    if (i == customRecord.RecordTypeId) 
    {
        // Do the work
    }
}

Suddenly, doing the iteration and comparison manually instead of letting List.contains(Object) deal with it for us, it's working as expected with debug logs both enabled and disabled.

This reminded me of some funky behavior you can get in Java when working with equality operators and String objects; in Java we always check String equality with String.equals(String) rather than the == operator to avoid any problems with a String object being "unequal", despite containing the same character sequence. This led me to my next solution:

final List<String> RECORD_TYPE_IDS = new String[] 
{
    '0123456789abcdef01', '0123456789abcdef02' // and more
};

and

if (RECORD_TYPE_IDS.contains((String) customRecord.RecordTypeId)) 

Again, suddenly, it is working. Problem officially solved in two different ways.

As always, when I go to check on the known issues board, THAT is when I find the issue is already reported, instead of my first search: https://success.salesforce.com/issues_view?id=a1p3A000001RXPlQAO

TL;DR = Don't use List.contains(Object) where the List is templated for Id and the parameter is also type Id. Use String instead, or do a loop and compare on your own.

| improve this answer | |

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.