IGNITE-23472 Fix JavaLogger #11615

chesnokoff · 2024-10-23T13:20:03Z

JavaLogger.configure method is invoked only once for all instances and it configures cfg field which was not static. Because of that only one instance had correct value and other instances had cfg with null value

Thank you for submitting the pull request to the Apache Ignite.

In order to streamline the review of the contribution
we ask you to ensure the following steps have been taken:

The Contribution Checklist

There is a single JIRA ticket related to the pull request.
The web-link to the pull request is attached to the JIRA ticket.
The JIRA ticket has the Patch Available state.
The pull request body describes changes that have been made.
The description explains WHAT and WHY was made instead of HOW.
The pull request title is treated as the final commit message.
The following pattern must be used: IGNITE-XXXX Change summary where XXXX - number of JIRA issue.
A reviewer has been mentioned through the JIRA comments
(see the Maintainers list)
The pull request has been checked by the Teamcity Bot and
the green visa attached to the JIRA ticket (see TC.Bot: Check PR)

Notes

If you need any help, please email [email protected] or ask anу advice on http://asf.slack.com #ignite channel.

modules/core/src/main/java/org/apache/ignite/logger/java/JavaLogger.java

chesnokoff · 2024-11-01T09:55:00Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+        IgniteLogger log2 = log1.getLogger(getClass());
+
+        assertTrue(log1.toString().contains("JavaLogger"));
+        assertTrue(log1.toString().contains(JavaLogger.DFLT_CONFIG_PATH));


Assert failed and was fixed by this(true) change in default constructor

chesnokoff · 2024-11-01T09:59:12Z

modules/log4j2/src/test/java/org/apache/ignite/logger/log4j2/Log4j2ConfigUpdateTest.java

+
+        assertTrue(logContent.contains("[INFO] Accepted info"));
+        assertFalse(logContent.contains("[DEBUG] Ignored debug"));
+        assertTrue(logContent.contains("[DEBUG] Accepted debug"));


This assert fails

chesnokoff · 2024-11-01T10:00:44Z

modules/log4j2/src/test/java/org/apache/ignite/logger/log4j2/Log4j2ConfigUpdateTest.java

+        log.info("Accepted info");
+        log.debug("Ignored debug");
+
+        log = logSupplier.get(debugCfgFile);


Configuration of log is still infoCfgFile because cfg field is inited only once. That's why "Accepted debug" won't be logged

