search

jongpie / NebulaLogger

The most robust observability solution for Salesforce experts. Built 100% natively on the platform, and designed to work seamlessly with Apex, Lightning Components, Flow, Process Builder & integrations.
https://nebulalogger.com
MIT License
709 stars 165 forks source link

Overhauled JavaScript stack trace parsing #727

Closed jongpie closed 3 months ago

jongpie commented 3 months ago

This is a big PR, so here's a lot of context to explain the issues at hand & what's changing.

Context: The current JavaScript stack trace parsing logic is veeeeery broken

Using the c/logger LWC (or Nebula/logger in the managed package), JavaScript developers can adding logging to their own Aura components & LWCs. And much like logging in Apex, when logging in JavaScript, Nebula Logger (tries to) use stack trace parsing to automatically track details about your components, such as the name & function in your component that added a log entry. These details are then stored in fields like LogEntry__c.OriginLocation__c, LogEntry__c.OriginSourceApiName__c, LogEntry__c.OriginSourceActionName__c, etc.

Thanks to some great feedback & contributions from @ZackFra and others, it turns out that there are some big problems with the current approach. This PR fixes several issues related to JavaScript stack trace parsing, including:

This PR will be used in place of PR #692 - after some extensive testing of the current release and changes in #692, I found that there some other related parsing issues with the current release's overall approach, and resolving everything while using the same overall approach/architecture would be fairly challenging. But credit & many thanks to @ZackFra for identifying the critical problems in the current code & how to resolve them. This PR leverages several of the same approaches @ZackFra used in #692.

One outstanding issue not addressed by this PR:

export default class TestLWC extends LightningElement {
  async connectedCallback() {
    this.logger = await createLogger();
    this.logger.info(
      "this entry will have some missing origin details in certain browsers"
    );
  }
}

Old Approach: JS Stack Trace Parsing Occurred in Apex

Previously, JavaScript stack traces were parsed by the Apex classes ComponentLogger and LoggerStackTrace. One thought behind using this approach was doing it in JavaScript would require the user's browser to do more work, so offloading the parsing to Apex (instead of JS) would help minimize any performance impact of using the logger LWC.

