1

I've been trying to debug a complex issue in a production system by looking at field history tracking and the system fields. Something that threw me off the trail is a difference between the CreatedDate of an object and its field history records. Having notice the oddness, here's some code I ran in developer console:

System.debug([SELECT CreatedDate, Name FROM Invoice__c WHERE Id = 'a0B1a00000LlnHp']);
System.debug([SELECT CreatedDate, ParentId, OldValue, NewValue, Field FROM Invoice__History WHERE ParentId  = 'a0B1a00000LlnHp' ORDER BY CreatedDate ASC LIMIT 2]);

The result of this is:

(Invoice__c:{CreatedDate=2018-07-08 22:00:56, Name=INV-0002874639, Id=a0B1a00000LlnHpEAJ, RecordTypeId=0121a000000AJtzAAG})
(Invoice__History:{CreatedDate=2018-07-08 22:01:10, ParentId=a0B1a00000LlnHpEAJ, OldValue=null, NewValue=INV-0002874639, Field=Name, Id=0171a0000IweE5vAQE}, Invoice__History:{CreatedDate=2018-07-08 22:01:10, ParentId=a0B1a00000LlnHpEAJ, OldValue=null, NewValue=null, Field=created, Id=0171a0000IweE5LAQU})

So, the Invoice was created at 22:00:56, but the history record showing its creation was created at 22:01:10. This threw me off the debugging scent because the field history in another object that caused this invoice to be created shows a change happening at 22:01:10. Which made me think that the change over there couldn't have caused the invoice to be created because it happened after the invoice was created.

The Invoice object has some fairly slow triggers on it, and was being processed in bulk from a scheduled job. So, I could guess that the CreatedDate of Invoice is set at the beginning of before insert and the history records are inserted after all the other triggers and workflows etc. so those processes account for the extra 5 seconds.

The help page on order-of-execution says nothing about this. Does anyone know what the facts are on what the exact CreatedDate is, and when history records are inserted?

0

Here is what the official Salesforce Field History Tracking Documentation has to say about tracking the date and time, when the changes occurred in the database.

In Lightning, you can see gaps in numerical order in the Created Date and ID fields. All tracked changes still are committed and recorded to your audit log. However, the exact time that those changes occur in the database can vary widely and aren't guaranteed to occur within the same millisecond. For example, there can be triggers or updates on a field that increase the commit time, and you can see a gap in time. During that time period, IDs are created in increasing numerical order but can also have gaps for the same reason.

This clearly showcases, that the date and time logged against a Field History Tracking entry could differ from the actual time when the changes were actually made to the data within the database.

I suspect this occurs because of the delay in commit due to multiple subsequent trigger executions within the same context.

  • Excellent, that's exactly the documentation I was looking for! A bit disappointed that I didn't find it myself, but hey-ho! – Aidan Jul 18 '18 at 11:27

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.