Add `docker.` prefix to container logger names, to enable log level to be set across all loggers by vcvitaly · Pull Request #3018 · testcontainers/testcontainers-java

vcvitaly · 2020-07-24T10:16:22Z

vcvitaly · 2020-08-25T05:53:31Z

@bsideup please review?

hmemcpy · 2020-10-08T08:35:32Z

Sorry for the bump, any chance of reviewing this? I have a feeling this may help deal with #637 where it would be nice to set the log level for all dockers at once instead of matching against the 🐳...

rnorth · 2020-10-15T20:13:10Z

@vcvitaly please could you merge from master, or preferably give maintainers permission to edit?

We've had some CI problems, so hopefully updating from master should fix things.

rnorth · 2020-10-15T20:20:29Z

Overall I think this looks fine and long overdue (sorry for the immense time to review). Let's just see the tests pass once rebased onto master and I think we should be good to go!

rnorth · 2020-10-15T20:25:48Z

I think it would be fair to say this fixes #637, although not in the way originally proposed.

vcvitaly · 2020-10-16T12:52:53Z

@rnorth I just can't find that checkbox to allow edits, I don't have it for some reason. I rebased onto the master.

rnorth

Thanks @vcvitaly, LGTM.
Heads up @bsideup, @kiview, this is a slight change in aesthetics, but I think is unavoidable!

rnorth · 2020-11-05T19:30:50Z

I’m afraid I’ll have to defer this to 1.15.1, so that we can review this together. We’re expecting to publish that release soon after 1.15.0, so it shouldn’t be too much delay.

perlun · 2021-06-02T11:19:34Z

@rnorth Anything blocking this from being merged now, given that 1.15.1 is released? Would be incredibly nice to make the container logging be more easily controlled from e.g. logback-test.xml config.

rnorth · 2021-06-09T16:03:39Z

@bsideup I think you had some ideas about how this could be done without a change to how it looks for normal use cases?

adutra · 2021-08-09T12:26:25Z

