Re: Synchronization issue in multithreading (Losing huge data in multithreading) with log4j 1.x bridge (2.17.2)

Pooja, I think it would be better for attachments and such if you create a
JIRA ticket <https://issues.apache.org/jira/projects/LOG4J2/issues>. What
would be ideal is to share a simple program (a Java file + Log4j
configuration) reproducing the issue in the ticket. This would help us a
lot to troubleshoot what is going on.

On Fri, Mar 25, 2022 at 12:34 AM Pooja Pandey <[email protected]>
wrote:

> Just for reference, few methods which were synchronized earlier in
> log4j1.x but not anymore in log4j1.x bridge.
>
> 1.  public void addAppender(final Appender appender)
>
> 2.  public Appender getAppender(final String name)
>
> 3.  public void removeAppender(final Appender appender)
>
> 4.  public void removeAllAppenders()
>
>
>
> I suspect the methods relating to configuration or getting appenders would
> only be problematic at initialization time.
>
>
>
> The methods we might need to watch for are ones relating to the runtime
> logging methods (e.g. info() warn()).  May be the methods chained to in
> log4j2 are not threadsafe.  But maybe the bridge itself has some thread
> safety issues.
>
>
>
> Pasting sample code here (Please Note that in this test program, class
> CustomLogger is a dummy class, which you would need to replace with your
> logger)
>
>
>
> package test.common;
>
>
>
> import org.apache.log4j.Logger;
>
> import sun.management.VMManagement;
>
>
>
> import java.io.BufferedWriter;
>
> import java.io.IOException;
>
> import java.lang.management.ManagementFactory;
>
> import java.lang.management.RuntimeMXBean;
>
> import java.lang.reflect.Field;
>
> import java.lang.reflect.Method;
>
> import java.nio.file.Files;
>
> import java.nio.file.Paths;
>
> import java.time.Duration;
>
> import java.time.Instant;
>
> import java.util.ArrayList;
>
> import java.util.List;
>
> import java.util.concurrent.Callable;
>
> import java.util.concurrent.ExecutionException;
>
> import java.util.concurrent.ExecutorService;
>
> import java.util.concurrent.Executors;
>
> import java.util.concurrent.Future;
>
> import java.util.concurrent.TimeUnit;
>
> class CustomLogger extends Logger {
>
>     protected CustomLogger(String name) {
>
>         super(name);
>
>     }
>
>
>
>     public static void LogError(String s, Object o) {
>
>     }
>
> }
>
> public class JavaLoggingMultiThTest {
>
>
>
>     public int pid;
>
>
>
>     private class LoggerTask implements Callable<LoggerTask> {
>
>         public synchronized void run() {
>
>             int logMsgWrittenPerThread;
>
>             int maxLogMsgsPerThread = 52224;
>
>             for(logMsgWrittenPerThread = 1; logMsgWrittenPerThread <=
> maxLogMsgsPerThread; logMsgWrittenPerThread++) {
>
>                 CustomLogger.LogError("p:" + pid + ", LM:" +
> Integer.toString(logMsgWrittenPerThread), null);
>
>             }
>
>         }
>
>
>
>         @Override public synchronized LoggerTask call()  {
>
>             run();
>
>             return this;
>
>         }
>
>     }
>
>
>
>     public synchronized void runLoggerTaskMultipleThreads() {
>
>         int numThreads = 20;
>
>         ArrayList<LoggerTask> loggerTaskList = new ArrayList<LoggerTask>();
>
>         for(int i=0; i< numThreads; i++) {
>
>             loggerTaskList.add(new LoggerTask());
>
>         }
>
>         ExecutorService pool = Executors.newFixedThreadPool(numThreads);
>
>         try {
>
>             Instant startTS = Instant.now();
>
>             List<Future<LoggerTask>> waiters =
> pool.invokeAll(loggerTaskList);
>
>             boolean allEnded = false;
>
>             for (Future waiter : waiters) {
>
>                 try {
>
>                     waiter.get();
>
>                 } catch (InterruptedException | ExecutionException e) {
>
>                     e.printStackTrace();
>
>                 }
>
>             }
>
>             do {
>
>                try {
>
>                     pool.shutdown();
>
>                     allEnded = pool.awaitTermination(1, TimeUnit.MINUTES);
>
>                 } catch (InterruptedException e) {
>
>                     e.printStackTrace();
>
>                     System.out.println("Interrupted, for some reason");
>
>                 }
>
>                 if (!allEnded)
>
>                     System.out.println("Not ending cleanly");
>
>             } while (!allEnded);
>
>             Instant endTS = Instant.now();
>
>             Duration elapsed = Duration.between(startTS, endTS);
>
>             System.out.println("Time taken by current process" + elapsed);
>
>         } catch (InterruptedException e) {
>
>             e.printStackTrace();
>
>         }
>
>     }
>
>
>
>     private static int getCurrrentProcessId() throws Exception {
>
>
>
>         RuntimeMXBean runtime = ManagementFactory.getRuntimeMXBean();
>
>         Field jvm = runtime.getClass().getDeclaredField("jvm");
>
>         jvm.setAccessible(true);
>
>
>
>         VMManagement management = (VMManagement) jvm.get(runtime);
>
>         Method method =
> management.getClass().getDeclaredMethod("getProcessId");
>
>         method.setAccessible(true);
>
>
>
>         return (Integer) method.invoke(management);
>
>     }
>
>     public static void main(String[] args) throws IOException {
>
>
>
>         BufferedWriter writer =
> Files.newBufferedWriter(Paths.get("C:\\Users\\Pooja.Pandey\\vdrws.log"));
>
>         writer.write("");
>
>         writer.flush();
>
>
>
>         JavaLoggingMultiThTest javaLoggingMultiThTest = new
> JavaLoggingMultiThTest();
>
>         try {
>
>             javaLoggingMultiThTest.pid = getCurrrentProcessId();
>
>         } catch (Exception e) {
>
>             e.printStackTrace();
>
>         }
>
>         javaLoggingMultiThTest.runLoggerTaskMultipleThreads();
>
>     }
>
> }
>
>
>
>
>
>
>
> *From:* Pooja Pandey <[email protected]>
> *Sent:* Friday, March 25, 2022 4:37 AM
> *To:* Log4J Users List <[email protected]>
> *Subject:* Synchronization issue in multithreading (Losing huge data in
> multithreading) with log4j 1.x bridge (2.17.2)
>
>
>
> **** External email: Verify sender before opening attachments or links ****
>
>
>
> Hi,
>
>
>
> In our application we have migrated from log4j1.x to log4j1.x bridge. With
> Log4j1.x there was no issue with multithreading but with log4j 1.x bridge
> we have noticed that in multithreading environment there is a huge data
> loss while logging, however single thread works fine. I see that in
> Category.java which Logger extends; many methods are not synchronized any
> more in log4j1.x bridge however which were in case of log4j1.x. I suspect
> this could be root cause of this multithreading problem. Please let me know
> if you have any idea.
>
>
>
> I have compared Category.java which is a kind of core class for logging
> functionality in Log4j1.x and Log4j1.x bridge and I see that many methods
> which we are using were synchronized in log4j1.x but NOT in log4j1.x
> bridge. I think this could be one of the root causes leading to this
> problem.
>
>
>
>
>
> Log4j1.x:   synchronized public Appender getAppender(String name)
>
> Log4j1.x bridge:     public Appender getAppender(final String name)
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]