2

I am just wondering how apex replay debugger works with just a log file. It seems the log does not necessarily provide all the variable states in the log file.

I have written a code in the developer console

try
{
    System.Debug('1');
    Integer i = 0;
    System.Debug('2');
    Integer j = 0/100;
    System.Debug('3');
}
catch(Exception ex)
{
    System.Debug('4');
    LogException e = new LogException();
    System.Debug('5');
    e.Module('Annonymous').log(ex);
    System.Debug('6');
}

[LogException is a class I have written to write the exception in a custom object, link here]

The code above generates the below log file

47.0 APEX_CODE,FINEST;APEX_PROFILING,FINEST;CALLOUT,FINEST;DB,FINEST;NBA,INFO;SYSTEM,DEBUG;VALIDATION,INFO;VISUALFORCE,FINER;WAVE,INFO;WORKFLOW,INFO
Execute Anonymous: try
Execute Anonymous: {
Execute Anonymous:     System.Debug('1');
Execute Anonymous:  Integer i = 0;
Execute Anonymous:     System.Debug('2');
Execute Anonymous:  Integer j = 0/100;
Execute Anonymous:     System.Debug('3');
Execute Anonymous: }
Execute Anonymous: catch(Exception ex)
Execute Anonymous: {
Execute Anonymous:     System.Debug('4');
Execute Anonymous:     LogException e = new LogException();
Execute Anonymous:     System.Debug('5');
Execute Anonymous:     e.Module('Annonymous').log(ex);
Execute Anonymous:     System.Debug('6');
Execute Anonymous: }
Execute Anonymous:     
Execute Anonymous:     
04:21:47.1 (1748638)|USER_INFO|[EXTERNAL]|0057F000000kScH|[email protected]|(GMT-08:00) Pacific Standard Time (America/Los_Angeles)|GMT-08:00
04:21:47.1 (1803063)|EXECUTION_STARTED
04:21:47.1 (1818307)|CODE_UNIT_STARTED|[EXTERNAL]|execute_anonymous_apex
04:21:47.1 (2100696)|HEAP_ALLOCATE|[79]|Bytes:3
04:21:47.1 (2164440)|HEAP_ALLOCATE|[84]|Bytes:152
04:21:47.1 (2184536)|HEAP_ALLOCATE|[399]|Bytes:408
04:21:47.1 (2201691)|HEAP_ALLOCATE|[412]|Bytes:408
04:21:47.1 (2213887)|HEAP_ALLOCATE|[520]|Bytes:48
04:21:47.1 (2240294)|HEAP_ALLOCATE|[139]|Bytes:6
04:21:47.1 (2288249)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:29
04:21:47.1 (2419449)|STATEMENT_EXECUTE|[1]
04:21:47.1 (2423312)|STATEMENT_EXECUTE|[1]
04:21:47.1 (2424934)|STATEMENT_EXECUTE|[2]
04:21:47.1 (2426374)|STATEMENT_EXECUTE|[3]
04:21:47.1 (2429377)|HEAP_ALLOCATE|[3]|Bytes:1
04:21:47.1 (2463363)|HEAP_ALLOCATE|[52]|Bytes:5
04:21:47.1 (2497995)|HEAP_ALLOCATE|[58]|Bytes:5
04:21:47.1 (2506928)|HEAP_ALLOCATE|[66]|Bytes:7
04:21:47.1 (2594382)|USER_DEBUG|[3]|DEBUG|1
04:21:47.1 (2613308)|STATEMENT_EXECUTE|[4]
04:21:47.1 (2624219)|VARIABLE_SCOPE_BEGIN|[4]|i|Integer|false|false
04:21:47.1 (2634759)|HEAP_ALLOCATE|[4]|Bytes:4
04:21:47.1 (2678061)|VARIABLE_ASSIGNMENT|[4]|i|0
04:21:47.1 (2693433)|STATEMENT_EXECUTE|[5]
04:21:47.1 (2696139)|HEAP_ALLOCATE|[5]|Bytes:1
04:21:47.1 (2712572)|USER_DEBUG|[5]|DEBUG|2
04:21:47.1 (2720928)|STATEMENT_EXECUTE|[6]
04:21:47.1 (2725272)|VARIABLE_SCOPE_BEGIN|[6]|j|Integer|false|false
04:21:47.1 (2732949)|HEAP_ALLOCATE|[6]|Bytes:4
04:21:47.1 (2739792)|VARIABLE_ASSIGNMENT|[6]|j|0
04:21:47.1 (2745245)|STATEMENT_EXECUTE|[7]
04:21:47.1 (2747500)|HEAP_ALLOCATE|[7]|Bytes:1
04:21:47.1 (2759179)|USER_DEBUG|[7]|DEBUG|3
04:21:47.2 (2826861)|CUMULATIVE_LIMIT_USAGE
04:21:47.2 (2826861)|LIMIT_USAGE_FOR_NS|(default)|
  Number of SOQL queries: 0 out of 100
  Number of query rows: 0 out of 50000
  Number of SOSL queries: 0 out of 20
  Number of DML statements: 0 out of 150
  Number of DML rows: 0 out of 10000
  Maximum CPU time: 0 out of 10000
  Maximum heap size: 0 out of 6000000
  Number of callouts: 0 out of 100
  Number of Email Invocations: 0 out of 10
  Number of future calls: 0 out of 50
  Number of queueable jobs added to the queue: 0 out of 50
  Number of Mobile Apex push calls: 0 out of 10

