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

stdThreadLocalLog does not print log and trace logs #9870

Open
dlangBugzillaToGithub opened this issue Mar 29, 2024 · 4 comments
Open

stdThreadLocalLog does not print log and trace logs #9870

dlangBugzillaToGithub opened this issue Mar 29, 2024 · 4 comments
Labels
Arch:x86_64 Issues specific to x86_64 OS:Linux Issues specific to Linux Severity:Normal

Comments

@dlangBugzillaToGithub
Copy link

ttanjo (@tom-tan) reported this on 2024-03-29T18:56:10Z

Transfered from https://issues.dlang.org/show_bug.cgi?id=24468

CC List

  • forestix
  • kinke

Description

I reproduce this issue with dmd 2.107.1 on Ubuntu 22.04 and run.dlang.io.
I cannot reproduce this issue with `shaledLog`.

# PoC code
```dlang
import std.logger, std.stdio;

void main()
{
    writeln("==== stdThreadLocalLog ====");
    stdThreadLocalLog.logLevel = LogLevel.all;
    stdThreadLocalLog.log("log");
    stdThreadLocalLog.trace("trace");
    stdThreadLocalLog.info("info");
    stdThreadLocalLog.warning("warning");
    stdThreadLocalLog.error("error");
    stdThreadLocalLog.critical("critical");

    writeln("==== sharedLog ====");
    (cast()sharedLog).logLevel = LogLevel.all;
    (cast()sharedLog).log("log");
    (cast()sharedLog).trace("trace");
    (cast()sharedLog).info("info");
    (cast()sharedLog).warning("warning");
    (cast()sharedLog).error("error");
    (cast()sharedLog).critical("critical");
}

```

# Expected output
Both loggers print `all`, `trace`, `info`, `warning`, `error` and `critical` logs.
```
==== stdThreadLocalLog ====
2024-03-29T18:38:03.881 [all] onlineapp.d:16:main log
2024-03-29T18:38:03.881 [trace] onlineapp.d:17:main trace
2024-03-29T18:38:03.881 [info] onlineapp.d:9:main info
2024-03-29T18:38:03.881 [warning] onlineapp.d:10:main warning
2024-03-29T18:38:03.881 [error] onlineapp.d:11:main error
2024-03-29T18:38:03.881 [critical] onlineapp.d:12:main critical
==== sharedLog ====
2024-03-29T18:38:03.881 [all] onlineapp.d:16:main log
2024-03-29T18:38:03.881 [trace] onlineapp.d:17:main trace
2024-03-29T18:38:03.881 [info] onlineapp.d:18:main info
2024-03-29T18:38:03.881 [warning] onlineapp.d:19:main warning
2024-03-29T18:38:03.882 [error] onlineapp.d:20:main error
2024-03-29T18:38:03.882 [critical] onlineapp.d:21:main critical
```

# Actual behavior
`sharedLog` prints all the logs but `stdThreadLocalLog` lacks `all` and `trace` logs.

```
==== stdThreadLocalLog ====
2024-03-29T18:38:03.881 [info] onlineapp.d:9:main info
2024-03-29T18:38:03.881 [warning] onlineapp.d:10:main warning
2024-03-29T18:38:03.881 [error] onlineapp.d:11:main error
2024-03-29T18:38:03.881 [critical] onlineapp.d:12:main critical
==== sharedLog ====
2024-03-29T18:38:03.881 [all] onlineapp.d:16:main log
2024-03-29T18:38:03.881 [trace] onlineapp.d:17:main trace
2024-03-29T18:38:03.881 [info] onlineapp.d:18:main info
2024-03-29T18:38:03.881 [warning] onlineapp.d:19:main warning
2024-03-29T18:38:03.882 [error] onlineapp.d:20:main error
2024-03-29T18:38:03.882 [critical] onlineapp.d:21:main critical
```
@dlangBugzillaToGithub
Copy link
Author

