[BUG] debug.enable('pw:api') does not work in 1.25 (worked in 1.20)

[ajssd]

Context:

• Playwright Version: 1.25.0
• Operating System: Mac
• Node.js version: 14.19.2

Describe the bug

This is regarding the logging that you get with DEBUG=pw:api.

I am upgrading from Playwright 1.20.1 to 1.25.0. We use Playwright with the Mocha testrunner, launched from a Node script.

The following works in Playwright 1.20.1, but does not work in Playwright 1.25.0 (no other changes):

import debug from 'debug';
debug.enable('pw:api')

Note that I get the logging if I set DEBUG=pw:api from the command line when starting up Node. It just doesn't work when using the debug library like above.

[rwoll]

Thanks for your report! If you need logs, using the environment variable or Logger API are the correct ways of doing it.

To my knowledge:

import debug from 'debug';
debug.enable('pw:api')

is not documented to be supported by PW, and the fact it was working before was merely a coincidence. 😄 While convenient, the fact PW uses the debug package is an implementation detail that should not be depended upon. My best guess as to why it stopped working: we started bundling Playwright's deps within the last few months so the PW package now has zero deps (https://www.npmjs.com/package/playwright-core)!

[ajssd]

Thanks @rwoll for the information. We're not able to use the environment variable, but I was able to get the Logger API working -- to some extent.

The problem is that logging using the Logger API is much less informative than logging using DEBUG=pw:api.

For example, just clicking on a UI element, with the Logger API, I get two calls to log(), and both have a short "message" and no "args" passed. The two messages are:

=> frame.click started
<= frame.click succeeded

Useful, but not terribly, especially when there are lots of sequential clicks, it's hard to tell what's what.

On the other hand, if I use DEBUG=pw:api, I get much more information for the same activity. In particular, I get the locator information, as well as information about what the locator resolved to, e.g.

pw:api => frame.click started +1ms
pw:api waiting for selector "#SiteRequestView >> .header-buttons oj-button.oj-complete#next .oj-button-text:has-text("Finish")" +1ms
pw:api   selector resolved to visible <span id="next_oj6|text" class="oj-button-text">…</span> +14ms
pw:api attempting click action +13ms
pw:api   waiting for element to be visible, enabled and stable +0ms
pw:api   element is visible, enabled and stable +31ms
pw:api   scrolling into view if needed +0ms
pw:api   done scrolling +1ms
pw:api   performing click action +4ms
pw:api   click action done +33ms
pw:api   waiting for scheduled navigations to finish +1ms
pw:api   navigations have finished +2ms
pw:api <= frame.click succeeded +1ms

Can the Logger API be improved so that we're able to show the same information as DEBUG=pw:api ?

[rwoll]

I can repro. Even with a logger like:

  const browser = await playwright.chromium.launch({
    logger: {
      isEnabled: () => true,
      log: (name, severity, message, args) => console.log(name, severity, message, args),
    }
  });

we don't pretty out nearly as much.

We're not able to use the environment variable

@ajssd Can you elaborate more on this contraint?

You can also set it directly in the node process before you require playwright:

process.env.DEBUG = "pw:*";

Additionally, check out the tracing API depending on what your use case is: https://playwright.dev/docs/trace-viewer#recording-a-trace

[ajssd]

Regarding why the environment variable isn't a solution for us ... we have a node script (call it test.js) that processes some command-line arguments (like say, --debug). Then, in that script, we instantiate a "Mocha" object, load up the test files, and do mocha.run().

Now, on the command line, instead of doing test.js --debug we could do DEBUG=pw:api test.js and I think that would work. But that's not really how we have our test automation set up, plus it makes it less portable, not to mention that it used to work -- if only by accident.

If we could get a little more info passed to the logger -- enough to replicate at least some of what DEBUG=pw:api is doing -- that would be terrific.

I tried process.env.DEBUG="pw:*" from the test.js script, and that did not work. Maybe because of how Mocha works?

[rwoll]

I tried process.env.DEBUG="pw:*" from the test.js script, and that did not work. Maybe because of how Mocha works?

I'm assuming your script imports/requires mocha at the top of your file. Try moving the require inline, and ensure it's after the point at which you set process.env.DEBUG.

[ajssd]

Yes, at the top of my file I have

import Mocha from 'mocha';

and then further down, I have, effectively:

// Instantiate a Mocha instance
const mocha = new Mocha({
    reporter: ...,
    rootHooks: ...,
    grep: ...,
    invert: ...,
    ....
});

// Add each test to mocha
myTestFiles.forEach(f => mocha.addFile(f));

// Run the tests
mocha.loadFilesAsync()
    .then(() => mocha.run(failures => ...))
    .catch((e) => { ... });

I saw your suggestion, but I can't figure out how to get Mocha to work with an inline import using import('mocha').then(...). Let me know if you know how to do this.

Is it possible for Playwright just to pass additional information the logger? That would be the best solution, I think.

[rwoll]

I saw your suggestion, but I can't figure out how to get Mocha to work with an inline import using import('mocha').then(...). Let me know if you know how to do this.

You can do const mocha = require('mocha'); where you need it.

Is it possible for Playwright just to pass additional information the logger? That would be the best solution, I think.

Agreed it's the best solution. The above/other suggestions are merely a workaround for the time being.

Thanks!

[ajssd]

Thanks for the suggestion and continued help, but we have an ESM environment so my understanding is that we must import not require the Mocha module.

[rwoll]

Does the following work?

const mocha = await import('mocha');

Again, just a workaround until a more info is plumbed through the logger.

[ajssd]

Appreciate the workaround suggestions ... oddly, while our original code

import Mocha from 'mocha';

works fine, replacing that with

const Mocha = await import('mocha');

gives

const mocha = new Mocha({
              ^
TypeError: Mocha is not a constructor

which I can't quite explain without knowing more about how Mocha's implementation (see code above).

[ajssd]

@rwoll just circling back to see if there is any update on this, now that 1.26 was just released. Any chance the extra logger info will make it into 1.27?

[rwoll]

Any chance the extra logger info will make it into 1.27?

There are no plans at the moment. (When we have an idea of a release milestone, we tag with v1.XY.)

Would you be open to contributing a PR?

[pavelfeldman]

Why was this issue closed?

Thank you for your involvement. This issue was closed due to limited engagement (upvotes/activity), lack of recent activity, and insufficient actionability. To maintain a manageable database, we prioritize issues based on these factors.

If you disagree with this closure, please open a new issue and reference this one. More support or clarity on its necessity may prompt a review. Your understanding and cooperation are appreciated.