Predeployment of PersistenceUnit that using Log4j as session logger failed by EckelDong · Pull Request #198 · apache/logging-log4j2

EckelDong · 2018-08-01T12:20:32Z

Environment Details

GlassFish Version (and build number): 5.0
JDK version: 1.8.0_152
OS: CentOS 7
Eclipse Link: 2.7.0
Log4j: 2.11.1

Problem Description

I hava A and B machines. DAS is running on machine A, and the standalone instance managed by DAS is running on machine B. When I deploy a EAR package, I got error from DAS(not standalone):

[2018-08-01T19:40:42.950+0800] [glassfish 5.0] [SEVERE] [NCLS-CORE-00026] [javax.enterprise.system.core] [tid: _ThreadID=42 _ThreadName=admin-listener(4)] [timeMillis: 1533123642950] [levelValue: 1000] [[
  Exception during lifecycle processing
javax.persistence.PersistenceException: Exception [EclipseLink-28018] (Eclipse Persistence Services - 2.7.0.v20170811-d680af5): org.eclipse.persistence.exceptions.EntityManagerSetupException
Exception Description: Predeployment of PersistenceUnit [JPA_UNIT] failed.
Internal Exception: java.util.ServiceConfigurationError: org.apache.logging.log4j.util.PropertySource: Provider org.apache.logging.log4j.util.EnvironmentPropertySource not a subtype
	at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.createPredeployFailedPersistenceException(EntityManagerSetupImpl.java:2080)
	at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.predeploy(EntityManagerSetupImpl.java:2071)
	at org.eclipse.persistence.jpa.PersistenceProvider.createContainerEntityManagerFactoryImpl(PersistenceProvider.java:347)
	at org.eclipse.persistence.jpa.PersistenceProvider.createContainerEntityManagerFactory(PersistenceProvider.java:313)
	at org.glassfish.persistence.jpa.PersistenceUnitLoader.loadPU(PersistenceUnitLoader.java:199)
	at org.glassfish.persistence.jpa.PersistenceUnitLoader.<init>(PersistenceUnitLoader.java:107)
	at org.glassfish.persistence.jpa.JPADeployer$1.visitPUD(JPADeployer.java:223)
	at org.glassfish.persistence.jpa.JPADeployer$PersistenceUnitDescriptorIterator.iteratePUDs(JPADeployer.java:510)
	at org.glassfish.persistence.jpa.JPADeployer.createEMFs(JPADeployer.java:230)
	at org.glassfish.persistence.jpa.JPADeployer.prepare(JPADeployer.java:168)
	at com.sun.enterprise.v3.server.ApplicationLifecycle.prepareModule(ApplicationLifecycle.java:925)
	at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:434)
	at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:219)
	at org.glassfish.deployment.admin.DeployCommand.execute(DeployCommand.java:491)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:540)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:536)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:360)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$2.execute(CommandRunnerImpl.java:535)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$3.run(CommandRunnerImpl.java:566)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$3.run(CommandRunnerImpl.java:558)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:360)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:557)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:1465)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl.access$1300(CommandRunnerImpl.java:110)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1847)
	at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1723)
	at org.glassfish.admin.rest.utils.ResourceUtil.runCommand(ResourceUtil.java:254)
	at org.glassfish.admin.rest.utils.ResourceUtil.runCommand(ResourceUtil.java:232)
	at org.glassfish.admin.rest.utils.ResourceUtil.runCommand(ResourceUtil.java:276)
	at org.glassfish.admin.rest.resources.TemplateListOfResource.createResource(TemplateListOfResource.java:134)
	at sun.reflect.GeneratedMethodAccessor1880.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:200)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
	at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer.service(GrizzlyHttpContainer.java:377)
	at org.glassfish.admin.rest.adapter.RestAdapter$2.service(RestAdapter.java:316)
	at org.glassfish.admin.rest.adapter.RestAdapter.service(RestAdapter.java:179)
	at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:463)
	at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:168)
	at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:206)
	at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:180)
	at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:242)
	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112)
	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
	at org.glassfish.grizzly.portunif.PUFilter.handleRead(PUFilter.java:231)
	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112)
	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
	at org.glassfish.grizzly.portunif.PUFilter.handleRead(PUFilter.java:231)
	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112)
	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:539)
	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:593)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:573)
	at java.lang.Thread.run(Thread.java:748)

Steps to reproduce

EAR package:
--lib
----entity.jar
--------META-INF/persistence.xml
--ejb.jar
----log4j2.xml
--web.war
----WEB-INF/web.xml
persistence.xml

<?xml version="1.0" encoding="UTF-8"?>
<persistence version="2.1" xmlns="http://xmlns.jcp.org/xml/ns/persistence"
             xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:schemaLocation="http://xmlns.jcp.org/xml/ns/persistence http://xmlns.jcp.org/xml/ns/persistence/persistence_2_1.xsd">
    <persistence-unit name="JPA_UNIT" transaction-type="JTA">
        <provider>org.eclipse.persistence.jpa.PersistenceProvider</provider>
        <jta-data-source>jdbc/datacenter_jta_ds</jta-data-source>
        <non-jta-data-source>jdbc/datacenter_non_jta_ds</non-jta-data-source>
        <shared-cache-mode>NONE</shared-cache-mode>
        <properties>
            <property name="eclipselink.weaving" value="static"/>
            <property name="eclipselink.logging.level" value="ALL"/>
            <!--<property name="eclipselink.logging.parameters" value="false"/>-->
            <property name="eclipselink.logging.logger" value="org.jetmind.javakit.logging.eclipselink.Log4jSessionLog"/>
        </properties>
    </persistence-unit>