timoninmaxim · 2024-11-07T07:20:55Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+    /**
+     * Configure java.util.logging.config.file property
+     */
+    private void setJavaLoggerConfig() throws IOException {


Method can be inlined

timoninmaxim · 2024-11-07T07:21:28Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+    private void setJavaLoggerConfig() throws IOException {
+        File file = new File(U.getIgniteHome(), LOG_CONFIG_DEBUG);
+        System.setProperty("java.util.logging.config.file", file.getPath());
+        LogManager.getLogManager().readConfiguration();


I suppose user shouldn't explicitly read configuration. It is invoked inside LogManager while user tries to log first message, isn't it?

LogManager reads the property when Logger.getLogger method is called first time.
The problem is that it happens before System.setProperty

Firstly, it happens because JavaLoggerTest extends GridCommonAbstractTest which initialize IgniteUtils and IgniteUtils calls Logger.getLogger.

Secondly, U.getIgniteHome() also calls initialization of IgniteUtils and it calls Logger.getLogger again.

So Logger.getLogger is called before setProperty and that's why jul won't read this property without explicit configuration.

ignite/modules/core/src/main/java/org/apache/ignite/internal/util/IgniteUtils.java

Line 319 in 67e2831

private static final Logger log = Logger.getLogger(IgniteUtils.class.getName());

timoninmaxim · 2024-11-07T07:28:46Z

modules/core/src/main/java/org/apache/ignite/logger/java/JavaLogger.java

@@ -194,7 +194,7 @@ public JavaLogger(boolean init) {
     * @param impl Java Logging implementation to use.
     */
    public JavaLogger(final Logger impl) {


Do we really need this constructor?

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

timoninmaxim · 2024-11-07T07:30:21Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+
+
+    /**
+     * Check JavaLogger default constructor


Sentences in comments and javadocs should end with a dot sign.

timoninmaxim · 2024-11-07T07:34:16Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+        cfg.setGridLogger(log);
+        startGrid(cfg);
+
+        doSleep(2_000);


Please don't use sleep for waiting any events. Use instead GridTestUtils#waitForCondition.

timoninmaxim · 2024-11-07T07:34:28Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+    @Test
+    public void testGridLoggingWithCustomLogger() throws Exception {
+        AtomicBoolean hasLog = new AtomicBoolean(false);
+        Filter filter = record -> {


Use LogListener instead

ListeningTestLogger did not have toString method implementation. That's why I've edited ListeningTestLogger

timoninmaxim · 2024-11-08T13:38:27Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

@@ -84,4 +153,5 @@ public void testLogInitialize() throws Exception {
        assert !log.fileName().contains("%");
        assert log.fileName().contains("other-app");
    }
+


useless change

...src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLoggerSelfTest.java

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

timoninmaxim · 2024-11-11T08:07:39Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+    public void testDefaultConstructorWithProperty() throws Exception {
+        File file = new File(U.getIgniteHome(), LOG_CONFIG_DEBUG);
+        System.setProperty("java.util.logging.config.file", file.getPath());
+        // Call readConfiguration explicitly because Logger.getLogger was already called during IgniteUtils initialization


Comments should be ended with a dot sign.

timoninmaxim · 2024-11-11T08:09:01Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+        assertTrue(log2.toString().contains(LOG_CONFIG_DEBUG));
+        assertTrue(log1.isDebugEnabled());
+
+        System.clearProperty("java.util.logging.config.file");


This code will not call in case of an assertion error.

timoninmaxim · 2024-11-11T08:18:01Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+        cfg.setGridLogger(log);
+        startGrid(cfg);
+
+        assertTrue(GridTestUtils.waitForCondition(lsn::check, 2_000));


Why do you wait for the check in background?

I thought the program would log after the execution of startGrid. However, I've checked it, and the message is actually logged before the execution of startGrid completes.

timoninmaxim · 2024-11-11T08:46:22Z

modules/core/src/main/java/org/apache/ignite/logger/java/JavaLogger.java

    /** {@inheritDoc} */
    @Override public IgniteLogger getLogger(Object ctgr) {
        return new JavaLogger(ctgr == null
            ? Logger.getLogger("")
            : Logger.getLogger(ctgr instanceof Class
                ? ((Class<?>)ctgr).getName()
-                : String.valueOf(ctgr)));
+                : String.valueOf(ctgr)), quiet, cfg);


It starts invoking another constructor. Before your change there was a chain:

JavaLogger#getLogger(Object) -> new JavaLogger(Logger, configure=true)

After your change, in case root logger created as new JavaLogger(false) the underlying logger will use constructor with no configuration and it never been configured. And the constructor JavaLogger(Logger, boolean) is useless. Is it ok?

timoninmaxim · 2024-11-11T08:47:40Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+        startGrid(cfg);
+
+        assertTrue(GridTestUtils.waitForCondition(lsn::check, 2_000));
+        stopAllGrids();


Can be replaced with

try(Ignite ign = startGrid(cfg) { ... }

timoninmaxim · 2024-11-11T08:48:32Z

...es/core/src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLogger.java

@@ -271,6 +271,23 @@ public GridTestLog4jLogger(final URL cfgUrl) throws IgniteCheckedException {
        quiet = quiet0;
    }

+    /**
+     * Creates new logger with given implementation.
+     *


Remove useless blank line

timoninmaxim · 2024-11-11T08:51:16Z

...src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLoggerSelfTest.java

+        File xml = GridTestUtils.resolveIgnitePath(LOG_PATH_TEST);
+
+        assert xml != null;
+        assert xml.exists();


the existence is already tested in GridTestUtils.resolveIgnitePath

I copied this part of the code from Log4j2LoggerSelfTest. Now I've fixed it in both GridTestLog4jLoggerSelfTest and Log4j2LoggerSelfTest.

timoninmaxim · 2024-11-11T08:51:31Z

...src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLoggerSelfTest.java

+
+        IgniteLogger log = new GridTestLog4jLogger(xml).getLogger(getClass());
+
+        System.out.println(log.toString());


do not sout anything in tests

Same as previous answer about Log4j2LoggerSelfTest.

modules/core/src/main/java/org/apache/ignite/logger/java/JavaLogger.java

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

timoninmaxim · 2024-11-25T15:48:28Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+            IgniteLogger log2 = log1.getLogger(getClass());
+            assertTrue(log2.toString().contains("JavaLogger"));
+            assertTrue(log2.toString().contains(LOG_CONFIG_DEBUG));
+            assertTrue(log1.isDebugEnabled());


modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

timoninmaxim · 2024-11-25T15:49:05Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+
+        IgniteConfiguration cfg = getConfiguration(getTestIgniteInstanceName());
+        cfg.setGridLogger(log);
+        try (Ignite ign = startGrid(cfg)) {


Add a blank line before this line

timoninmaxim · 2024-11-25T15:49:46Z

modules/core/src/test/java/org/apache/ignite/logger/java/JavaLoggerTest.java

+
+        IgniteConfiguration cfg = getConfiguration(getTestIgniteInstanceName());
+        cfg.setGridLogger(log);
+        try (Ignite ign = startGrid(cfg)) {


Name ign -> ignore, to avoid a warning about unused variable in IDEA

...src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLoggerSelfTest.java

timoninmaxim · 2024-11-25T16:02:30Z

...src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLoggerSelfTest.java

+        assertTrue(log.toString().contains("GridTestLog4jLogger"));
+        assertTrue(log.toString().contains(xml.getPath()));
+
+        log.setApplicationAndNode(null, UUID.randomUUID());


Why do you need it?

timoninmaxim · 2024-11-25T16:03:14Z

...src/test/java/org/apache/ignite/testframework/junits/logger/GridTestLog4jLoggerSelfTest.java

-    public static void beforeTests() {
+    @Before
+    public void beforeTest() {
+        System.clearProperty("appId");


make GridTestLog4jLogger#APP_ID package private and use this variable

chesnokoff force-pushed the ignite-23472 branch 2 times, most recently from 47549cd to 64a31fb Compare November 1, 2024 09:46

chesnokoff commented Nov 1, 2024

View reviewed changes

chesnokoff force-pushed the ignite-23472 branch 5 times, most recently from c5293f7 to 0e1af24 Compare November 5, 2024 15:32

chesnokoff closed this Nov 5, 2024

chesnokoff reopened this Nov 5, 2024

chesnokoff force-pushed the ignite-23472 branch from 0e1af24 to 64e382c Compare November 6, 2024 10:51

timoninmaxim requested changes Nov 7, 2024

View reviewed changes

chesnokoff force-pushed the ignite-23472 branch 2 times, most recently from 5f057ff to fc07c23 Compare November 8, 2024 13:06

timoninmaxim requested changes Nov 8, 2024

View reviewed changes

chesnokoff force-pushed the ignite-23472 branch 4 times, most recently from 9e7fa81 to c4ac02e Compare November 9, 2024 16:30

timoninmaxim requested changes Nov 11, 2024

View reviewed changes

chesnokoff force-pushed the ignite-23472 branch 3 times, most recently from 162f57c to 773eb80 Compare November 17, 2024 19:57

chesnokoff added 6 commits November 22, 2024 15:13

IGNITE-23472 Add ListeningTestLogger.toString()

5601da2

IGNITE-23472 Add jul-debug.properties

35880ad

IGNITE-23472 Add tests for JavaLogger

6d738a2

IGNITE-23472 Fix JavaLogger

0e32bfc

IGNITE-23472 Add tests for GridTestLog4jLogger

0f6d60c

IGNITE-23472 Fix GridTestLog4jLogger

204c8a8

chesnokoff force-pushed the ignite-23472 branch from 773eb80 to ee46642 Compare November 22, 2024 12:13

chesnokoff force-pushed the ignite-23472 branch 2 times, most recently from 2886b29 to af6ab6f Compare November 25, 2024 09:14

IGNITE-23472 Fix after review

c3cad59

chesnokoff force-pushed the ignite-23472 branch from af6ab6f to c3cad59 Compare November 25, 2024 11:39

timoninmaxim requested changes Nov 25, 2024

View reviewed changes

chesnokoff force-pushed the ignite-23472 branch 4 times, most recently from 2b9847b to d51ef1c Compare November 26, 2024 13:57

chesnokoff added 2 commits November 27, 2024 15:45

IGNITE-23472 Fix after review 2

a7533e0

IGNITE-23472 Add test for GridTestLog4jLogger

605d861

chesnokoff force-pushed the ignite-23472 branch from d51ef1c to 605d861 Compare November 27, 2024 12:50

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

IGNITE-23472 Fix JavaLogger #11615

IGNITE-23472 Fix JavaLogger #11615

chesnokoff commented Oct 23, 2024 •

edited

Loading

chesnokoff Nov 1, 2024

chesnokoff Nov 1, 2024

chesnokoff Nov 1, 2024

timoninmaxim Nov 7, 2024

timoninmaxim Nov 7, 2024

chesnokoff Nov 8, 2024 •

edited

Loading

timoninmaxim Nov 7, 2024

timoninmaxim Nov 7, 2024

timoninmaxim Nov 7, 2024

timoninmaxim Nov 7, 2024

chesnokoff Nov 8, 2024 •

edited

Loading

timoninmaxim Nov 8, 2024

timoninmaxim Nov 11, 2024

timoninmaxim Nov 11, 2024

timoninmaxim Nov 11, 2024

chesnokoff Nov 13, 2024

timoninmaxim Nov 11, 2024

timoninmaxim Nov 11, 2024

timoninmaxim Nov 11, 2024

timoninmaxim Nov 11, 2024

chesnokoff Nov 13, 2024 •

edited

Loading

timoninmaxim Nov 11, 2024

chesnokoff Nov 13, 2024 •

edited

Loading

timoninmaxim Nov 25, 2024

timoninmaxim Nov 25, 2024

timoninmaxim Nov 25, 2024

timoninmaxim Nov 25, 2024

timoninmaxim Nov 25, 2024


		IgniteLogger log = new GridTestLog4jLogger(xml).getLogger(getClass());

		System.out.println(log.toString());

IGNITE-23472 Fix JavaLogger #11615

Are you sure you want to change the base?

IGNITE-23472 Fix JavaLogger #11615

Conversation

chesnokoff commented Oct 23, 2024 • edited Loading

The Contribution Checklist

Notes

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

chesnokoff Nov 8, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

chesnokoff Nov 8, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

chesnokoff Nov 13, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

chesnokoff Nov 13, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

chesnokoff commented Oct 23, 2024 •

edited

Loading

chesnokoff Nov 8, 2024 •

edited

Loading

chesnokoff Nov 8, 2024 •

edited

Loading

chesnokoff Nov 13, 2024 •

edited

Loading

chesnokoff Nov 13, 2024 •

edited

Loading