Logger output is overwritten by failure message

[canadaduane]

🐛 bug report

While writing a plugin, I used the Transformer's logger to log some debug info (part of diagnosing another issue). Unfortunately, if the transformation step fails for another reason (e.g. "@parcel/packager-js: Asset has no content") the debug info I sent is overwritten and can't be reviewed.

In other words: while the Transformer is transforming, I can see my debug output, but as soon as the whole process fails, the debug output is erased on the terminal and overwritten with a "failure" message (in this case, an UnhandledPromiseRejectionWarning).

🤔 Expected Behavior

Logger output should be preserved, even if there is a catastrophic failure during the transformation step.

😯 Current Behavior

During the build process, if I ctrl-C before the final error, I can see the error messages in the logs:

yarn build
yarn run v1.21.1
warning package.json: No license field
$ parcel build --log-level verbose index.html
parcel-transformer-svelte: DEBUG OUTPUT HERE
🚨 Build failed.

(note "DEBUG OUTPUT HERE")

But if I allow it to continue to the end, the "DEBUG OUTPUT HERE" disappears:

yarn run v1.21.1
warning package.json: No license field
$ parcel build --log-level verbose index.html
🚨 Build failed.
@parcel/packager-js: Asset has no content
Error: Asset has no content
    at CommittedAsset.getContent (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/core/lib/CommittedAsset.js:59:15)
    at CommittedAsset.getCode (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/core/lib/CommittedAsset.js:67:30)
    at Asset.getCode (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/core/lib/public/Asset.js:145:48)
    at processAsset (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/scope-hoisting/lib/concat.js:137:28)
    at queue.add (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/scope-hoisting/lib/concat.js:67:25)
    at _queue.push (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:45:30)
    at PromiseQueue._runFn (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:98:13)
    at PromiseQueue._next (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:85:16)
    at PromiseQueue.run (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:76:12)
    at concat (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/scope-hoisting/lib/concat.js:70:38)
console: (node:46873) UnhandledPromiseRejectionWarning: Error: Asset has no content
    at CommittedAsset.getContent (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/core/lib/CommittedAsset.js:59:15)
    at CommittedAsset.getCode (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/core/lib/CommittedAsset.js:67:30)
    at Asset.getCode (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/core/lib/public/Asset.js:145:48)
    at processAsset (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/scope-hoisting/lib/concat.js:137:28)
    at queue.add (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/scope-hoisting/lib/concat.js:67:25)
    at _queue.push (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:45:30)
    at PromiseQueue._runFn (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:98:13)
    at PromiseQueue._next (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:85:16)
    at PromiseQueue.run (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/utils/lib/PromiseQueue.js:76:12)
    at concat (/Users/duane/tmp/svelte-parcel-duplicate-styles/node_modules/@parcel/scope-hoisting/lib/concat.js:70:38)

💁 Possible Solution

Since I can't use console.log and related tools for debug output, it's important that the logger output not be erased in the terminal. Actually, I wonder if part of the problem is that the logger output is being overwritten by STDOUT from console.log due to an error not "inside" the parcel logger ecosystem?

🔦 Context

I just need a way to get some debug output into the console while developing a plugin.

💻 Code Sample

Creating a postProcess that returns undefined can replicate this issue:

  async postProcess({ assets, logger }) {
    logger.warn({ message: JSON.stringify(["postProcess assets", assets]) });
    // note: no return statement here!
  },

🌍 Your Environment

Software	Version(s)
Parcel	2.0.0-beta.1
Node	v10.21.0
npm/Yarn	yarn 1.21.1
Operating System	Mac OS 10.14.6

[zachbryant]

Bump, still seeing this in the nightly builds. This is currently making it impossible to debug my plugin. The docs for developing are slim enough, I need to see output to continue 🤦

[AndrewKvalheim]

To work around this it's sufficient to disrupt process.stdout.isTTY:

parcel build |& cat

[zachbryant]

To work around this it's sufficient to disrupt process.stdout.isTTY:

parcel build |& cat

Thank you for the tip!

[mischnic]

I think this is caused by

parcel/packages/reporters/cli/src/CLIReporter.js

Line 120 in eabbbec

resetWindow();

For watch mode, it should probably be cleared, but I guess not for one-shot builds.

[zachbryant]

I've stopped seeing the issue as of 2.0.0-nightly.614

[jcalfee]

I see this issue just running parcel without the build. Additionally, I'm not sure if this is parcel or not, after some error shows up and is cleared, I often find my node_modules directory empty and package.json file overwritten with {}.

[jcalfee]

Not working too well for me:

$ parcel  |& cat
Server running at http://localhost:1234
Building...
Installing buffer...
[Error: ENOENT: no such file or directory, open 'rjsf/node_modules/deepcopy/src/buffer.mjs'] {
  errno: -2,
  code: 'ENOENT',
  syscall: 'open',
  path: 'rjsf/node_modules/deepcopy/src/buffer.mjs'
}
🚨 Build failed.

unknown: Could not find entry: /home/user/rjsf

Parcel is shutting down...
Parcel is shutting down...
user@os:~/rjsf$ ^C
user@os:~/rjsf$ cat package.json 
{}

And I can't find resetWindow to comment it out:

egrep resetWindow node_modules/parcel
$

[jcalfee]

Adding parcel |& cat in package.json (where parcel does run) creates a syntax error. I backup package.json and make my node_modules directory read only so I could avoid having to reinstall.

[jcalfee]

Ctrl+C does not stop the error from being removed in my case. This is parcel v2.3.2.

[jondlm]

Another trick is to set the environment variable NODE_ENV=test which is also picked up along with isTTY. Alternatively you can use PARCEL_WORKERS=0 NODE_OPTIONS=--inspect-brk, put a debugger in your code and use your Chrome debugger.

I tried reproducing the issue with postProcess but ran into other issues with that (details below). It would be helpful to have a minimal repro for this issue if it's still a problem.

I had a little transformer:

const { Transformer } = require("@parcel/plugin");

module.exports = new Transformer({
  async transform({ asset }) {
    return [asset];
  },
  async postProcess({ assets, logger }) {
    logger.warn({ message: "transform" });
    return assets;
  },
});

Which should just return the assets unchanged but it just spews this error:

@parcel/workers: Asset has no content

That makes me think something is broken with postProcess but I could be wrong.