</persistence>

Log4jSessionLog.java

package org.jetmind.javakit.logging.eclipselink;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.eclipse.persistence.internal.databaseaccess.Accessor;
import org.eclipse.persistence.internal.sessions.AbstractSession;
import org.eclipse.persistence.logging.AbstractSessionLog;
import org.eclipse.persistence.logging.SessionLog;
import org.eclipse.persistence.logging.SessionLogEntry;

import java.util.HashMap;
import java.util.Map;

public class Log4jSessionLog extends AbstractSessionLog {
    private final Level[] log4jLevels = new Level[]{Level.ALL, Level.TRACE, Level.TRACE, Level.DEBUG, Level.INFO, Level.INFO, Level.WARN, Level.ERROR, Level.OFF};

    private Map<String, String> loggerNameMap = new HashMap<>();

    public Log4jSessionLog() {
        String namespace = "org.eclipse.persistence";

        loggerNameMap.put(null, namespace + ".default");
        for (String category : SessionLog.loggerCatagories) loggerNameMap.put(category, namespace + "." + category);
    }

    @Override
    public void log(SessionLogEntry entry) {
        LogManager.getLogger(loggerNameMap.get(entry.getNameSpace())).log(log4jLevels[entry.getLevel()], () -> buildMessage(entry), entry.getException());
    }

    private String buildMessage(SessionLogEntry entry) {
        StringBuilder buf = new StringBuilder();

        Accessor connection = entry.getConnection();
        boolean printConnection = shouldPrintConnection() && connection != null;

        AbstractSession session = entry.getSession();
        if (shouldPrintSession() && session != null) {
            buf.append("[").append(session.getSessionTypeString()).append("(").append(System.identityHashCode(session)).append(")");
            if (printConnection) {
                buf.append(",");
                appendConnection(buf, connection);
            }
            buf.append("]");
        } else if (printConnection) {
            buf.append("[");
            appendConnection(buf, connection);
            buf.append("]");
        }

        buf.append(formatMessage(entry));

        return buf.toString();
    }

    private void appendConnection(StringBuilder buf, Accessor connection) {
        buf.append(AbstractSessionLog.CONNECTION_STRING).append("(");
        buf.append(System.identityHashCode(connection.getDatasourceConnection() == null ? connection : connection.getDatasourceConnection()));
        buf.append(")");
    }
}

by the way, prior to 2.9.0, it's work fine

garydgregory · 2018-08-01T16:08:23Z

I applied your patch to git master and release-2.x. Please verify and close. The JIRA ticket is https://issues.apache.org/jira/browse/LOG4J2-2397

session logger failed (Closes #198).

raducoravu · 2018-09-24T10:42:13Z

@garydgregory Having the same "Provider org.apache.logging.log4j.util.EnvironmentPropertySource not a subtype" problem when loading the log4j libraries on two different class loaders, from what I tested this fix seems to also fix my problem.
Could you give me an estimate as to when this fix will be incorporated in a released version (I'm assuming log4j-2.11.2)?

garydgregory · 2018-11-06T02:33:41Z

@raducoravu,
You can pick up SNAPSHOT builds from the Apache Snapshot repository anytime. For the actual release, it might happen during or after the US Thanksgiving holiday but that is only a guess. Since we are all volunteers with busy schedules and the release process is somewhat ponderous, it might or might not happen in that timeframe. @rgoers, any thoughts ?

ba94cfc

EckelDong closed this Aug 2, 2018

asfgit pushed a commit that referenced this pull request Aug 3, 2018

[LOG4J2-2397] Predeployment of PersistenceUnit that using Log4j as

cb41936

session logger failed (Closes #198).

asfgit pushed a commit that referenced this pull request Aug 3, 2018

[LOG4J2-2397] Predeployment of PersistenceUnit that using Log4j as

1b54723

session logger failed (Closes #198).

vorburger mentioned this pull request Dec 23, 2021

release 2.x clean slf4j javadoc #652

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Predeployment of PersistenceUnit that using Log4j as session logger failed#198

Predeployment of PersistenceUnit that using Log4j as session logger failed#198
EckelDong wants to merge 1 commit intoapache:masterfrom
EckelDong:master

EckelDong commented Aug 1, 2018

Uh oh!

garydgregory commented Aug 1, 2018

Uh oh!

raducoravu commented Sep 24, 2018

Uh oh!

garydgregory commented Nov 6, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Uh oh!

Conversation

EckelDong commented Aug 1, 2018

Environment Details

Problem Description

Steps to reproduce

Uh oh!

garydgregory commented Aug 1, 2018

Uh oh!

raducoravu commented Sep 24, 2018

Uh oh!

garydgregory commented Nov 6, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants