DX enhancements - quieter logging on startup and polling, clickable URL in console #1372

agorskiy12 · 2024-04-08T20:50:27Z

Description

when running one-app in node.env = 'development'

logging is cleaner on startup
hiding messages about bundle sizes unless they are critical
hiding messages about what ports the app is launching on
hiding messages about module map polling, unless something goes wrong
offer a clickable URL to the UI project in the command line

Motivation and Context

GitHub discussion about DX enhancements

How Has This Been Tested?

unit test

Types of Changes

Bug fix (non-breaking change which fixes an issue)
New feature (non-breaking change which adds functionality)
Breaking change (fix or feature that would cause existing functionality to not work as expected)
Documentation (adding or updating documentation)
Dependency update
Security update

Checklist:

My change requires a change to the documentation and I have updated the documentation accordingly.
These changes should be applied to a maintenance branch.
This change requires cross browser checks.
Performance tests should be ran against the server prior to merging.
This change impacts caching for client browsers.
This change impacts HTTP headers.
This change adds additional environment variable requirements for One App users.
I have added the Apache 2.0 license header to any new files created.

What is the Impact to Developers Using One App?

they will see less logging in development

github-actions · 2024-04-08T20:52:50Z

Size Change: 0 B

Total Size: 232 kB

ℹ️ View Unchanged

Filename	Size
`./build/app/app.js`	38.2 kB
`./build/app/app~vendors.js`	129 kB
`./build/app/runtime.js`	5.64 kB
`./build/app/service-worker-client.js`	5.46 kB
`./build/app/vendors.js`	54.1 kB

_{compressed-size-action}

10xLaCroixDrinker · 2024-04-08T21:55:24Z

src/server/utils/cdnCache.js

+    console.info(chalk.bold.cyanBright('CACHE INFORMATION'));
+    console.info(message);
+    console.info('To clear the cache, please delete this file:');
+    console.info(`    ${chalk.bold.cyanBright(path.join('~', oneAppDirectoryName, cacheFileName))}`);


Can you replace the template literal with string interpolation? Doing so helps with performance in cases where the log is dropped and does not have to be evaluated. (Same applies to message a couple lines above)

do you mean replace with string concatenation?

Like:

console.info('one-app-dev-cdn loading module map from %s', remoteModuleMapUrl);

What if we just put this as a single line
"one-app module cache size 30mb. To clear, delete file"

I dont think the separator, title and all are necessary

I agree with Matt, we could eliminate a lot of this.

10xLaCroixDrinker · 2024-04-08T21:57:30Z

src/server/utils/cdnCache.js