kinke commented on 2024-03-29T22:25:48Z

According to the docs (https://dlang.org/phobos/std_logger_core.html#.stdThreadLocalLog), `stdThreadLocalLog` just forwards to `sharedLog`. The latter has a default LogLevel of info. So in your example, you'd need to set the `sharedLog.logLevel` *before* logging to `stdThreadLocalLog` (which defaults to `LogLevel.all`, forwarding everything to the shared logger).

The key info is in the std.logger package docs (https://dlang.org/phobos/std_logger.html):
> The LogLevel of the stdThreadLocalLog can be used to filter log calls before they reach the sharedLog Logger.

Perhaps this should be duplicated in the documentation for the `stdThreadLocalLog` property.

@dlangBugzillaToGithub
Copy link
Author

ttanjo (@tom-tan) commented on 2024-03-30T03:37:33Z

Thank you for the information.
It works when I set `Loglevel.all` to both logger before calling logging methods  as follows.

```dlang
    ...
    (cast()sharedLog).logLevel = LogLevel.all;
    stdThreadLocalLog.logLevel = LogLevel.all;

    writeln("==== stdThreadLocalLog ====");
    stdThreadLocalLog.log("log");
    ...
```

> Perhaps this should be duplicated in the documentation for the `stdThreadLocalLog` property.

I guess the information of default logLevel in each logger should be in the `Thread Local Redirection` section in std.logger because most users read the documents in std.logger first.

Can I close this issue or leave it opened until the document is improved?
If the case of latter, I will send a pull request for it.

@dlangBugzillaToGithub
Copy link
Author

forestix commented on 2024-05-28T23:13:54Z

The experience I had today as a newcomer to Phobos logging:

- Read the std.logger docs.
- Create a StdForwardLogger for each of my modules.
  (I want to control each module's log level separately.)
- Discover that trace log messages are silently discarded.
- Set my logger's log level.
- Discover that trace log messages are still silently discarded.
- Read the std.logger docs again.
- Set globalLogLevel.
- Discover that trace log messages are still silently discarded.
- Read the std.logger docs again.
- Set sharedLog.logLevel.
- Discover that the compiler won't let me
  (none of the overloads of `logLevel` are callable using a `shared` mutable object)
- Read the std.logger docs again.
- Notice how much time this basic task is taking, and swear in exasperation.
- Grovel through the dlang forum archive in search of help.
- Find the magic incantation here:
  https://forum.dlang.org/post/mveqddfktkykwvhombsl@forum.dlang.org
  (cast()sharedLog).logLevel = LogLevel.all;
- Try the magic incantation.
- Discover that the compiler won't let me use it in @safe code.

A default log level higher than `trace` is no surprise; that's reasonably common in logging libraries. However, dealing with it in Phobos is surprisingly painful.

In particular, the solution has at least these problems:

- It's nonintuitive.
- It's not clearly documented.
- It's unreasonably awkward for something as common as logging.
- It doesn't work at all in @safe code.

After finally getting to the bottom of it (and nearly giving up on D because this is far from the first Phobos usability problem to bite me) I see that I could work around it in my own programs by using @trusted code. However, I'm writing a library, and I really don't want to require that its users resort to library-specific functions or @trusted shenanigans to control such basic functionality as logging.

It would be nice if this was either fixed by a revised std.logger design, or at least hidden behind a clearly documented standard interface.

@dlangBugzillaToGithub
Copy link
Author

forestix commented on 2024-05-29T01:36:00Z

Also, is `(cast()sharedLog).logLevel = LogLevel.all` thread-safe?

If so, how is the user supposed to know that?

If not, where is the thread-safe equivalent?

@LightBender LightBender removed the P1 label Dec 6, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Arch:x86_64 Issues specific to x86_64 OS:Linux Issues specific to Linux Severity:Normal
Projects
None yet
Development

No branches or pull requests

2 participants