Chaining log entries across multiple executions

[dschibster]

Hi Jonathan,

I wanted to reach out regarding a funky thing I encountered that maybe you know about.
I was creating a process that did some funny things with Opportunities and OLIs using Platform Events out of a Site (long story, better not go into detail here). For this process, I wanted to create logs using Nebula Logger, and thought that using the Parent Transaction Uuid, I would be able to chain everything together. However, for I don't know which reason, each of the Logs still showed up separately. I know that the functionality was supposed to work for Batch Jobs, and probably a little differently than I had envisioned, but do you know if what I was trying to do is feasible?

Idea is the following: The Platform Event goes through 3 steps by executing one thing, publishing itself again, doing the second thing, publishing itself again, you get the gist. What I would really like is all three executions of the platform event to be condensed into one Log.

Hope there's an easy out for that one!

[jongpie]

Hi @dschibster - the parent transaction UUID works a little differently from how you're envisioning it, there is not a way to do exactly what you want. A Log__c record is meant to always reflect a single transaction in Salesforce, so when you have multiple transactions in a batch context (or queueable context), it's intentional behavior that multiple Log__c records are still generated - if the data was instead condensed into 1 Log__c record, there would be missing/inaccurate/misleading data on the condensed Log__c record, since a Log__c has data about a specific transaction.

Instead of condensing all LogEntry__c records into 1 single Log__c, Nebula Logger will still create separate Log__c records, and each child Log__c record is related back to the original parent Log__c record using the lookup field Log__c.ParentLog__c. For example, if you deploy & run this batch class in an org....

public with sharing class Account_Batch_Logger_Example implements Database.Batchable<SObject>, Database.Stateful {
    private String originalTransactionId;

    public Database.QueryLocator start(Database.BatchableContext batchableContext) {
        // Each batchable method runs in a separate transaction,
        // so store the first transaction ID to later relate the other transactions
        this.originalTransactionId = Logger.getTransactionId();

        Logger.info('Starting Account_Batch_Logger_Example');
        Logger.saveLog();

        // Just as an example, query 100 accounts
        return Database.getQueryLocator([SELECT Id, Name, OwnerId, Owner.Name, Type FROM Account LIMIT 100]);
    }

    public void execute(Database.BatchableContext batchableContext, List<Account> scope) {
        // One-time call (per transaction) to set the parent log
        Logger.fine('this.originalTransactionId==' + this.originalTransactionId);
        Logger.setParentLogTransactionId(this.originalTransactionId);

        for (Account account : scope) {
            // TODO add your batch job's logic

            // Then log the result
            Logger.info('Processed an account record', account);
        }

        Logger.debug('Saving account records', scope);
        update scope;

        Logger.saveLog();
    }

    public void finish(Database.BatchableContext batchableContext) {
        // The finish method runs in yet-another transaction, so set the parent log again
        Logger.fine('this.originalTransactionId==' + this.originalTransactionId);
        Logger.setParentLogTransactionId(this.originalTransactionId);

        Logger.info('Finishing running Account_Batch_Logger_Example');
        Logger.saveLog();
    }
}

...this will generate 3 Log__c records when you run Database.executeBatch(new Account_Batch_Logger_Example());

