[jira] [Commented] (LOG4J2-2589) Potential Memory Leak

["Stefan Höltker (Jira)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/LOG4J2-2589?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17076999#comment-17076999 ] 

Stefan Höltker commented on LOG4J2-2589:
----------------------------------------

Still an error any news to this issue ? 

> Potential Memory Leak 
> ----------------------
>
>                 Key: LOG4J2-2589
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2589
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: API, Appenders, Configurators, Core
>    Affects Versions: 2.11.2
>         Environment: Windows 10
> openjdk version "1.8.0_202"                                                                                            OpenJDK Runtime Environment (AdoptOpenJDK)(build 1.8.0_202-b08)                                    OpenJDK 64-Bit Server VM (AdoptOpenJDK)(build 25.202-b08, mixed mode)
>            Reporter: Stefan Höltker
>            Priority: Major
>         Attachments: 2019-04-12 13_20_45-eclipse-workspace - C__Daten_analyse_ems_prd_20190409_java_pid11448.hprof - Ecli.png, screenshot-1.png
>
>
> We moved our application from a own small logging component to Log4j2.
> The application runs about 60.000 jobs  per day at our biggest installation.
> We write our own Appender wich writes wit Hibernate to our DB (see InnovaIntegrationsportalHibernateAppender).
> After a runtime of ~36h the JVM crashed with OOME, analysing the hprof i saw that there is a amount of 763,5MB of the class org.apache.logging.log4j.core.appender.AbstractManager 
> see screenshot of the Analyse attached (2019-04-12 13_20_45-eclips...)
>  
> Going deeper i tried to reconstruct the behavior in a test class and profiled its result (see screenshot-1).
> Looks like a memory leak to me.
> InnovaIntegrationsportalHibernateAppender
> {code:java}
> package de.itout.innova.log4j.innova_log4j_appender;
> import de.itout.innova.ssp.entities.ssp.entities.*;
> import de.itout.jpa.util.*;
> import java.io.*;
> import java.util.*;
> import javax.persistence.*;
> import org.apache.logging.log4j.core.*;
> import org.apache.logging.log4j.core.appender.*;
> import org.apache.logging.log4j.core.config.plugins.*;
> import org.apache.logging.log4j.core.layout.*;
> /**
>  *
>  * @author swendelmann
>  */
> @Plugin(name = "InnovaIntegrationsportalHibernateAppender", category = "Core", elementType = "appender")
> public class InnovaIntegrationsportalHibernateAppender extends AbstractAppender
> {
>   private String schnittstelle;
>   private String version;
>   private String laufId;
>   private EntityManager em;
>   public InnovaIntegrationsportalHibernateAppender(String name, Filter filter, Layout<? extends Serializable> layout)
>   {
>     super(name, filter, layout);
>   }
>   public InnovaIntegrationsportalHibernateAppender(String name, Filter filter, Layout<? extends Serializable> layout, boolean ignoreExceptions)
>   {
>     super(name, filter, layout, ignoreExceptions);
>   }
>   private InnovaIntegrationsportalHibernateAppender(String name, Filter filter, Layout<? extends Serializable> layout, boolean ignoreExceptions, String schnittstelle, String version, String laufId)
>   {
>     super(name, filter, layout, ignoreExceptions);
>     this.schnittstelle = schnittstelle;
>     this.version = version;
>     this.laufId = laufId;
>   }
>   // Your custom appender needs to declare a factory method
>   // annotated with `@PluginFactory`. Log4j will parse the configuration
>   // and call this factory method to construct an appender instance with
>   // the configured attributes.
>   @PluginFactory
>   public static InnovaIntegrationsportalHibernateAppender createAppender(
>           @PluginAttribute("name") String name,
>           @PluginElement("Layout") Layout<? extends Serializable> layout,
>           @PluginElement("Filter") final Filter filter,
>           @PluginAttribute("schnittstelle") String schnittstelle,
>           @PluginAttribute("version") String version,
>           @PluginAttribute("laufId") String laufId
>   )
>   {
>     if (name == null)
>     {
>       LOGGER.error("No name provided for InnovaIntegrationsportalHibernateAppender");
>       return null;
>     }
>     if (layout == null)
>     {
>       layout = PatternLayout.createDefaultLayout();
>     }
>     if (laufId == null || laufId.isEmpty())
>     {
>       LOGGER.error("No laufid provided for InnovaIntegrationsportalHibernateAppender");
>     }
>     return new InnovaIntegrationsportalHibernateAppender(name, filter, layout, true, schnittstelle, version, laufId);
>   }
>   @Override
>   public void append(LogEvent event)
>   {
>     try
>     {
>       em = JPAUtil.getEntityManager("SSP");
>       em.getTransaction().begin();
>       LauflogPK lauflogPK = new LauflogPK(schnittstelle, version, laufId, getNextLaufLogPos());
>       Lauflog lauflog = new Lauflog(lauflogPK);
>       lauflog.setLevel(event.getLevel().name());
>       Date eventDateTime = new Date(event.getTimeMillis());
>       lauflog.setLastchangeAenderungsdatum(eventDateTime);
>       lauflog.setLastchangeAenderungszeit(eventDateTime);
>       lauflog.setLastchangeBenutzer("WENDELMANN");
>       lauflog.setLastchangeLogflag('A');
>       lauflog.setText(event.getMessage().getFormattedMessage());
>       em.persist(lauflog);
>       em.getTransaction().commit();
>     }
>     catch (Throwable t)
>     {
>       em.getTransaction().rollback();
>       LOGGER.error("Cant commit to Database InnovaIntegrationsportalHibernateAppender ", t);
>       //TODO Log to file
>     }
>     finally
>     {
>       try
>       {
>         if (em != null)
>         {
>           em.close();
>         }
>       }
>       catch (Throwable t)
>       {
>         LOGGER.error("Cant close em: ", t);
>       }
>     }
>   }
>   /**
>    * SELECT ISNULL(MAX(POS)+1,0) FROM LAUFLOG
>    * @return 
>    */
>   private int getNextLaufLogPos()
>   {
>     Integer i = (Integer) em.createQuery("SELECT MAX(l.lauflogPK.pos)+1 FROM Lauflog l WHERE l.lauflogPK.schnittstelle = :schnittstelle AND l.lauflogPK.version = :version AND l.lauflogPK.lauf = :lauf ")
>             .setParameter("schnittstelle", this.schnittstelle)
>             .setParameter("version", this.version)
>             .setParameter("lauf", this.laufId)
>             .getSingleResult();
>     if (i == null)
>     {
>       return 0;
>     }
>     else
>     {
>       return i;
>     }
>   }
> }
> {code}
>  
> Test Class for Profiling
> {code:java}
> package de.itout.innova.log4j;
> import de.itout.innova.log4j.innova_log4j_appender.*;
> import de.itout.jpa.util.*;
> import java.io.*;
> import java.nio.charset.*;
> import org.apache.logging.log4j.*;
> import org.apache.logging.log4j.core.*;
> import org.apache.logging.log4j.core.appender.*;
> import org.apache.logging.log4j.core.config.*;
> import org.apache.logging.log4j.core.layout.*;
> import org.junit.*;
> /**
>  *
>  * @author swendelmann
>  */
> public class ProfilingTest
> {
>   QEntityManager em;
>   private org.apache.logging.log4j.Logger logg = LogManager.getLogger();
>   // Potential memory leak
>   final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
>   public ProfilingTest()
>   {
>   }
>   @Before
>   public void setUp()
>   {
>     em = JPAUtil.getEntityManager("SSP");
>   }
>   @After
>   public void tearDown()
>   {
>     em.close();
>   }
>   @Test
>   public void testProfiling()
>   {
>     logg.trace("Start the Main Method");
>     int runs = 1000;
>     int logs = 10;
>     String allSicherungsVerzeichnis = "target/sicherungsverzeichnis/";
>     logg.debug("Start Test mit " + runs + " durchläufen");
>     for (int i = 0; i < runs; i++)
>     {
>       String laufid = "LD0" + i;
>       File laufLogFile = new File(allSicherungsVerzeichnis + laufid + "_full.log");
>       Configuration config = ctx.getConfiguration();
>       // Full File Logger
>       Layout layout = PatternLayout.newBuilder()
>         .withConfiguration(config)
>         .withPattern(PatternLayout.SIMPLE_CONVERSION_PATTERN)
>         .withCharset(Charset.forName("UTF-8"))
>         .build();
>       Appender fullAppender = FileAppender.newBuilder()
>         .setConfiguration(config)
>         .setName(laufid + "FULL")
>         .withFileName(laufLogFile.getAbsolutePath())
>         .withAppend(true)
>         .withImmediateFlush(true)
>         .setIgnoreExceptions(false)
>         .setLayout(layout)
>         .build();
>       fullAppender.start();
>       config.addAppender(fullAppender);
>       // Hibernate Logger
>       Appender appender = InnovaIntegrationsportalHibernateAppender.createAppender(laufid, null, null, "LISA_4711", "LI0001", laufid);
>       appender.start();
>       AppenderRef ref = AppenderRef.createAppenderRef(laufid, Level.ALL, null); // HIER LOGLEVEL DB EINSTELLEN
>       AppenderRef refFull = AppenderRef.createAppenderRef(laufid + "FULL", Level.ALL, null); // HIER LOGLEVEL Datei einstellen
>       AppenderRef[] refs = new AppenderRef[]
>       {
>         ref, refFull
>       };
>       LoggerConfig loggerConfig = LoggerConfig
>         .createLogger(false, Level.ALL, laufid, "true", refs, null, config, null);
>       loggerConfig.addAppender(appender, Level.ALL, null); // HIER LOGLEVEL ebenfalls einstellen
>       loggerConfig.addAppender(fullAppender, Level.ALL, null); // HIER LOGLEVEL Datei einstellen
>       config.addLogger(laufid, loggerConfig);
>       ctx.updateLoggers();
>       org.apache.logging.log4j.Logger log = LogManager.getLogger(laufid);
>       for (int j = 0; j < logs; j++)
>       {
>         log.info("Ich bin nur eine Info und soll nur in das FullFile logging!");
>         log.warn("Ich bin ein böser warning und soll in das FullFile und in das Innova Integrationsportal Hibernate Logging");
>       }
>       appender.stop();
>       fullAppender.stop();
>       config.removeLogger(laufid);
>       config.removeLogger(laufid + "FULL");
>       ctx.updateLoggers();
>     }
>     logg.trace("Fertig");
>   }
> }
> {code}
>  



--
This message was sent by Atlassian Jira
(v8.3.4#803005)