04:21:47.2 (2826861)|TOTAL_EMAIL_RECIPIENTS_QUEUED|0
04:21:47.2 (2826861)|STATIC_VARIABLE_LIST|
  int:BYTES:0
  int:BYTES:0
  byte[]:DigitOnes:0
  byte[]:DigitTens:0
  Boolean:FALSE:0
  int:MAX_EXPONENT:0
  double:MAX_VALUE:0
  int:MAX_VALUE:0
  int:MIN_EXPONENT:0
  double:MIN_NORMAL:0
  double:MIN_VALUE:0
  int:MIN_VALUE:0
  double:NEGATIVE_INFINITY:0
  double:NaN:0
  double:POSITIVE_INFINITY:0
  int:SIZE:0
  int:SIZE:0
  Boolean:TRUE:0
  String:_sfdcSuppressedCodeLocations:0
  char[]:digits:0
  long:serialVersionUID:0
  long:serialVersionUID:0
  long:serialVersionUID:0
  int[]:sizeTable:0

04:21:47.2 (2826861)|CUMULATIVE_LIMIT_USAGE_END

04:21:47.1 (13812414)|CODE_UNIT_FINISHED|execute_anonymous_apex
04:21:47.1 (16206664)|EXECUTION_FINISHED
04:21:47.17 (17420941)|CUMULATIVE_PROFILING_BEGIN
04:21:47.17 (17420941)|CUMULATIVE_PROFILING|No profiling information for SOQL operations
04:21:47.17 (17420941)|CUMULATIVE_PROFILING|No profiling information for SOSL operations
04:21:47.17 (17420941)|CUMULATIVE_PROFILING|No profiling information for DML operations
04:21:47.17 (17420941)|CUMULATIVE_PROFILING|method invocations|
External entry point: public static void execute(): executed 1 time in 0 ms
AnonymousBlock: line 3, column 1: global public static void debug(ANY): executed 1 time in 0 ms
AnonymousBlock: line 5, column 1: global public static void debug(ANY): executed 1 time in 0 ms
AnonymousBlock: line 7, column 1: global public static void debug(ANY): executed 1 time in 0 ms

04:21:47.17 (17420941)|CUMULATIVE_PROFILING_END

From the log, we can see, the first System.Debug('1') gets hit after some HEAP_ALLOCATE.

enter image description here

Why this heap is allocated?

My whole point is to understand how the replay debugger works in visual studio code with a log file as input?

Improve this question

2 Answers 2

Reset to default
2

The mechanism how apex replay debugger works is described in here in dreamforce 18 session.

To summarize here is how the replay debugger works

1.Developer sets the checkpoints by selecting line numbers where one needs more info of the variable.

These are sent to the server. Salesforce has a tooling api to set checkpoints in the code and store them in the org. Behind scenes a tooling api object ApexExecutionOveralyAction is created

2.Heap Dump is generated using the tooling api has more context and all the information.

3.One fetches the logs (they have proper heap dumps)and then the replay debugger parses of the logs to get the variable values.

Salesforce has open sourced the Vscode extension code so if you know Typescript and Node you can reverse engineer the below packages

https://github.com/forcedotcom/salesforcedx-vscode/tree/develop/packages/salesforcedx-apex-replay-debugger

https://github.com/forcedotcom/salesforcedx-vscode/tree/develop/packages/salesforcedx-vscode-apex-replay-debugger

Improve this answer
1
  • thanks for the info.
    – Noor A Shuvo
    Commented Dec 24, 2019 at 14:50
1

Heap can be allocated by both your code statements and the underlying libraries e.g. the first call to System.debug might allocate some memory that is held in static variables as part of its internal configuration. The more useful information is the values that are calculated and assigned together with the line numbers of the source code involved: that information allows the replay debugger to re-create the steps through the code.

AFAIK the replay debugger does mine all the information it presents from the log file, so what it can and cannot do is limited by that information. The log files become very large too on normal size codebases, so where I work we rarely use it.

Improve this answer
1
  • Thanks for the info. So, I think, a large portion of the log is unnecessary info.
    – Noor A Shuvo
    Commented Dec 24, 2019 at 14:50

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .