javaspringspring-boothibernatespring-boot-devtools

Saving entities with Hibernate 5.1 and Spring 5.2.9 fails to save entity (spring-boot 2.3.4, spring-boot-devtools)


[Edit: fixed spring version in q to 5.2.9. v2.3.4 is the aggregated maven dep.]

I've gone through heaps of posts to try to figure this out. Seems like there's a huge compatibility issue, but I can't figure out which versions to change to. I don't do Java normally, but have to when teaching, so hoping someone will ignore my non-existant Java-skills and bless me with some advice. 🤷‍♂️🙏

If I step through disassembled code, I can see that my unit tests (integrated) does something else when trying to reflect my ID property than what is done when ran with Spring.

[Edit] Here's the SQL log:

Hibernate: create table ChatMessages (Id varchar(255) not null, UserName varchar(50), Message varchar(512), primary key (Id))
2020-10-07 10:01:15.142  INFO 43304 --- [nio-8081-exec-8] o.h.h.i.QueryTranslatorFactoryInitiator  : HHH000397: Using ASTQueryTranslatorFactory
Hibernate: select chatmessag0_.Id as Id1_0_, chatmessag0_.UserName as UserName2_0_, chatmessag0_.Message as Message3_0_ from ChatMessages chatmessag0_

Here's the exception and the top of the trace:

[nio-8081-exec-6] o.h.p.access.spi.GetterMethodImpl        : HHH000122: IllegalArgumentException in class: org.hiof.chatroom.core.ChatMessage, getter method of property: id
2020-10-07 02:28:59.438 ERROR 47504 --- [nio-8081-exec-6] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.hibernate.PropertyAccessException: IllegalArgumentException occurred calling getter of org.hiof.chatroom.core.ChatMessage.id] with root cause

java.lang.IllegalArgumentException: object is not an instance of declaring class
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_172]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_172]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_172]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_172]
    at org.hibernate.property.access.spi.GetterMethodImpl.get(GetterMethodImpl.java:41) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.tuple.entity.AbstractEntityTuplizer.getIdentifier(AbstractEntityTuplizer.java:223) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.getIdentifier(AbstractEntityPersister.java:4633) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.id.Assigned.generate(Assigned.java:32) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.event.internal.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:105) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.event.internal.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:192) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.event.internal.DefaultSaveEventListener.saveWithGeneratedOrRequestedId(DefaultSaveEventListener.java:38) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.event.internal.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:177) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.event.internal.DefaultSaveEventListener.performSaveOrUpdate(DefaultSaveEventListener.java:32) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.event.internal.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:73) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.internal.SessionImpl.fireSave(SessionImpl.java:682) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.internal.SessionImpl.save(SessionImpl.java:674) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hibernate.internal.SessionImpl.save(SessionImpl.java:669) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final]
    at org.hiof.chatroom.database.ChatMessageRepository.add(ChatMessageRepository.java:21) ~[classes/:na]

It's a super simple DB setup with SQL Lite.

The only entity is mapped as such:

<class name="org.hiof.chatroom.core.ChatMessage" table="ChatMessages">
    <id name="id" column="Id">
        <generator class="assigned"/>
    </id>
    <property name="user" column="UserName" length="50"/>
    <property name="message" column="Message" length="512"/>
</class>

And the entity:

public class ChatMessage {
    private String id;
    private String user;
    private String message;

    public String getId() {
        return id;
    }

    public void setId(String id) {
        this.id = id;
    }

    public String getUser() {
        return user;
    }

    public void setUser(String user) {
        this.user = user;
    }

    public String getMessage() {
        return message;
    }

    public void setMessage(String message) {
        this.message = message;
    }
}

Here's a test that goes through with no different infrastructure and config than (not) having Spring running the application:

public class When_persisting_chat_messages {
    @Test
    public void stores_message() throws Exception {
        DatabaseManager.ensureDatabase("./db/chat-test.db");
        UnitOfWork uow = new UnitOfWork();
        ChatMessageRepository repo = new ChatMessageRepository(uow);
        ChatMessage msg = new ChatMessage();
        String id = UUID.randomUUID().toString();
        msg.setId(id);
        repo.add(msg);
        uow.saveChanges();
        uow.close();
        uow = new UnitOfWork();
        repo = new ChatMessageRepository(uow);
        msg = repo.get(id);
        Assertions.assertNotNull(msg);
    }
}

I'm fairly sure it has to do with the StandardServiceRegistryBuilder involved in setting up the session factory in my UOW. No idea what to do tho.

It's way too late and I was hoping to demo this for some students tomorrow, so I apologize if I left this post a bit off the prefered standards of SO.

[Edit]
Repo is published here: https://github.com/lars-erik/hiof-sweat2020-chatroom-demo

[Edit after 2 days]
I managed to pin down the place it throws when ran in the web project. For a dotnet developer like me, this smells like two versions of my core "assembly" (module) is loaded into the "domain" and the ID property is read from the "wrong module's metadata". No idea tho, but that's how it seems. In the getIdentifier method, both owner and idGetter points to the same class, org.hiof.chatroom.core.ChatMessage. Yet the invoke insists the instance is not the id getter's declaring class. Here's the trace:

get:42, GetterMethodImpl (org.hibernate.property.access.spi)
getIdentifier:230, AbstractEntityTuplizer (org.hibernate.tuple.entity)
getIdentifier:5155, AbstractEntityPersister (org.hibernate.persister.entity)
generate:31, Assigned (org.hibernate.id)
saveWithGeneratedId:115, AbstractSaveEventListener (org.hibernate.event.internal)
saveWithGeneratedOrRequestedId:194, DefaultSaveOrUpdateEventListener (org.hibernate.event.internal)
saveWithGeneratedOrRequestedId:38, DefaultSaveEventListener (org.hibernate.event.internal)
entityIsTransient:179, DefaultSaveOrUpdateEventListener (org.hibernate.event.internal)
performSaveOrUpdate:32, DefaultSaveEventListener (org.hibernate.event.internal)
onSaveOrUpdate:75, DefaultSaveOrUpdateEventListener (org.hibernate.event.internal)
accept:-1, 1659093435 (org.hibernate.internal.SessionImpl$$Lambda$541)
fireEventOnEachListener:102, EventListenerGroupImpl (org.hibernate.event.service.internal)
fireSave:636, SessionImpl (org.hibernate.internal)
save:629, SessionImpl (org.hibernate.internal)
save:624, SessionImpl (org.hibernate.internal)

[Edit oct. 11.] Debugging currently shows two versions of the ChatMessage class when ran with spring. :/

owner.getClass() = {Class@9587} "class org.hiof.chatroom.core.ChatMessage"
owner.getClass() == getterMethod.getDeclaringClass() = false
org.hiof.chatroom.core.ChatMessage.class = {Class@8446} "class org.hiof.chatroom.core.ChatMessage"
getterMethod.getDeclaringClass() = {Class@8446} "class org.hiof.chatroom.core.ChatMessage"

The owner's class' classloader is "RestartClassLoader", while the declaring one is "Launcher$AppClassLoader".


Solution

  • This was caused by spring-boot-devtools. It creates a classloader called RestartClassLoader to speed up restarts. However, it messes with Hibernate's metadata reflection giving two instances of the same type when we get to id reflection.

    So this ends up being somewhat of a dupe of this and a few others:
    Classes loaded by different Classloaders in Spring Boot and Logback