Log.emit() - when to emit? (triggers)

[cropredyHelix]

Great session and we've adopted this pattern in our org

Normally, one wants to Log.emit() at the end of a transaction. Some transaction boundaries are easy to ascertain (edge points: async, VF controller just before redirect, APEX REST). Other transaction boundaries are impossible to ascertain (the last trigger invocation). Triggers may invoke services or do CRUD that start other triggers that do workflows that do field updates that start new triggers...

Triggers can be edge points - user interaction with the standard UI or direct OOTB REST/SOAP API CRUD.

And, since a trigger may be part of the service started from APEX REST, async, VF controller, ... , simply adding a Log.emit() within Domain layer trigger handlers will mean the log emitted by some edge points will be partial, flushed by the trigger's Log.emit(). It gets worse if triggers indirectly start other triggers that have their own Log.emit().

One key goal of the log is to enable diagnostics after a transaction has ended but something has gone wrong that is hard to reproduce. This could include the database updated without exception, but updated incorrectly. When this happens from 3rd party systems like middleware doing OOTB REST/SOAP API it is especially useful to have logging.

I've thought about different patterns to address this in imperfect ways such as introducing this:

Log.init();  // intent to emit
Log.push('outer');
Log.message();
Log.init('inner - in a trigger now');  // intent to emit
Log.push('inner')
Log.message('do work in inner');
Log.pop();
Log.emit();  // Log.emit here does not flush because log.init stack is not at top
Log.message('more work in outer');
Log.emit();

but this generates a lot of platform events, especially when triggers call triggers, each with their own Log.emit. Thus, one has to wade through Platform Event noise when analyzing the persisted logs (however one chooses to persist)

Or, perhaps a variant to this:

Log.init();  // intent to emit
Log.push('outer');
Log.message();
Log.init('inner - in a trigger now');  // intent to emit
Log.push('inner')
Log.message('do work in inner');
Log.pop();
Log.emit();  // Log.emit does nothing if not at top level of log.init stack
Log.message('more work in outer');
Log.emit();

A secondary issue is suppressing logs in use cases where one doesn't care. Examples:

• Setting up test data in a testmethod (CRUD invokes triggers, triggers do Log.emit()
• CRUD operation where the transaction starts in a trigger but the running user is not "interesting' - such as a Data Loader repair / migration job running user, simple edits of sobjects by non-API users, ...

so, perhaps add an interface in Log:

public interface Emittable {
   Boolean isEmittable();
}

and then we have

public class MyEmittable implements Log.Emittable {
   public Boolean isEmittable() {
     return !UserInfo.getName == 'Data Loader Migration User';
  }
}
Log.init(new MyEmittable());
Log.push(..);
Log.message(..);
Log.pop();
Log.emit(); // calls the myEmittable object's method isEmittable() and if false, does not emit a Platform Event nor flush the log

Thoughts as to the correct pattern to apply to the trigger-as-transaction-edge use cases?

[afawcett]

Thanks @cropredyHelix for the feedback, glad you liked the session!

RE: Execution scopes visibility

"Normally, one wants to Log.emit() at the end of a transaction. Some transaction boundaries are easy to ascertain (edge points: async, VF controller just before redirect, APEX REST). Other transaction boundaries are impossible to ascertain (the last trigger invocation)."

Yes, when your code is not at the root of the invocation there is no way I have ever been able to find to know when all is done. Chris Peterson and I did ponder something of a platform enhancement to consider this, but it was just that a pondering. I'll pass this example over to him by way of further support to consider something in the future. For now, i think your stack counter idea is the best of less ideal ideas, though of course if a final emit does not happen to reach zero logs can be lost.

RE: suppressing logs

I like your idea, nice one!