Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logger is hardcoded to "trace" #171

Open
johansten opened this issue Apr 18, 2024 · 10 comments
Open

Logger is hardcoded to "trace" #171

johansten opened this issue Apr 18, 2024 · 10 comments
Assignees

Comments

@johansten
Copy link

johansten commented Apr 18, 2024

Core constructor takes an options object w/ a "logger" entry for customizing the log level, but generatePlatformLogger() then ignores it, using "trace".

@devceline
Copy link
Contributor

Yes - trace is the level that gets logged to the in-memory array of logs. This can be downloaded via window.downloadLogsBlobInBrowser on the browser, or simply retrieved via core.getLogsBlob.

However - The level passed is what determines what gets filtered and allowed to pass through the console. You can see this being done here. This is where the level passed is used

@johansten
Copy link
Author

johansten commented Apr 24, 2024

IDK. For some reason, after this recent change, my console is all trace, to the point where it's not even useful any longer. It doesn't matter if I pass "logger": "silent", or anything else into my Core, because it gets overwritten w/ "trace" here https://github.com/WalletConnect/walletconnect-utils/blob/master/misc/logger/src/utils.ts#L78 and https://github.com/WalletConnect/walletconnect-utils/blob/master/misc/logger/src/utils.ts#L96

@johansten
Copy link
Author

    const core = new Core({
        projectId: xyz,
        logger: 'silent'
    });
    console.log(core.logger.level === 'trace') // <-- true

@johansten
Copy link
Author

If I expand the minified code that's being run in generatePlatformLogger() this is what I get:

function I(r) {
    var e;
    const t = new B((e = r.opts) == null ? void 0 : e.level, r.maxSizeInBytes);
    return {
        logger: h(g(i({}, r.opts), {
            level: "trace"
        }), t),
        chunkLoggerController: t
    }
}

If I comment out the trace line, or change it to silent, my console is back to good again.
As you can see, the user-submitted level from destructuring of opts is overwritten by level: "trace".

@devceline
Copy link
Contributor

Hi @johansten! First of all thank you so much for the detailed breakdown of the error.

We currently use this logger for app.web3inbox.com and the level passed gets respected. Eg, in production error is passed to notify client so logs coming from @walletconnect/notify-client are filtered so that only those with level error shows up.

Yes - you are absolutely right that logger's level is trace. But we have a second layer of filtering. The reason it's trace is so that we keep it in the log array that we can access later. Eg window.downloadLogsBlobInBrowser.

So for the most part, what we should focus on the logs being outputted and not the level of the logger itself.

So - if you set your logger level to error - do you still get trace logs? Better yet, can you provide me with a repository where this happens and we can take it from here?

@johansten
Copy link
Author

I did a barebones example, as it works just as intended.

I think there's something deeper going on here:

This is what I get from a minimal test, you can see it's going through forwardToConsole, just as you say.

Trace: {"level":10,"time":1714009291903,"pid":21519,"hostname":"slartibartfast.local","context":"core","msg":"Initialized"}

    at L.forwardToConsole (/Users/johan/Code/wctest/node_modules/@walletconnect/logger/dist/index.cjs.js:1:1736)
    at L.appendToLogs (/Users/johan/Code/wctest/node_modules/@walletconnect/logger/dist/index.cjs.js:1:1938)
    at B.write (/Users/johan/Code/wctest/node_modules/@walletconnect/logger/dist/index.cjs.js:1:2891)
    at Pino.write (/Users/johan/Code/wctest/node_modules/pino/lib/proto.js:208:10)
    at Pino.LOG [as trace] (/Users/johan/Code/wctest/node_modules/pino/lib/tools.js:60:21)
    at I.initialize (/Users/johan/Code/wctest/node_modules/@walletconnect/web3wallet/dist/index.cjs.js:1:13468)
    at I.init (/Users/johan/Code/wctest/node_modules/@walletconnect/web3wallet/dist/index.cjs.js:1:13422)
    at main (/Users/johan/Code/wctest/test/test.js:10:35)
    at Object.<anonymous> (/Users/johan/Code/wctest/test/test.js:20:1)
    at Module._compile (node:internal/modules/cjs/loader:1376:14)

This is what I get in my actual wallet code,

Trace: { context: 'core' } Initialized
    at console.trace (/Users/johan/Code/wctest/packages/electrovite-react/.vite/build/main.js:35:15668)
    at console.trace (/Users/johan/Code/wctest/packages/electrovite-react/.vite/build/main.js:35:16721)
    at Z5.initialize (/Users/johan/Code/wctest/packages/electrovite-react/.vite/build/main.js:90:60810)
    at Z5.init (/Users/johan/Code/wctest/packages/electrovite-react/.vite/build/main.js:90:60764)
    at Sit (/Users/johan/Code/wctest/packages/electrovite-react/.vite/build/main.js:103:2487)
    at Object.<anonymous> (/Users/johan/Code/wctest/packages/electrovite-react/.vite/build/main.js:103:4493)
    at Module._compile (node:internal/modules/cjs/loader:1271:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1326:10)
    at Module.load (node:internal/modules/cjs/loader:1126:32)
    at Module._load (node:internal/modules/cjs/loader:967:12)

It's not even running through Pino for some reason.. But disabling the trace overwrite makes things work as expected.

@devceline
Copy link
Contributor

I assume your wallet code is closed source? If it's not can you share it here and I can take a look?

If the above is not possible - can you please share some of the trace logs?

@johansten
Copy link
Author

I think the important thing is that I somehow don't get a logger object from Pino. My core.logger is console.
I don't understand how that happens, it shouldn't happens, it only happens in my wallet and not in stand-alone test code.

(I feel like I need to add here that I don't understand the design decision of logging everything, and only filtering what you display. Pino is touted for being lightweight, and fast, because of not doing the work unless it needs doing, and then you go ahead and do all of it anyway)

@devceline
Copy link
Contributor

The reason we log everything is to access it later for debugging - We keep all trace logs in an array so we can easily debug issues and see where connection is going wrong if anything happens.

Can you share how you configure your Core instance? It would be way faster to help you out here if I got to see some code.

@devceline
Copy link
Contributor

@johansten Hi, the issue has been inactive for a while - did you end up finding the cause of why your repo's logger was always logging to trace?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants