WalletConnect / walletconnect-utils

Javascript Utilities for WalletConnect
MIT License
113 stars 75 forks source link

Logger is hardcoded to "trace" #171

Closed johansten closed 3 months ago

johansten commented 6 months ago

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

devceline commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago
    const core = new Core({
        projectId: xyz,
        logger: 'silent'
    });
    console.log(core.logger.level === 'trace') // <-- true
johansten commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 5 months ago

@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?