-            return LoggerFactory.getLogger("docker[" + abbreviatedName + "]");
-        }
+        return LoggerFactory.getLogger(String.format(
+            "docker.%s[%s]",


I'd suggest avoiding brackets here. Some frameworks (e.g. Quarkus) give brackets a special meaning, and as a consequence, the following configuration would fail:

quarkus.log.category."docker.[foo:latest]".level=ERROR

Of course, this would work:

quarkus.log.category.docker.level=ERROR

But then we lose the ability to distinguish different containers.

I think a better approach would be to create a hierarchy of docker.<image name>.<label>, separated by dots.

Also, IMHO the little whale emoji is pretty, but only adds clutter when included in a logger name. Maybe move it to the log messages themselves?

I agree @adutra. The whale emoji is cute but it totally doesn't belong in the actual logger name. 😂 So something like this would be preferable here:

return LoggerFactory.getLogger("docker." + abbreviatedName);

Ideally, I think it should be prefixed with org.testcontainers though, so that all Testcontainers-based logging can be filtered away easily. org.testcontainers.docker would perhaps be the most suitable prefix here, i.e. this:

return LoggerFactory.getLogger("org.testcontainers.docker." + abbreviatedName);

perlun · 2021-09-07T08:05:56Z

Ping @bsideup, would be great to get your feedback on this. (Not myself advocating a particular solution, only eager to see #637 resolved one way or the other)

okorz001 · 2022-01-26T21:35:40Z

any progress on this? it is a bit more difficult to promote this library when logging is difficult to configure.

(personally, I would prefer an org.testcontainers. prefix, but anything other than root will solve my problems.)

sideeffffect · 2022-09-29T21:34:10Z

Humble ping 🙂
org.testcontainers. is definitely better.

kiview · 2022-09-30T10:07:57Z

Sorry, everyone, I am not sure why we let this go stale for some time now. We will look into it so that we can decide at least whether we will tackle this in a timely manner, or not at all.

perlun · 2022-10-25T15:01:23Z

Sorry, everyone, I am not sure why we let this go stale for some time now. We will look into it so that we can decide at least whether we will tackle this in a timely manner, or not at all.

Sounds good @kiview, any updates on this yet? ☺️

perlun · 2022-10-27T06:46:34Z

@vcvitaly - I added some feedback in https://github.com/testcontainers/testcontainers-java/pull/3018/files#r1006459726. If you're still with us, it would be nice to get these final details sorted out before this hopefully gets merged.

If not, I am willing to take ownership of this change to make it be mergable. We really, really need to get this shipped anytime soon. It's a major pain related to e.g. CI logging right now.

vcvitaly · 2022-11-07T17:15:22Z

@vcvitaly - I added some feedback in https://github.com/testcontainers/testcontainers-java/pull/3018/files#r1006459726. If you're still with us, it would be nice to get these final details sorted out before this hopefully gets merged.

If not, I am willing to take ownership of this change to make it be mergable. We really, really need to get this shipped anytime soon. It's a major pain related to e.g. CI logging right now.

@perlun sorry, I almost forgot about this PR) let me review this within two days

vcvitaly · 2022-11-08T07:59:19Z

@kiview I renamed the logger as suggested by the community, please provide your feedback.

perlun · 2022-11-15T13:04:50Z

Ping @kiview, is this mergable now or would it require any further adjustments?

perlun · 2022-12-14T12:05:34Z

@eddumelendez - you seem to have been merging stuff recently. If you could help push things forward on this, it would be very greatly appreciated. 🙇 🙏

perlun · 2023-01-09T07:57:26Z

Anyone who talks to the maintainers recently, please ping them about this. I seem to be unable to get in touch with them despite repeated attempts.

eddumelendez · 2023-01-11T05:08:54Z

Hi, sorry for the delay on this one. We just started discussing about this internally. So, we will be sharing news hopefully soon.

Thanks for your patience.

vcvitaly · 2023-01-24T06:36:45Z

@eddumelendez quite some time has passed since the PR was opened so here is a short review of the reasons why I opened it:

The initial problem was that since the container logs start with the whale emoji or docker prefix, they go under the root INFO hierarchy, and you cannot see debug logs that might be useful if there are issues. I experienced that myself when I was working on another PR to testcontainers and couldn't find an issue for a while because it was printed as debug and effectively not shown. What I did - I just removed the whale emoji from the factory and added the 'docker' prefix with the DEBUG level to the logback-test.xml because I thought that missing debug info is a mistake. I now understand that it was probably a conscious decision.
Since then multiple community members have made complaints that it's hard to configure logging with the whale emoji and that a non-Unicode prefix should be used. I then changed the prefix to org.testcontainers.docker as suggested by @perlun

If something else is required from my side that might speed up pr review, I'd be happy to provide any additional info.

eddumelendez

Thanks for your contribution, @vcvitaly ! Sorry about the delay. I've left some comments. Can you also update the docs related to logging, please?

The reason why tc has been decided it is because we want to avoid log truncation.

eddumelendez · 2023-03-13T14:42:43Z

-        } else {
-            return LoggerFactory.getLogger("docker[" + abbreviatedName + "]");
-        }
+        return LoggerFactory.getLogger("org.testcontainers.docker." + abbreviatedName);


Suggested change

return LoggerFactory.getLogger("org.testcontainers.docker." + abbreviatedName);

return LoggerFactory.getLogger("tc." + abbreviatedName);

eddumelendez · 2023-03-13T14:42:46Z

+
+        assertThat(event.getFormattedMessage()).isEqualTo("some text");
+        assertThat(event.getLevel()).isEqualTo(Level.DEBUG);
+        assertThat(event.getLoggerName()).startsWith("org.testcontainers.docker");


Suggested change

assertThat(event.getLoggerName()).startsWith("org.testcontainers.docker");

assertThat(event.getLoggerName()).startsWith("tc");

eddumelendez · 2023-03-13T14:43:03Z

    <logger name="org.testcontainers.shaded" level="WARN"/>

-</configuration>
+</configuration>


can we rollback this, please?

eddumelendez · 2023-03-13T21:55:41Z

+
+    @Test
+    public void debugIsNotSwallowedForContainerLogs() {
+        // Arrange


Suggested change

// Arrange

eddumelendez · 2023-03-13T21:55:47Z

+        listAppender.start();
+        LOGGER.addAppender(listAppender);
+
+        // Act


Suggested change

// Act

eddumelendez · 2023-03-13T21:55:56Z

+        // Act
+        LOGGER.debug("some text");
+
+        // Assert


Suggested change

// Assert

eddumelendez · 2023-03-14T18:07:30Z

#6781 has been created in order to tackle this. Thanks for your contribution @vcvitaly

vcvitaly requested review from bsideup, kiview and rnorth as code owners July 24, 2020 10:16

vcvitaly mentioned this pull request Jul 24, 2020

Improve log messages when database container test query fails #3015

Merged

rnorth added this to the next milestone Oct 15, 2020

rnorth added the type/feature label Oct 15, 2020

rnorth changed the title ~~Update logging settings for containers #3016~~ Add docker. prefix to container logger names, to enable log level to be set across all loggers Oct 15, 2020

rnorth previously approved these changes Oct 17, 2020

View reviewed changes

rnorth modified the milestones: 1.15.0, 1.15.1 Nov 5, 2020

bsideup removed this from the 1.15.1 milestone Dec 11, 2020

rnorth added this to the next milestone Dec 12, 2020

bsideup removed this from the next milestone Feb 11, 2021

adutra reviewed Aug 9, 2021

View reviewed changes

Vitalii Chura and others added 2 commits November 7, 2022 19:31

Add docker. prefix to container logger names (#3016)

44a9093

Update logger name used by containers

ecf0d7a

vcvitaly dismissed rnorth’s stale review via ecf0d7a November 7, 2022 18:31

vcvitaly requested a review from a team November 7, 2022 18:31

vitalii-chura-axon added 2 commits November 7, 2022 21:52

fix formatting

56d856c

remove unnecessary logger from logbacks

6ed6bee

perlun mentioned this pull request Feb 16, 2023

Bugfix: Log consumers are now called with exactly one complete log line #5854

Merged

eddumelendez mentioned this pull request Mar 12, 2023

Loggers provided by DockerLoggerFactory inherit from root logger instead of custom loggers #3016

Closed

eddumelendez added this to the next milestone Mar 13, 2023

This was referenced Mar 13, 2023

Solves #3016: custom docker logger name prefix via System property #6773

Closed

Solves #3016: custom docker logger name prefix via config #6772

Closed

eddumelendez requested changes Mar 13, 2023

View reviewed changes

eddumelendez reviewed Mar 13, 2023

View reviewed changes

eddumelendez closed this Mar 14, 2023

	return LoggerFactory.getLogger("org.testcontainers.docker." + abbreviatedName);
	return LoggerFactory.getLogger("tc." + abbreviatedName);

	assertThat(event.getLoggerName()).startsWith("org.testcontainers.docker");
	assertThat(event.getLoggerName()).startsWith("tc");

Uh oh!

Conversation

vcvitaly commented Jul 24, 2020

Uh oh!

vcvitaly commented Aug 25, 2020

Uh oh!

hmemcpy commented Oct 8, 2020

Uh oh!

rnorth commented Oct 15, 2020

Uh oh!

rnorth commented Oct 15, 2020

Uh oh!

rnorth commented Oct 15, 2020

Uh oh!

vcvitaly commented Oct 16, 2020

Uh oh!

rnorth left a comment

Choose a reason for hiding this comment

Uh oh!

rnorth commented Nov 5, 2020

Uh oh!

perlun commented Jun 2, 2021

Uh oh!

rnorth commented Jun 9, 2021

Uh oh!

adutra Aug 9, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

perlun Oct 27, 2022

Choose a reason for hiding this comment

Uh oh!

perlun commented Sep 7, 2021

Uh oh!

okorz001 commented Jan 26, 2022

Uh oh!

sideeffffect commented Sep 29, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kiview commented Sep 30, 2022

Uh oh!

perlun commented Oct 25, 2022

Uh oh!

perlun commented Oct 27, 2022

Uh oh!

vcvitaly commented Nov 7, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vcvitaly commented Nov 8, 2022

Uh oh!

perlun commented Nov 15, 2022

Uh oh!

perlun commented Dec 14, 2022

Uh oh!

perlun commented Jan 9, 2023

Uh oh!

eddumelendez commented Jan 11, 2023

Uh oh!

vcvitaly commented Jan 24, 2023

Uh oh!

eddumelendez left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

eddumelendez Mar 13, 2023

Choose a reason for hiding this comment

Uh oh!

eddumelendez Mar 13, 2023

Choose a reason for hiding this comment

Uh oh!

eddumelendez Mar 13, 2023

Choose a reason for hiding this comment

Uh oh!

eddumelendez Mar 13, 2023

Choose a reason for hiding this comment

Uh oh!

eddumelendez Mar 13, 2023

Choose a reason for hiding this comment

Uh oh!

eddumelendez Mar 13, 2023

adutra Aug 9, 2021 •

edited

Loading

sideeffffect commented Sep 29, 2022 •

edited

Loading

vcvitaly commented Nov 7, 2022 •

edited

Loading

eddumelendez left a comment •

edited

Loading