Remove debug logging in production environment

[Pessimistress]

Background

Remove logging from @deck.gl/core/lib in production mode.

Change List

• Reorganize core exports
• Build setup
• Upgrade guide

[Pessimistress]

@tsherif Eventually this should be moved to luma repo's dev-modules

[ibgreen]

Why not move it to probe.gl? After all it is complementary to the probe.gl log class...

[Pessimistress]

To test this branch locally:

yarn build
cd modules/core
yarn prepublishOnly

[coveralls]

Coverage increased (+2.4%) to 84.136% when pulling 5c488f9 on x/prod-build into b73b81a on master.

[tsherif]

This is super interesting. I'm wondering if we could generalize this by having a global object (e.g. LUMA_DEV) that was a proxy for all debug functions. Then we would just have one object to look for and remove. But that's a bigger discussion...

Did you see any per improvements with this?

[Pessimistress]

Did you see any per improvements with this?

Most of the logging happens in layer lifecycle and attribute updates. We don't have any stress test that consists of many layer updates, so the impact of this change is minimal.

[ibgreen]

There is the concern (inline) that this might defeat tree-shaking.

A minor thing is that there is a value in being able to always activate certain log statements in production (e.g. at minimum the version of deck.gl, luma.gl context vendor/driver information etc). This has helped us debug user problems on deployed code in very remote locations in the past. For that case maybe probe.gl could offer some log functions that are not affected by this plugin, e.g. log.logProduction()?

Also will just reiterate that from my perspective, I'd prefer that debugging was made optional by moving it into an optional module loadable at run-time from e.g. unpkg.com (the way loaders.gl v2 loads libraries like draco, basis and workers at run-time rather than bundling them into the app).

A way to do that would be to develop the hooks system @tsherif suggested. This may sound like a big step but the attribute management logs are an example of a system that already is handled through a set of hooks. We could simply move the implementation of those hooks into a script that is loaded runtime from unpkg.com. A deck.debug() command in the console could load the script and install logging on a deployed version.

This way we could get the best of both worlds (almost) zero overhead in production, yet the debug code is always available to be loaded when needed, without rebuilding/recompiling/relinking.

If it is not done that way, my fear is that debug functionality will be less useful since it will only be available in certain build configuration, when luma.gl/debug is imported etc, and this will lead to decreased use, and the decreased use lead to less maintenance (and ultimately to debug functionality being removed from the libraries).

[ibgreen]

The conventional wisdowm is that require kills tree shaking as that works on static analysis of export/import...

Recommend validating that this actually leads to smaller apps. My fear is that this will trigger unconditional bundling of lib.prod.

[Pessimistress]

core/lib is almost entirely dependencies of the Deck class (with the exception of LayerExtension which is super light).

This change shaves about 1K off the minified bundle. However, the main concern of including the logging functions is performance, because even when log.log returns noOp we spend CPU cycles building the dynamic message strings.

[ibgreen]

core/lib is almost entirely dependencies of the Deck class (with the exception of LayerExtension which is super light).

You are saying these should always be bundled anyway? Fine, though

1. I recommend calling this out in comments above the require statements (E.g. // 'require' defeats tree shaking but we always bundle these symbols anyway)..

2. When I do this type of setups, they tends to come back and bite me as the library evolves...

However, the main concern of including the logging functions is performance, because even when log.log returns noOp we spend CPU cycles building the dynamic message strings.

Got it. FWIW, to handle this, probe.gl has always allowed for message strings to be supplied as functions that only gets evaluated when the logging actually is enabled, e.g instead of:

log.info(`Dynamic strings generated for ${variableName} every time we execute this`)();

log.info(() => `Don't want dynamic strings generated for ${variableName} when we are not actually logging`)();

In theory, this still mints a function (which should be way faster than building a string, but possibly not zero impact, depends on how the JS engine handles this).

[Pessimistress]

I ran some benchmark tests, it's actually 2-3x more expensive to create those functions inline.

[ibgreen]

Thanks for checking and it only goes to prove that actual profiling beats assumptions every time. (Perhaps it is the captured variable that makes it expensive... but that doesn't matter).

In light of this, I'd consider modifying the various probe.gl log calls to take multiple string segment as parameters and then concat them inside the log functions (only when logging actually happens). That should create no small objects and simple parameter passing is typically extremely fast in modern JS engines.

I opened an issue in probe.gl: uber-web/probe.gl#108.

@Pessimistress Happy to help out with this one if this would be considered helpful to the ongoing optimization push.

[ibgreen]

Why not move it to probe.gl? After all it is complementary to the probe.gl log class...