hibernate-mapping ClassNotFoundException

[danwin]

Hello,

the deployment of a web project with a hibernate-mapping runs into a ClassNotFoundException

2010-09-11 10:15:41,575 ERROR [org.jboss.kernel.plugins.dependency.AbstractKernelController] (HDScanner) Error installing to Start: name=persistence.unit:unitName=#timetracker-persistence state=Create
javax.persistence.PersistenceException: [PersistenceUnit: timetracker-persistence] class or package not found
    at org.hibernate.ejb.Ejb3Configuration.addNamedAnnotatedClasses(Ejb3Configuration.java:1067)
    ...
Caused by: java.lang.ClassNotFoundException: timetracker.impl.ProjectImpl from BaseClassLoader@...
...
DEPLOYMENTS IN ERROR:
  Deployment "persistence.unit:unitName=#timetracker-persistence" is in error due to the following reason(s): java.lang.ClassNotFoundException: timetracker.impl.ProjectImpl

The class that cannot be found is referenced by my hbm.xml

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping auto-import="false">

    <class name="timetracker.impl.ProjectImpl" table="`project`">

        <id type="long" name="e_id" column="e_id" access="org.eclipse.emf.teneo.hibernate.mapping.identifier.IdentifierPropertyHandler">
            <meta attribute="syntheticId">true</meta>
            <generator class="native"/>
        </id>

        <property name="bezeichnung" lazy="false" insert="true" update="true" not-null="false" unique="false" type="java.lang.String">
            <column not-null="false" unique="false" name="`bezeichnung`"/>
        </property>
        
        <property name="nummer" lazy="false" insert="true" update="true" not-null="false" unique="false" type="java.lang.String">
            <column not-null="false" unique="false" name="`nummer`"/>
        </property>
    </class>

</hibernate-mapping>

The class is existing at the deployed war. Why the class cannot be found? May it be caused by wrong class loading order?

Thanks,

Daniel

[danwin]

The hbm.xml described above gets processed correctly:

2010-09-12 12:10:52,790 DEBUG [org.hibernate.cfg.AnnotationConfiguration] (HDScanner) Process hbm files
2010-09-12 12:10:52,790 INFO  [org.hibernate.cfg.HbmBinder] (HDScanner) Mapping class: timetracker.impl.ProjectImpl -> project
2010-09-12 12:10:52,790 DEBUG [org.hibernate.cfg.HbmBinder] (HDScanner) Mapped property: e_id -> e_id
2010-09-12 12:10:52,790 DEBUG [org.hibernate.cfg.HbmBinder] (HDScanner) Mapped property: bezeichnung -> bezeichnung
2010-09-12 12:10:52,790 DEBUG [org.hibernate.cfg.HbmBinder] (HDScanner) Mapped property: nummer -> nummer

Furthermore the debug log about the startup of the persistence-unit indicates correct classpath settings (root WEB-INF/classes where timetracker.impl.ProjectImpl resides):

