Friday, September 22, 2017

Teaching an Old Log Parser New Tricks - FIT sfdx CLI plugin

I've currently got two problems with the prototype FitDX Apex debug log parser I released a couple of weeks ago.

  1. It comes from the FuseIT SFDC Explorer source and is excessively large for what it does. It's got a lot of baggage for features it doesn't currently expose.
  2. To be a native SFDX CLI plugin I need to be working from node.js.

Enter Edge.js and it's quote from "What problems does Edge.js solve?"

Ah, whatever problem you have. If you have this problem, this solves it.

--Scott Hanselman (@shanselman)

As promised, it does what it says on the box and helps solve both problems by connecting the .NET world with node.js - in process.

In my case I've got a .NET library that has many years of work put into it to parse Apex debug logs from a raw string. It's also still actively developed and utilized in the FuseIT SFDC Explorer UI. Between that and my lack of experience with node.js I wasn't in a hurry to rewrite it all so it could be used as a native SFDX CLI plugin. While I still needed to reduce the .NET DLL down to just the required code for log parsing I don't need to rewrite it all in JavaScript. Bonus!

This seems like a good place for a quick acknowledgement to @Amorelandra for pointing me in the right direction with node.js. Thanks again!

With the edge module the node.js code becomes the plumbing to pass off input from the heroku plugins to my happy place (the .NET code). And it is all transparent to the user (assuming the OS specific edge.js requirements are meet). A big bonus being a plugin is that it gives me a prebuilt framework for gathering all the inputs in a consistent way.

I used Wade Wegner's SFDX plugin as a boiler plate for integrating with the cli, chopped most of it out, and kept the command to pull the latest debug log from an org. This debug log is then feed directly into the .NET library to use the existing FuseIT parser.

Enough patting myself of the back for getting this all working. How does it work in practice?

Summary

Like with fitdx, this will give you a count for each event type that appears in the log.

>sfdx fit:apex:log:latest -u <targetusername> --summary
41.0 : 41.0 APEX_CODE,DEBUG;APEX_PROFILING,NONE;CALLOUT,NONE;DB,INFO;SYSTEM,INFO;VALIDATION,INFO;VISUALFORCE,NONE;WAVE,INFO;WORKFLOW,INFO
INFO;WORKFLOW,INFO
CODE_UNIT_FINISHED : 2
CODE_UNIT_STARTED : 11
CUMULATIVE_LIMIT_USAGE : 18
CUMULATIVE_LIMIT_USAGE_END : 18
DML_BEGIN : 22
DML_END : 22
ENTERING_MANAGED_PKG : 768
LIMIT_USAGE_FOR_NS : 54
SOQL_EXECUTE_BEGIN : 25
SOQL_EXECUTE_END : 25
USER_DEBUG : 2
USER_INFO : 1

768 ENTERING_MANAGED_PKG events! Story of my life.

Debug only

>sfdx fit:apex:log:latest -u  --debugOnly
28.0 APEX_CODE,DEBUG;APEX_PROFILING,INFO;CALLOUT,INFO;DB,INFO;SYSTEM,DEBUG;VALIDATION,INFO;VISUALFORCE,INFO;WAVE,INFO;WORKFLOW,INFO
18:56:59.180 (1181147014)|USER_DEBUG|[4]|ERROR|UserInfo.getSessionId(): 00D700000000001!ApexTestSession
18:56:59.416 (1416651819)|USER_DEBUG|[4]|ERROR|UserInfo.getSessionId(): 00D700000000001!ApexTestSession

Filtering

>sfdx fit:apex:log:latest -u  --filter USER_INFO,CODE_UNIT_STARTED
28.0 APEX_CODE,DEBUG;APEX_PROFILING,INFO;CALLOUT,INFO;DB,INFO;SYSTEM,DEBUG;VALIDATION,INFO;VISUALFORCE,INFO;WAVE,INFO;WORKFLOW,INFO
18:56:58.400 (4013418)|USER_INFO|[EXTERNAL]|005700000000001|daniel.ballinger@example.com|Pacific Standard Time|GMT-07:00
18:56:58.979 (979316201)|CODE_UNIT_STARTED|[EXTERNAL]|01q70000000HFV6|DFB.TestAccountBeforeUpdate1 on Account trigger event BeforeInsert for [new]
18:56:58.982 (982430091)|CODE_UNIT_STARTED|[EXTERNAL]|01q70000000HFVB|DFB.TestAccountBeforeUpdate2 on Account trigger event BeforeInsert for [new]
18:56:58.985 (985467868)|CODE_UNIT_STARTED|[EXTERNAL]|01q70000000blnO|DFB.AccountTrigger on Account trigger event BeforeInsert for [new]
18:56:59.108 (1108633716)|CODE_UNIT_STARTED|[EXTERNAL]|01q70000000Ti5b|DFB.ToolingTest on Account trigger event BeforeUpdate for [0010g00001YxxQ5]
18:56:59.180 (1180950117)|CODE_UNIT_STARTED|[EXTERNAL]|01q70000000H1vs|DFB.RestrictContactByName on Contact trigger event BeforeInsert for [new]

Format Shifting

>sfdx fit:apex:log:latest -u  --json
>sfdx fit:apex:log:latest -u  --csv
>sfdx fit:apex:log:latest -u  --human

The first two should still be fairly self explanatory and the latter is still intended to make reading the log easier for those that run on digesting food rather than electricity.

Installation

Most of the steps are covered in the Github repo. I found the most challenging part here to be piggybacking off the existing install of node.js and npm that lives under sfdx.

Your results may vary. It is likely safer to install your own instance of node.js. The standard disclaimer applies.

One more thing