• The start() method runs first & in a separate transaction, so it generates the parent Log__c
• The execute() method runs in a separate transactions, and each time execute() runs, it generates its own Log__c records. In this example class, the execute method will only run once if you use the default batch size of 200 (since there's a limit of 100 records in the query locator), and only 1 Log__c is generated - but with a large set of data, Salesforce will call execute() multiple times, each of which is a separate transaction.
• The finish() method also runs in a separate transaction, so it also generates its own Log__c record

By using Logger.setParentLogTransactionId(this.originalTransactionId);, the Log__c records from execute() and finish() are related to the parent Log__c created in start(), using the field Log__c.ParentLog__c - if you then view the parent log & look at the "Related Logs" tab, you'll see the 2 other Log__c records. I ran this batch class in a scratch org, here is a screenshot of the resulting data:

• "Log-000012" - This is the Log__c that originated in the start() method
• "Log-000013" and "Log-000014" - these originated in execute() and finish(), and are related to `Log-000012"

Hope this helps, but please let me know if you have any follow up questions!

[dschibster]

I'm definitely seeing it now. Thanks for the clarification, I just didn't look thoroughly enough, but this already helps a lot. What I was thinking about instead of one Parent Log and several child logs was more of a "Log Group", so to say. I see the architectural vision behind having each transation condensed into one log, however in my case, the logs don't really have a hierarchy, but are more of just a sequence. Envision this.

• Aura Controller fires the Platform Event
• First execution Saves Opportunity
• Second Execution Saves OLIs
• Third Execution sends an Email.

Going to the parent log requires manual searching in my case. The potential benefit I see is that it can potentially help getting things in order outside of a Batch Job. I do get that this is quite a niche requirement, so I'm not asking you to implement this specific thing, but now I know how to look when I want to see one process in general. You could theoretically "treat" the aura controller log as the one that's the parent for my Platform Events, just not the way I originally envisioned it. :)

[jongpie]

Ahhh, ok, that helps to clarify on how you're trying to use the data - there are a few other features in Nebula Logger that might work for you. For all of these options, you would define your groupings by passing a String value that uniquely identifies your a grouping (using whatever naming convention you prefer). Once the logging data is generated using one of these options, you would just need to know what String value you want to see, and you would be able to search/filter for certain Log__c or LogEntry__c records associated with the String value. I think the main factor to consider for these options is how exactly you want to be able to report on the data.

1. Scenario-based logging

This is a relatively new feature suggested last year, and I've very recently been enhancing it (see v4.8.1 and v4.8.2 that was released just a few hours ago 😅 ), and it essentially provides a "log group" (if I understand your architectural vision correctly). If you want to try this option, I recommend upgrading to v4.8.2 so you can leverage the latest changes to this feature.

I don't have great documentation for this at the moment (I'm working on rewriting the wiki content, so better documentation will be available soon hopefully), but the general idea is you would leverage Logger.setScenario(String scenario) to identify your grouping(s). Based on how you've described your transactions/sequence, you could have your aura controller do something like this:

public class MyController {
  @AuraEnabled
  public static runSomeCode() {
    Logger.setScenario('some scenario');
    Logger.info('Some example log entry');

    // TODO Add actual logic

    Logger.saveLog();
  }
}

If you then have a second class to save an opportunity, it would also use Logger.setScenario(String), like this:

public class SomeClass {
  public static saveOpportunity(Opportunity opp) {
    Logger.setScenario('some scenario');
    Logger.info('Another example log entry, this time saving the opp', opp);
    
    // TODO Add actual logic
    update opp;
    
    Logger.saveLog();
  }
}

And repeat the same idea of using the same String scenario in the other classes/methods that saves OLIs, sending an email, etc. The end result is:

• Each String scenario value that you provide is stored as a unique LoggerScenario__c record.
• The first time Logger.setScenario(String) is used in a tranasction, the first value is used to identify the resulting Log__c record by populating the new lookup field Log__c.TransactionScenario__c.
• Each LogEntry__c that is generated in 1 transaction is also linked to LoggerScenario__c records, using the new lookup field LogEntry__c.EntryScenario__c. If you call Logger.setScenario(String scenario) multiple times in 1 transaction, Log__c.TransactionScenario__c will help you identify the "source" scenario of the transaction, and LogEntry__c.EntryScenario__c will help you identify the "source" scenario of a specific LogEntry__c within a transaction.

If you then open a "Logger Scenario" record, you can see a list of all of the related Log__c and/or LogEntry__c records that use your String scenario value(s).

2. Log Entry Tags

Another option you could consider is using log entry tags. The changes you would need to implement for this approach are somewhat similar to the changes needed to leverage scenario-based logging (examples above), but the resulting data is a little bit different - so depending on how you want to leverage the data, this option might be better for your use case.

From a data model perspective, the main differences are:

• Scenario-based logging: This feature uses "1-to-many" relationships to link Log__c and LogEntry__c records to LoggerScenario__c records (via Log__c.TransactionScenario__c and LogEntry__c.EntryScenario__c)
• Log entry tags: This features uses "many-to-many" relationships to link LogEntry__c records (not Log__c) to LoggerTag__c records, using a junction object called LogEntryTag__c

If you have not considered (or used) this option before, you may want to try this out too to see if you prefer this.

3. Use Both Option 1 & 2 Together

If you think both scenario-based logging and log entry tags would be helpful, you also can use BOTH fairly easily, like this:

public class AnotherClass {
   public static doSomething() {
       Logger.setScenario('some scenario');
       Logger.info('One more example, using tags').addTag('some tag').addTags(new List<String>{ 'another tag', 'yet another tag' });

       // TODO Add actual logic

       Logger.saveLog();
   }
}

Let me know what you think!

[dschibster]

Hi @jongpie. Sorry for not following up earlier. Scenario-grouped logging should help me here! I'm probably going to be able to simply timestamp my scenarios to have them stay unique, and that way I have pseudo-group that I can look at whenever needed. I will however need to update my version of nebula logger before that. The newest update did however do the trick there!

[jongpie]

Wonderful, glad to hear that scenario logging will hopefully work for you! If you run into any issues or questions about it, just let me know!