But, building the parsing in Apex has the downside of making Nebula Logger the only project in the Salesforce ecosystem (that I'm aware of) that's trying to parse JavaScript stack traces using Apex. I have not been able to find any available projects/libraries/classes to provide this - so it has to be built, and maintained, just for Nebula Logger.

Before realizing the number of variations possible in JS stack traces, using Apex still seemed reasonable. But based on some of the info found by @ZackFra in issue #691 and PR #692, I did some extensive testing (some of which is detailed in this comment), using a combination of:

Improved Recipes Metadata: Testing These Issues Was Too Difficult

It took a lot of effort to even be able to test these scenarios/permutations, as Nebula Logger's repo didn't have sample metadata setup for most of these scenarios.

Previously, I was really only testing the recipes demo components via custom tabs / the target lightning__Tab. And when testing that target, in Firefox (my preferred browser), the stack trace parsing (built in Apex) worked. But in several other contexts, and in almost every other browser, the stack trace parsing logic resulted in inaccurate or missing data.

This led to me spending some time focusing on just making it easy for me to be able test logging in different targets, using multiple browsers. This includes:

Now, the recipes app is setup to quickly test the 3 demo components in multiple targets

image

New Approach: JS Stack Trace Parsing Now Occurs in JS

Once I was able to test JS logging in multiple targets & browsers, I was able to see some huge/critical differences in the stack traces generated in several scenarios. This led to 2 decisions:

  1. The complexity of trying to fix the Apex approach quickly grew: @ZackFra introduced in PR #692 some changes that improved the Apex code that parses JS stack traces (and fixed the parsing in several situations). But for some situations/browsers still did not work correctly, so I spent some trying extend the logic to cover more scenarios. The complexity of this quickly escalated.

  2. When parsing the JS stack trace in Apex, there wasn't a great way to show any of the parsed stack trace's data in JS. Ideally, I want JS logging to be able to show some useful summary in console.log() statements (when enabled) to help developers better debug their components. But to do this, the frontend would need to have the parsed stack trace data. This has always been an issue with using Apex to (async) parse the JS stack traces

As a result, I looked into options for parsing stack traces directly in JavaScript, with 2 hopes/goals in mind:

  1. I really don't want to have to build/maintain an Apex implementation that accommodates JS stack traces across all browsers. It seems hard to maintain 😅
  2. I want to improve the output shown in console.log() statements to provide Salesforce developers with more context.

Eventually, I came across the open source library JavaScript library stacktrace.js. It provides cross-browser stack trace parsing, directly in JavaScript. After prototyping this out for several days, it seems to provide (with a few tweaks) accurate stack trace parsing for all of the permutations of browsers + Salesforce targets + methods of calling the logger LWC.

This PR incorporates a modified version of its stack trace parsing code - all of the Apex code that previously handled JS stack traces has now be removed (with a few lingering items that are deprecated & will be removed in a future release).

Improved the Output of console.log() Statements

Lastly, since JS stack trace parsing now happens directly in JS, this makes it easier to provide some helpful context to the console.log() statements that Nebula Logger automatically executes.

Old Approach

In previous versions, Nebula Logger would automatically include the JS object representation of a component log entry every time it auto-calls a console log function. This is/was done to try to make it easy for JavaScript developers to see some logging context directly in their browser when debugging.

But due to how locker service/locker web security (LWC) work, the object was always shown as a Proxy object

image

To then actually see the object's data, JS developers would have to store the Proxy as a variable in their browser's dev console, and then run JSON.parse(JSON.stringify(theProxyObject)). So although the data was available in the browser, it was very tedious to actually leverage the data.

I also tried printing the Proxy object, using JSON.stringify(theProxyObject) - but because it contained the original, unparsed stack trace (and not a parsed version of it), the printed string was huuuuuge, and it was still very difficult to quickly see the relevant lines from the stack trace.

New Approach

With JS stack trace parsing now happening in the browser, each JS logging statement now includes a pretty-printed JSON string that includes the most relevant info about the log entry's origin:

Now developers can see at a glance the relevant info about their component that logged something.

Console output in Chrome:

image

Console output in Firefox:

image

Console output in Microsoft Edge:

image

jongpie commented 3 months ago

Thanks @jamessimone for reviewing! I'm going to merge this ASAP, then try to finally merge PR #700 this week 🥳

jamessimone commented 3 months ago

Awesome! Nice work

codecov[bot] commented 3 months ago

Codecov Report

Attention: Patch coverage is 97.50000% with 1 line in your changes missing coverage. Please review.

Project coverage is 95.39%. Comparing base (91f2eb2) to head (aca9a06).

Files Patch % Lines
...ore/main/logger-engine/classes/ComponentLogger.cls 97.43% 1 Missing :warning:
Additional details and impacted files ```diff @@ Coverage Diff @@ ## main #727 +/- ## ========================================== - Coverage 95.52% 95.39% -0.13% ========================================== Files 51 51 Lines 5695 5645 -50 ========================================== - Hits 5440 5385 -55 - Misses 255 260 +5 ``` | [Flag](https://app.codecov.io/gh/jongpie/NebulaLogger/pull/727/flags?src=pr&el=flags&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Jonathan+Gillespie) | Coverage Δ | | |---|---|---| | [Apex](https://app.codecov.io/gh/jongpie/NebulaLogger/pull/727/flags?src=pr&el=flag&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Jonathan+Gillespie) | `95.39% <97.50%> (-0.13%)` | :arrow_down: | Flags with carried forward coverage won't be shown. [Click here](https://docs.codecov.io/docs/carryforward-flags?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Jonathan+Gillespie#carryforward-flags-in-the-pull-request-comment) to find out more.

:umbrella: View full report in Codecov by Sentry.
:loudspeaker: Have feedback on the report? Share it here.