Update logger to work with progress bar

[tlylt]

What is the purpose of this pull request?

• Documentation update
• Bug fix
• Feature addition or enhancement
• Code maintenance
• Others, please explain:

Overview of changes:
Fixes #1723, which is related to the first task of #1633

• Some patching is done to the node-progress package to add helper methods that allow loggers to interrupt the progress bar
• Update the logger packages (winston and winston-daily-rotate-file)
  • some patching is done to ensure that error stack trace is properly printed out
• Adjustments were made to preserve the CLI output, with the exception that the new version of winston prepends 3 white space characters before the message, hence the gap between the level label and the message is slightly wider:
  • before
  • 
  • after
  • 

Anything you'd like to highlight / discuss:

Irrelevant observation: In the core package's package-lock.json, the version of core is still 3.0.6. Actually not sure if this lock file needs to exist at all...
(resolved)

Testing instructions:

• checkout the PR
• npm run setup to update the dependencies
• run markbind serve/markbind build to verify the CLI output
• also check the _markbind/logs to see the content of .log files

Can consider running npm run test, which will have quite a bit of console logging that is resulted from running all the functional tests, hence can observe the console behavior.

Proposed commit message: (wrap lines at 72 characters)
Update logger to work with progress bar

When the page build task is ongoing, the progress bar
shown is interrupted unexpectedly by warnings or error
logs, which will be written to the console without any
preceding linebreak.

Let's patch the node-progress package to signal the
start and the end of a proper interruption, and have
the loggers invoke these methods before and after
logging. Let's also upgrade the logger dependencies.

When the progress bar is running, the loggers will
call the relevant method to clear off the current bar
before logging and redraws the progress bar afterward.

---

Checklist: ☑️

• Updated the documentation for feature additions and enhancements
• Added tests for bug fixes or features
• Linked all related issues
• No unrelated changes

[jonahtanjz]

Thanks @tlylt!

Just a quick question, does this resolve #1723?

[jonahtanjz]

In the core package's package-lock.json, the version of core is still 3.0.6. Actually not sure if this lock file needs to exist at all...

Yup this package-lock.json is not being used. Can be removed in another PR #1873 (comment)

[tlylt]

Thanks @tlylt!

Just a quick question, does this resolve #1723?

Hi @jonahtanjz, nope it doesn't. I made this PR while attempting to resolve 1723 but I am facing a bit of a complication with how to properly interrupt the progress bar when logger.info/warn etc are called. Ideally when the progress bar is running, updates to the console can utilize the node-progress's interrupt method (which first removes the drawn progress bar, reset the cursor, log the output, then redraws the previously recorded progress bar) such that the progress bar will always remain at the bottom. But I am not too sure how to wrap that correctly into winston yet 😅 so thought to at least bump the relevant dependencies as a first step.

Yup this package-lock.json is not being used. Can be removed in another PR

Sure I will make a quite PR to fix this.

[jonahtanjz]

so thought to at least bump the relevant dependencies as a first step.

Alright in that case LGTM 👍

[tlylt]

Updated this PR as I discovered that the error stack trace disappeared after upgrading Winston.
I have:

• patched the above
• also fixed the progress bar interrupt issue

[jonahtanjz]

Thanks for working on this @tlylt!

Mostly looks good. The warnings are now on separate lines 👍 However, I found an edge case which still causes the line break issue (this time with the site data built log).

To replicate this issue:

1. Create a .mbd extension file and include it in the site.json
2. Serve the site
3. Error should show up and no linebreak after progress bar

Will also need to account for this case as similar errors may lead to this issue as well.

Log file if you need it for reference:
markbind-2022-04-19.log

Some updates to be done and hence re-approval required

[ryoarmanda]

Heads up, core/utils/logger.js has just been migrated to TypeScript, you would need to sync with master so that the changes are to the .ts file instead.

[tlylt]

Hi @jonahtanjz

To give a bit of an update:

• I have reverted the winston version upgrade because of the extra monkey patching required with the newer version, and somehow it is not working well with printing out the error stack trace (especially when not using JSON format)
• For the case of .mbd error, the current code is able to output the error logs but the progress bar will be shown at the very end instead (as it prevents itself from being disturbed by the "Build Success" statements).
  (for serve)
  
  (for build)
  

I'm not sure how to make this solution better at the moment... as I am facing some complications finding out how to update the progress bar in src/Site/index.js, because of the async processes and the error handling code (i.e how to appropriately remove the progressbar wrapping when encountering an error, or if there are other ways to address the root problem). Any suggestions/thoughts?

[jonahtanjz]

Thanks for updating @tlylt

Any suggestions/thoughts?

I'll need some time to look into this. In the meantime, I am fine with the current implementation of placing the progress bar at the end :)

[jonahtanjz]

It seems that the issue with this is that the progressBar does not terminate after encountering an error when generating pages. The terminate method in node-progress.js should write a newline to the end. However, the terminate method will only be called if all the pages are generated successfully as seen here.

One workaround that we can do is to introduce another counter in node-progress to keep track of all the pages that have been processed (those that have successfully generated + those that have failed). Then, terminate the progress bar when this counter is more than the total number of pages.

I've come up with some rough/draft code that I think resolves this issue (tlylt#4). Feel free to take a look at it :)

After:

[tlylt]

Hi @jonahtanjz, I tried the changes in your PR to my branch. If I do comment out the infoWrap, the last newline is not working:

May I double-check if you have any additional changes that are not pushed to the PR?

[jonahtanjz]

May I double-check if you have any additional changes that are not pushed to the PR?

Nope I did not make any other changes. I realised this issue reappears if there are more pages to generate. The page generation will take in a maximum of 4 pages to generate concurrently, as a result, if any of the pages fails, the promise will get rejected and the other pages will not be generated. This causes the count within the node-progress to still be less than the total, which will cause the issue of not terminating again.

For the case of .mbd error, the current code is able to output the error logs but the progress bar will be shown at the very end instead (as it prevents itself from being disturbed by the "Build Success" statements).

Let's go with this then in view of the above issue.

[jonahtanjz]

Thanks @tlylt for the workaround :)

LGTM 👍