@@ -26,15 +26,18 @@ export const oneAppModuleCachePath = path.join(oneAppDirectoryPath, cacheFileNam
 export const showCacheInfo = async () => {
  try {
    const stats = await fsPromises.stat(oneAppModuleCachePath);
+    if (stats.size > 1024 * 1024 * 10) {
+      console.warn(chalk.bold.redBright('🚨🚨🚨: Cache file size is more than 10MB. 🚨🚨🚨'));


Isn't this pretty common for large tenancies?

Yah I don't think this warning is necessary, or should be up at 300mb

i guess ill just delete it.

Yeah, I'm not sure there is any cache purge either so even a small tenancy will eventually hit the limit.

@smackfu the cache only keeps one copy of any file for a module. It doesn't not keep multiple versions. So if you only work on one tenancy, your cache size is pretty 'stable' because new versions of your modules replace old versions

FYI further discussion with @code-forger revealed there is a bug in the caching deduplication for locale files, which is why I was seeing duplicate entries for the same module.

PixnBits · 2024-04-10T17:26:39Z

src/server/utils/pollModuleMap.js

-    console.log('pollModuleMap: polling...');
+    console.info('pollModuleMap: polling...');


lots of log level changes
how does this affect the log entries in production? are there some side effects we and users should be aware of? are they breaking? (e.g. searching through logs)

Info is the default log level in production

src/server/utils/cdnCache.js

10xLaCroixDrinker · 2024-04-10T22:56:08Z

src/server/index.js

-    console.log('%s listening on port %d', context, port);
+    console.info('%s listening on port %d', context, port);
+    if (context === '🌎 One App server') {
+      console.log('🚀 One App Server is running on http://localhost:%d 🚀', port);


This URL is only accurate in development, but will be logged in production

I think we should actually add a new log level for cases like this. console.dev

It would require a change here:

https://github.com/americanexpress/one-app/blob/main/src/server/utils/logging/config/base.js#L22-L24
and here

https://github.com/americanexpress/one-app/blob/main/src/server/utils/logging/monkeyPatchConsole.js#L19

customLevels: { dev: process.env.NODE_ENV === 'development' ? 34 : 0, log: 35, },

This would allow us to have logs that are only for development, but not debugging, without carrying around this condition

(edit: pasted the wrong link earlier)

For reference in the above, console.info is 30 and console.warn is 40

i like the idea but i would use a native one like info

@giulianok that kind of defeats the purpose of the level. the existing log levels (trace, debug, info, log, warn, error, fatal) all have practical cases in both development and productions. these would strictly be for development.

If the point is about using console though, @PixnBits also pointed out and I agreed we should replace out use of console[method] with importing the logger and using logger[method]. IIRC everything left in src that uses console[method] is outside the fastify context. Anything within that context should be using fastify.log[method] or req.log[method] (if in the context of a request)

dogpatch626 · 2024-04-11T16:39:22Z

src/server/utils/cdnCache.js

-    console.log(chalk.bold.cyanBright(separator));
+    const fileSizeInMB = stats.size / (1024 * 1024); // bytes to mb
+    const cachePath = path.join('~', oneAppDirectoryName, cacheFileName);
+    console.info('Local module cache size is %sMB. To clear the cache, delete %s', fileSizeInMB.toFixed(2), cachePath);


should this be info? I feel like as this is a development only addition it makes sense to keep this logged out during the beginning especially as it is only logged once.

Generally, the cache should be 'invisible' to the user, most build / run systems have caches in dev mode. You dont see yarn, lerna, webpack, or esbuild tell you how big there cache is every run.

However, if there is some odd behaviour, and we ask the user to run one-app at a higher logging level, this log is useful. Therefore it should be at info level

this one could be a good candidate for the new logger.dev logging method

src/server/index.js

…one-app into feat/dx-logging

10xLaCroixDrinker · 2024-04-15T15:00:07Z

src/server/utils/logging/config/base.js

    log: 35,
+    dev: 36,


Suggested change

log: 35,

dev: 36,

log: 35,

dev: process.env.NODE_ENV === 'development' ? 36 : 0,

10xLaCroixDrinker · 2024-04-15T15:02:18Z

src/server/utils/logging/config/development.js

    warn: 40,
    error: 50,
    fatal: 60,
  },
-  customColors: 'trace:white,debug:green,info:gray,log:blue,warn:yellow,error:red,fatal:bgRed',
+  customColors: 'trace:white,debug:green,info:gray,log:blue,dev:green,warn:yellow,error:red,fatal:bgRed',


Is there a color we can use that we're not already using?

Maybe we should use magenta.

i like magenta. but where do I find the list of accepted colors? I was trying with "orange" or "purple" but those didnt work

10xLaCroixDrinker · 2024-04-15T15:03:23Z

src/server/utils/logging/config/production.js

@@ -46,6 +46,7 @@ export default {
        warn: 'warning',
        log: 'notice',
        info: 'info',
+        dev: 'dev',


Suggested change

dev: 'dev',

This is a production config, so the logs shouldn't get here.

10xLaCroixDrinker · 2024-04-15T15:05:40Z

src/server/index.js

@@ -57,7 +58,10 @@ export const listen = async ({
      port,
    });

-    console.log('%s listening on port %d', context, port);
+    console.info('%s listening on port %d', context, port);


Suggested change

console.info('%s listening on port %d', context, port);

logger.info('%s listening on port %d', context, port);

All instances of console should be replaced with logger, not just when using logger.dev. Unless you come across one that's within the Fastify context, then fastify.log, likewise request.log when in the request context.

10xLaCroixDrinker · 2024-04-15T15:06:08Z

src/server/utils/cdnCache.js

-    console.log(chalk.bold.cyanBright(separator));
+    const fileSizeInMB = stats.size / (1024 * 1024); // bytes to mb
+    const cachePath = path.join('~', oneAppDirectoryName, cacheFileName);
+    console.info('Local module cache size is %sMB. To clear the cache, delete %s', fileSizeInMB.toFixed(2), cachePath);


10xLaCroixDrinker · 2024-04-17T19:16:16Z

src/server/utils/cdnCache.js

-    console.log(chalk.bold.cyanBright(separator));
+    const fileSizeInMB = stats.size / (1024 * 1024); // bytes to mb
+    const cachePath = path.join('~', oneAppDirectoryName, cacheFileName);
+    logger.dev('Local module cache size is %sMB. To clear the cache, delete %s', fileSizeInMB.toFixed(2), cachePath);
  } catch (error) {
    console.error('There was error checking file stat', error);


Don't forget to changes the other instances of console to logger

feat(logging): dx logging cleanup

7bb8db1

agorskiy12 requested review from a team as code owners April 8, 2024 20:50

github-actions bot added Feature one-app-team-review-requested labels Apr 8, 2024

10xLaCroixDrinker suggested changes Apr 8, 2024

View reviewed changes

agorskiy12 added 2 commits April 9, 2024 18:39

feat(logging): addressing PR comments

338d1b8

feat(logging): addressing PR comments

ec51f20

PixnBits reviewed Apr 10, 2024

View reviewed changes

PixnBits mentioned this pull request Apr 10, 2024

Fix: watch local modules other bundles #1370

Closed

14 tasks

agorskiy12 requested a review from 10xLaCroixDrinker April 10, 2024 21:50

10xLaCroixDrinker suggested changes Apr 10, 2024

View reviewed changes

feat(logging): addressing PR comments, again

6ebe800

agorskiy12 force-pushed the feat/dx-logging branch from f820eff to 6ebe800 Compare April 11, 2024 15:52

Merge branch 'main' into feat/dx-logging

cc45394

agorskiy12 requested a review from 10xLaCroixDrinker April 11, 2024 16:03

dogpatch626 previously approved these changes Apr 11, 2024

View reviewed changes

giulianok reviewed Apr 11, 2024

View reviewed changes

src/server/index.js Show resolved Hide resolved

agorskiy12 added 2 commits April 11, 2024 18:56

feat(logging): logger.dev - part 1

b372304

Merge branch 'feat/dx-logging' of https://github.com/americanexpress/…

bc03f3a

…one-app into feat/dx-logging

agorskiy12 dismissed dogpatch626’s stale review via bc03f3a April 11, 2024 22:59

agorskiy12 marked this pull request as draft April 11, 2024 23:09

agorskiy12 added 2 commits April 15, 2024 09:11

feat(logging): add custom color to logger.dev method

487a76f

Merge branch 'main' into feat/dx-logging

3579498

10xLaCroixDrinker suggested changes Apr 15, 2024

View reviewed changes

agorskiy12 added 4 commits April 16, 2024 09:42

feat(logging): small fixes

a6182e7

feat(logging): addressing pr comments

4f2c170

feat(logging): updating argv, default log level

4225510

feat(logging): updating tests

fb8adfd

feat(logging): updating tests

3f446f7

10xLaCroixDrinker reviewed Apr 17, 2024

View reviewed changes

agorskiy12 added 6 commits April 19, 2024 12:05

feat(logging): wip

2cae0f7

feat(logging): normalizing

1769f66

feat(logging): normalizing p2

73840ed

Merge branch 'main' into feat/dx-logging

65c088f

feat(logging): cleanup to make intermediary PR

aad1ec1

feat(logging): updating so it passes tests

3fcc5c2

10xLaCroixDrinker closed this May 3, 2024

10xLaCroixDrinker deleted the feat/dx-logging branch May 3, 2024 20:01

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

DX enhancements - quieter logging on startup and polling, clickable URL in console #1372

DX enhancements - quieter logging on startup and polling, clickable URL in console #1372

agorskiy12 commented Apr 8, 2024 •

edited

Loading

github-actions bot commented Apr 8, 2024 •

edited

Loading

10xLaCroixDrinker Apr 8, 2024

agorskiy12 Apr 9, 2024

smackfu Apr 9, 2024

Matthew-Mallimo Apr 9, 2024

10xLaCroixDrinker Apr 10, 2024

10xLaCroixDrinker Apr 8, 2024

code-forger Apr 9, 2024

agorskiy12 Apr 9, 2024

smackfu Apr 9, 2024 •

edited

Loading

code-forger Apr 10, 2024

smackfu Apr 10, 2024

PixnBits Apr 10, 2024

10xLaCroixDrinker Apr 10, 2024

10xLaCroixDrinker Apr 10, 2024

10xLaCroixDrinker Apr 11, 2024 •

edited

Loading

10xLaCroixDrinker Apr 11, 2024

giulianok Apr 11, 2024

10xLaCroixDrinker Apr 11, 2024

dogpatch626 Apr 11, 2024

code-forger Apr 12, 2024 •

edited

Loading

agorskiy12 Apr 15, 2024

10xLaCroixDrinker Apr 15, 2024

10xLaCroixDrinker Apr 15, 2024 •

edited

Loading

10xLaCroixDrinker Apr 15, 2024

agorskiy12 Apr 17, 2024

10xLaCroixDrinker Apr 15, 2024

10xLaCroixDrinker Apr 15, 2024

10xLaCroixDrinker Apr 15, 2024

10xLaCroixDrinker Apr 17, 2024

		console.log('pollModuleMap: polling...');
		console.info('pollModuleMap: polling...');

	console.info('%s listening on port %d', context, port);
	logger.info('%s listening on port %d', context, port);

DX enhancements - quieter logging on startup and polling, clickable URL in console #1372

DX enhancements - quieter logging on startup and polling, clickable URL in console #1372

Conversation

agorskiy12 commented Apr 8, 2024 • edited Loading

Description

Motivation and Context

How Has This Been Tested?

Types of Changes

Checklist:

What is the Impact to Developers Using One App?

github-actions bot commented Apr 8, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

smackfu Apr 9, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

10xLaCroixDrinker Apr 11, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

code-forger Apr 12, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

10xLaCroixDrinker Apr 15, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

agorskiy12 commented Apr 8, 2024 •

edited

Loading

github-actions bot commented Apr 8, 2024 •

edited

Loading

smackfu Apr 9, 2024 •

edited

Loading

10xLaCroixDrinker Apr 11, 2024 •

edited

Loading

code-forger Apr 12, 2024 •

edited

Loading

10xLaCroixDrinker Apr 15, 2024 •

edited

Loading