2

[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".

Lars-Erik
  • 301
  • 3
  • 17
  • The stack track says that problem in the 'id' field. It looks like your DB has a numeric field but your class field type is String. – OleksiiMLD Oct 07 '20 at 07:25
  • yes, are you sure your ID in db is varchar/text types? this error normally happen if you have wrong mapping as well, you can check this https://stackoverflow.com/questions/14089233/hibernate-illegalargumentexception-occurred-calling-getter-of-a-class – Sam YC Oct 07 '20 at 07:41
  • @SamYC I'm sure. I can see that the DB column is created as "varchar(255) not null". As mentioned in the OP it works when I run it in a unit test in the .database module, but not when integrated with Spring. There is a difference in what happens when search for tracked entity is done deep inside Hibernate / Spring services. – Lars-Erik Oct 07 '20 at 07:56
  • I added the DB log to show that the ID-field is indeed varchar in the db. May get a chance to post more about the internal stuff that I found after office hours today. – Lars-Erik Oct 07 '20 at 08:03
  • 1
    The only difference I can see is, in your `web` module, there is a missing file `chat.hbm.xml`, you have it in the `database` module but not `web`, probably you can put it in and try again. – Sam YC Oct 07 '20 at 11:02
  • I could do that, @SamYC, but I'm fairly sure Hibernate wouldn't have created the table (as you can see from the log I added) without finding the HBM? :P – Lars-Erik Oct 07 '20 at 11:11
  • 1
    somehow you don't re-define `hibernate-core` in your `web` but you re-define your `sqlite-dialect` and `sqlite-jdbc` both at `web` and `database`, any reason? You probably need to run maven dependency tree checking on your `web` to see any library conflict. – Sam YC Oct 07 '20 at 11:19
  • @SamYC I juse sqllite-jdbc to create the database file without touching hibernate. Hibernate is bundled with both the database package dependency and the spring(-boot?) dependency. However, it has to be 5.1 otherwise we're faced with a MethodNotFound exception instead due to dual hibernate versions. If I knew how to make spring (web) use a newer version than the bundled one I think it would solve everything. – Lars-Erik Oct 07 '20 at 13:14
  • 1
    @Lars-Erik can you run this `mvn dependency:tree -Dverbose` in your `web` module and post the result? this can find out what is the conflict. – Sam YC Oct 07 '20 at 13:36
  • https://gist.github.com/lars-erik/a16941bf5d10e3b56262941ad959dee8 // @SamYC – Lars-Erik Oct 07 '20 at 13:40
  • 1
    Oh my, finally had a chance to look over that tree. It seems I might have gone and "assumed" again. I was convinced Spring *something* had a dependency on Hibernate. According to the tree it's the SQLite dialect package I pulled. That one should be simple to replace with bare code. Will give it a shot hopefully tomorrow evening. Thanks for now, @SamYC. – Lars-Erik Oct 07 '20 at 21:08
  • *Sigh* I had so high hopes. Still no cigar when I've copied the sqldialect project. I now run Hibernate 5.4.22.Final. I'll see about debugging it more later. I keep pressing F8 too early and get thrown to an outer catch clause. Suddenly back. // @SamYC – Lars-Erik Oct 08 '20 at 18:39
  • 1
    @Lars-Erik You have to do clean install again by using `mvn clean install`. I check out your code, and run mvn dependency check, I got different result. Your dependency tree show that you are using `org.hibernate:hibernate-core:jar:5.4.22` in your database module, which is already wrong, it is not the same compare to what you define in your database module, which is `5.1.0.Final`, which mean that you have `mvn install` `5.4.22` version before. I suggest you double check which hibernate version which is working actually in your database module and do a new clean install. – Sam YC Oct 09 '20 at 02:42
  • 1
    Once you got your database module work again, you can define your exact hibernate dependency version in your web module. Maven resolve the dependency based on "first come first serve" basis, so you just need to explicitly define hibernate before `com.github.gwenn:sqlite-dialect:jar` in your pom.xml will do. – Sam YC Oct 09 '20 at 02:44
  • Sorry, @SamYC. I didn't push it. Updated now. Will try clean install later, but still convinced it's because of a different service used deep down. – Lars-Erik Oct 09 '20 at 09:05
  • @Lars-Erik ok your latest code make more sense, if your database module is really working fine, it is using hibernate `5.4.22.Final`, and your web module is using `5.1.0`. You can align this and try again, in your `web` module pom.xml, move up the dependency `chatroom.database` before ` sqlite-dialect` will do. – Sam YC Oct 09 '20 at 10:00
  • @SamYC There should be no trace of 5.1 now. Here's the sqlite dialect pom: https://github.com/lars-erik/hiof-sweat2020-chatroom-demo/blob/fceb36d0d4645101dfd3520c1f44d2c02dcdaec4/src/sqllite-dialect/pom.xml#L47 The version conflict caused a MethodNotFound. The "main" problem still persists. (The id prop reflection) – Lars-Erik Oct 09 '20 at 10:20
  • Finally got to the bottom of the call stack where it fails. It doesn't seem to be "different" than when ran through the test. However, I start to recognize the "pattern". In .net which I'm used to, this could be caused by having two versions of an assembly, but with different metadata. So it might well be me who don't know well enough how to put together maven modules. See new edit at bottom of OP. // @SamYC – Lars-Erik Oct 09 '20 at 17:39
  • 1
    I'm getting closer to something. Pushed another commit now. It seems working with the multi module maven dependencies is total chaos. Sometimes they end up in .m2, sometimes not. Right now nothing goes there. Validating the .web module fails to find the two module dependencies. I've bumped the core module version in order to make sure it doesn't think the id field should be a UUID like it was in early commits. Still no success and still the same runtime error in the web project. ‍♂️ Really appreciate the help. Can't be far away now. Must just be something with the maven setup. // @SamYC – Lars-Erik Oct 10 '20 at 12:05
  • 1
    @Lars-Erik Glad to hear if it is maven issue, should be easier compare to Spring with hibernate integration compatibility issue... – Sam YC Oct 11 '20 at 16:31
  • I think I have a correct maven setup with a parent and everything. Only dependency from web is database. But I still have two versions of the class. – Lars-Erik Oct 11 '20 at 18:59
  • 1
    HA! Got it! It was spring-boot-devtools all along. It creates another classloader to restart quickly. Hence the mentioned class loader name in the OP. I'll go ahead and answer / dupe my question, tho I wish I could give you the answer points, @SamYC. Thanks a lot for sticking with me through this crazy journey. – Lars-Erik Oct 11 '20 at 19:18
  • 1
    Glad you found the root cause, I have learnt something too along the way. – Sam YC Oct 12 '20 at 02:49

1 Answers1

3

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

Lars-Erik
  • 301
  • 3
  • 17