2010-09-12 12:10:52,743 DEBUG [org.hibernate.ejb.Ejb3Configuration] (HDScanner) Processing PersistenceUnitInfo [
     name: timetracker-persistence
     persistence provider classname: org.hibernate.ejb.HibernatePersistence
     classloader: BaseClassLoader@69e49f{vfszip:/D:/Entwicklung/jboss-5.1.0.GA/server/default/deploy/timetracker.war/}
     Temporary classloader: null
     excludeUnlistedClasses: false
     JTA datasource: org.jboss.resource.adapter.jdbc.WrapperDataSource@19f20e5
     Non JTA datasource: null
     Transaction type: JTA
     PU root URL: vfszip:/D:/Entwicklung/jboss-5.1.0.GA/server/default/deploy/timetracker.war/WEB-INF/classes/

BUT, still I get the ClassNotFoundException! Why?

There is a warning that may stick together with the error:

2010-09-12 12:10:52,759 WARN  [org.hibernate.ejb.Ejb3Configuration] (HDScanner) Persistence provider caller does not implements the EJB3 spec correctly. PersistenceUnitInfo.getNewTempClassLoader() is null.

[jaikiran]

Please post the (exact) entire exception stacktrace. Also post the output of:

jar -tf timetracker.war

And which version of JBoss AS is this? Looking at the logs, it appears to be 5.1.0. Is that right?

Daniel Winz wrote:

There is a warning that may stick together with the error:

2010-09-12 12:10:52,759 WARN  [org.hibernate.ejb.Ejb3Configuration] (HDScanner) Persistence provider caller does not implements the EJB3 spec correctly. PersistenceUnitInfo.getNewTempClassLoader() is null.

You can ignore that log message.

[danwin]

Yes I am runnning JBoss 5.1.0 AS.

Output of "jar -tf timetracker.war":

META-INF/MANIFEST.MF
META-INF/
WEB-INF/
WEB-INF/classes/
WEB-INF/classes/META-INF/
WEB-INF/classes/META-INF/persistence.xml
WEB-INF/classes/timetracker/
WEB-INF/classes/timetracker/Operator.java
WEB-INF/classes/timetracker/Project.java
WEB-INF/classes/timetracker/TimetrackerFactory.java
WEB-INF/classes/timetracker/TimetrackerPackage.java
WEB-INF/classes/timetracker/impl/
WEB-INF/classes/timetracker/impl/OperatorImpl.java
WEB-INF/classes/timetracker/impl/ProjectImpl.java
WEB-INF/classes/timetracker/impl/TimetrackerBean.java
WEB-INF/classes/timetracker/impl/TimetrackerFactoryImpl.java
WEB-INF/classes/timetracker/impl/TimetrackerPackageImpl.java
WEB-INF/classes/timetracker/impl/TimetrackerService.java
WEB-INF/classes/timetracker/impl/OperatorImpl.class
WEB-INF/classes/timetracker/impl/ProjectImpl.class
WEB-INF/classes/timetracker/impl/TimetrackerBean.class
WEB-INF/classes/timetracker/impl/TimetrackerFactoryImpl.class
WEB-INF/classes/timetracker/impl/TimetrackerPackageImpl.class
WEB-INF/classes/timetracker/impl/TimetrackerService.class
WEB-INF/classes/timetracker/util/
WEB-INF/classes/timetracker/util/TimetrackerAdapterFactory.java
WEB-INF/classes/timetracker/util/TimetrackerSwitch.java
WEB-INF/classes/timetracker/util/TimetrackerAdapterFactory$1.class
WEB-INF/classes/timetracker/util/TimetrackerAdapterFactory.class
WEB-INF/classes/timetracker/util/TimetrackerSwitch.class
WEB-INF/classes/timetracker/validation/
WEB-INF/classes/timetracker/validation/OperatorValidator.java
WEB-INF/classes/timetracker/validation/ProjectValidator.java
WEB-INF/classes/timetracker/validation/OperatorValidator.class
WEB-INF/classes/timetracker/validation/ProjectValidator.class
WEB-INF/classes/timetracker/Operator.class
WEB-INF/classes/timetracker/Project.class
WEB-INF/classes/timetracker/TimetrackerFactory.class
WEB-INF/classes/timetracker/TimetrackerPackage$Literals.class
WEB-INF/classes/timetracker/TimetrackerPackage.class
WEB-INF/classes/persistence/
WEB-INF/classes/persistence/TestTimetrackerPersistence.java
WEB-INF/classes/persistence/TestTimetrackerPersistence.class
WEB-INF/classes/ProjectImpl.hbm.xml
WEB-INF/faces-config.xml
WEB-INF/lib/
WEB-INF/web.xml

Exception stacktrace:

2010-09-12 12:10:52,790 ERROR [org.jboss.kernel.plugins.dependency.AbstractKernelController] (HDScanner) Error installing to Start: name=persistence.unit:unitName=#timetracker-persistence state=Create
org.hibernate.MappingException: entity class not found: ProjectImpl
    at org.hibernate.ejb.EventListenerConfigurator.configure(EventListenerConfigurator.java:165)
    at org.hibernate.ejb.Ejb3Configuration.configure(Ejb3Configuration.java:847)
    at org.hibernate.ejb.Ejb3Configuration.configure(Ejb3Configuration.java:385)
    at org.hibernate.ejb.HibernatePersistence.createContainerEntityManagerFactory(HibernatePersistence.java:126)
    at org.jboss.jpa.deployment.PersistenceUnitDeployment.start(PersistenceUnitDeployment.java:301)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.reflect.plugins.introspection.ReflectionUtils.invoke(ReflectionUtils.java:59)
    at org.jboss.reflect.plugins.introspection.ReflectMethodInfoImpl.invoke(ReflectMethodInfoImpl.java:150)
    at org.jboss.joinpoint.plugins.BasicMethodJoinPoint.dispatch(BasicMethodJoinPoint.java:66)
    at org.jboss.kernel.plugins.dependency.KernelControllerContextAction$JoinpointDispatchWrapper.execute(KernelControllerContextAction.java:241)
    at org.jboss.kernel.plugins.dependency.ExecutionWrapper.execute(ExecutionWrapper.java:47)
    at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchExecutionWrapper(KernelControllerContextAction.java:109)
    at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchJoinPoint(KernelControllerContextAction.java:70)
    at org.jboss.kernel.plugins.dependency.LifecycleAction.installActionInternal(LifecycleAction.java:221)
    at org.jboss.kernel.plugins.dependency.InstallsAwareAction.installAction(InstallsAwareAction.java:54)
    at org.jboss.kernel.plugins.dependency.InstallsAwareAction.installAction(InstallsAwareAction.java:42)
    at org.jboss.dependency.plugins.action.SimpleControllerContextAction.simpleInstallAction(SimpleControllerContextAction.java:62)
    at org.jboss.dependency.plugins.action.AccessControllerContextAction.install(AccessControllerContextAction.java:71)
    at org.jboss.dependency.plugins.AbstractControllerContextActions.install(AbstractControllerContextActions.java:51)
    at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:348)
    at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1631)
    at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:934)
    at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:1082)
    at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:984)
    at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:774)
    at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:540)
    at org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer.deploy(BeanMetaDataDeployer.java:121)
    at org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer.deploy(BeanMetaDataDeployer.java:51)
    at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.internalDeploy(AbstractSimpleRealDeployer.java:62)
    at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.deploy(AbstractRealDeployer.java:50)
    at org.jboss.deployers.plugins.deployers.DeployerWrapper.deploy(DeployerWrapper.java:171)
    at org.jboss.deployers.plugins.deployers.DeployersImpl.doDeploy(DeployersImpl.java:1439)
    at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:1157)
    at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:1178)
    at org.jboss.deployers.plugins.deployers.DeployersImpl.install(DeployersImpl.java:1098)
    at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:348)
    at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1631)
    at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:934)
    at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:1082)
    at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:984)
    at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:822)
    at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:553)
    at org.jboss.deployers.plugins.deployers.DeployersImpl.process(DeployersImpl.java:781)
    at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeployerImpl.java:702)
    at org.jboss.system.server.profileservice.repository.MainDeployerAdapter.process(MainDeployerAdapter.java:117)
    at org.jboss.system.server.profileservice.hotdeploy.HDScanner.scan(HDScanner.java:362)
    at org.jboss.system.server.profileservice.hotdeploy.HDScanner.run(HDScanner.java:255)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.ClassNotFoundException: timetracker.impl.ProjectImpl from BaseClassLoader@5b38d6{VFSClassLoaderPolicy@f0a755{name=vfsfile:/D:/Entwicklung/jboss-5.1.0.GA/server/default/conf/jboss-service.xml domain=ClassLoaderDomain@17082d8{name=DefaultDomain parentPolicy=BEFORE parent=org.jboss.bootstrap.NoAnnotationURLClassLoader@14c1103} roots=[MemoryContextHandler@24761471[path= context=vfsmemory://5c4o02s-q8vka-gdzqrt41-1-gdzqrxqv-7 real=vfsmemory://5c4o02s-q8vka-gdzqrt41-1-gdzqrxqv-7], DelegatingHandler@23991545[path=hibernate-annotations.jar context=file:/D:/Entwicklung/jboss-5.1.0.GA/server/default/lib/

[jaikiran]

Daniel Winz wrote:

Caused by: java.lang.ClassNotFoundException: timetracker.impl.ProjectImpl from BaseClassLoader@5b38d6{VFSClassLoaderPolicy@f0a755{name=vfsfile:/D:/Entwicklung/jboss-5.1.0.GA/server/default/conf/jboss-service.xml domain=ClassLoaderDomain@17082d8{name=DefaultDomain parentPolicy=BEFORE parent=org.jboss.bootstrap.NoAnnotationURLClassLoader@14c1103} roots=[MemoryContextHandler@24761471[path= context=vfsmemory://5c4o02s-q8vka-gdzqrt41-1-gdzqrxqv-7 real=vfsmemory://5c4o02s-q8vka-gdzqrt41-1-gdzqrxqv-7], DelegatingHandler@23991545[path=hibernate-annotations.jar context=file:/D:/Entwicklung/jboss-5.1.0.GA/server/default/lib/

That last line doesn't look right. It looks like it's not picking up the .war classloader. Can you please post (or attach, if the stacktrace and logs are big) the entire exception stacktrace?

[danwin]

I've just recognized that I now get a

org.hibernate.MappingException

instead of the initial

javax.persistence.PersistenceException

Meanwhile I added "Class-Path: WEB-INF/classes" to the  META-INF/MANIFEST.MF.

[danwin]

Find attached the entire log.

[danwin]

Anyway both exceptions (MappingException and PersistenceException) are

Caused by: java.lang.ClassNotFoundException: timetracker.impl.ProjectImpl from BaseClassLoader@...

[jaikiran]

2010-09-12 12:09:02,358 INFO  [org.hibernate.ejb.Version] (main) Hibernate EntityManager 3.2.0.GA
2010-09-12 12:09:02,436 INFO  [org.hibernate.cfg.annotations.Version] (main) Hibernate Annotations 3.2.0.GA
2010-09-12 12:09:02,451 INFO  [org.hibernate.cfg.Environment] (main) Hibernate 3.3.1.GA

Are you packaging your own version of Hibernate or have you changed the version that's available in JBoss AS? The Hibernate entitymanager and Hibernate annotations versions, that are logged, aren't the same which are shipped by default in AS.

[danwin]

I newly installed jboss to get a clean environment, now a newer version of hibernate is logged, but the error resists ...

2010-09-13 11:14:49,351 INFO  [org.jboss.jpa.deployment.PersistenceUnitDeployment] (main) Starting persistence unit persistence.unit:unitName=#timetracker-persistence
2010-09-13 11:14:49,468 INFO  [org.hibernate.cfg.annotations.Version] (main) Hibernate Annotations 3.4.0.GA
2010-09-13 11:14:49,501 INFO  [org.hibernate.cfg.Environment] (main) Hibernate 3.3.1.GA
2010-09-13 11:14:49,514 INFO  [org.hibernate.cfg.Environment] (main) hibernate.properties not found
2010-09-13 11:14:49,524 INFO  [org.hibernate.cfg.Environment] (main) Bytecode provider name : javassist
2010-09-13 11:14:49,539 INFO  [org.hibernate.cfg.Environment] (main) using JDK 1.4 java.sql.Timestamp handling
2010-09-13 11:14:49,724 INFO  [org.hibernate.annotations.common.Version] (main) Hibernate Commons Annotations 3.1.0.GA
2010-09-13 11:14:49,738 INFO  [org.hibernate.ejb.Version] (main) Hibernate EntityManager 3.4.0.GA
2010-09-13 11:14:49,803 INFO  [org.hibernate.ejb.Ejb3Configuration] (main) Processing PersistenceUnitInfo [
    name: timetracker-persistence
    ...]
2010-09-13 11:14:49,890 WARN  [org.hibernate.ejb.Ejb3Configuration] (main) Persistence provider caller does not implement the EJB3 spec correctly. PersistenceUnitInfo.getNewTempClassLoader() is null.
2010-09-13 11:14:50,050 INFO  [org.hibernate.cfg.HbmBinder] (main) Mapping class: Project -> project
2010-09-13 11:14:50,304 INFO  [org.hibernate.cfg.HbmBinder] (main) Mapping class: Operator -> operator
2010-09-13 11:14:50,308 INFO  [org.hibernate.cfg.HbmBinder] (main) Mapping collection: Operator.project -> operator_project
2010-09-13 11:14:50,394 WARN  [org.hibernate.cfg.AnnotationConfiguration] (main) Unable to apply constraints on DDL for timetracker.impl.OperatorImpl
java.lang.ClassNotFoundException: timetracker.impl.OperatorImpl from BaseClassLoader@1dd040a{VFSClassLoaderPolicy@134329b{name=vfsfile:/D:/Entwicklung/jboss-5.1.0.GA/server/default/conf/jboss-service.xml domain=ClassLoaderDomain@19e733e{name=DefaultDomain

[jaikiran]

Entire logs please.

[danwin]

server.log attached

[danwin]

I've extended log4j settings to DEBUG level for hibernate. Find attached the deployement log.

If I interpret right the classloader that is initially provided for the war (BaseClassLoader@1161d05) differs from the one that tries to load the classes OperatorImpl and ProjectImpl (BaseClassLoader@12bed82) ...

2010-09-13 19:53:08,160 DEBUG [org.hibernate.ejb.Ejb3Configuration] (HDScanner) Processing PersistenceUnitInfo [
    name: timetracker-persistence
    persistence provider classname: org.hibernate.ejb.HibernatePersistence
    classloader: BaseClassLoader@1161d05{vfszip:/D:/Entwicklung/jboss-5.1.0.GA/server/default/deploy/timetracker.war/}
    Temporary classloader: null
    excludeUnlistedClasses: false
    JTA datasource: org.jboss.resource.adapter.jdbc.WrapperDataSource@34ab3e
    Non JTA datasource: null
    Transaction type: JTA
    PU root URL: vfszip:/D:/Entwicklung/jboss-5.1.0.GA/server/default/deploy/timetracker.war/WEB-INF/classes/
    Jar files URLs []
    Managed classes names []
    Mapping files names []
    Properties [
        hibernate.connection.autocommit: false
        hibernate.jndi.java.naming.factory.url.pkgs: org.jboss.naming:org.jnp.interfaces
        hibernate.cache.provider_class: org.hibernate.cache.HashtableCacheProvider
        hibernate.transaction.manager_lookup_class: org.hibernate.transaction.JBossTransactionManagerLookup
        hibernate.jndi.java.naming.factory.initial: org.jnp.interfaces.NamingContextFactory
        hibernate.dialect: org.hibernate.dialect.HSQLDialect
        hibernate.format_sql: true
        hibernate.jacc.ctx.id: timetracker.war
        hibernate.session_factory_name: persistence.unit:unitName=#timetracker-persistence
        hibernate.cache.region_prefix: persistence.unit:unitName=#timetracker-persistence
        hibernate.bytecode.use_reflection_optimizer: false
        hibernate.show_sql: true
        hibernate.bytecode.provider: javassist
        hibernate.connection.release_mode: after_statement]

Error:

2010-09-13 19:53:08,238 WARN  [org.hibernate.cfg.AnnotationConfiguration] (HDScanner) Unable to apply constraints on DDL for timetracker.impl.OperatorImpl
java.lang.ClassNotFoundException: timetracker.impl.OperatorImpl from BaseClassLoader@12bed82{VFSClassLoaderPolicy@f60f20{name=vfsfile:/D:/Entwicklung/jboss-5.1.0.GA/server/default/conf/jboss-service.xml ...

[jaikiran]

Yes, the stacktrace suggests it's using the wrong classloader:

Caused by: java.lang.ClassNotFoundException: timetracker.impl.OperatorImpl from BaseClassLoader@fb78af{VFSClassLoaderPolicy@1b030d8...
    at org.jboss.classloader.spi.base.BaseClassLoader.loadClass(BaseClassLoader.java:448) 
    at java.lang.ClassLoader.loadClass(ClassLoader.java:248) 
    at java.lang.Class.forName0(Native Method) 
    at java.lang.Class.forName(Class.java:247) 
    at org.hibernate.annotations.common.util.ReflectHelper.classForName(ReflectHelper.java:78) 
    at org.hibernate.annotations.common.reflection.java.JavaReflectionManager.classForName(JavaReflectionManager.java:79) 
    at org.hibernate.ejb.EventListenerConfigurator.configure(EventListenerConfigurator.java:181) 
    ... 63 more

The code in org.hibernate.annotations.common.uti.ReflectHelper.classForName looks like this:

public static Class classForName(String name, Class caller) throws ClassNotFoundException {
    try {
      ClassLoader contextClassLoader = Thread.currentThread().getContextClassLoader();
      if (contextClassLoader != null)
        return contextClassLoader.loadClass(name);
    }
    catch (Throwable e)
    {
    }
    return Class.forName(name, true, caller.getClassLoader());
  }

So someone, somewhere is setting the TCCL to null or the real exception is being eaten up without being logged. If you have a debugger, it would be a good idea to see what's going on in that code.

[danwin]

I am new to JBoss. I can remote debug after deployment but I don't have any idea how to debug deployment itself.

But I unlimeted some more log4j settings to DEBUG and got real large logfile (19MB unzipped) ...