Hibernate/JPA - Entity listener not being called properly
Asked Answered
G

3

6

I'm trying to leverage EntityListener objects and callback methods within my Seam/Hibernate/JPA application. I'm using a Seam 2.2-managed persistence context on JBoss 5.1 with PostgreSQL 9.1 on the backend. I have the following entity declared:

@Entity(name = "TestEntity")
@EntityListeners(TestCallback.class)
@Table(name = "tbl_test")
public class TestEntity implements Serializable {

    private static final long serialVersionUID = 2016897066783042092L;

    @Id
    @GeneratedValue(strategy = GenerationType.SEQUENCE, generator = "xxx")
    @SequenceGenerator(name = "xxx", sequenceName = "xxx")
    @Index(name = "xxx")
    @DocumentId
    private Long id = null;

    @Column
    private String test = null;
...
}

along with the following EntityListener callback class:

public class TestCallback {

    /**
     * Logger for this class
     */
    private Log logger = null;

    public TestCallback() {
        logger = Logging.getLog(TestCallback.class);
    }

    @PrePersist
    public void prePersist(TestEntity e) {
        logger.debug("prePersist(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("prePersist(TestEntity) - end"); //$NON-NLS-1$
    }

    @PostPersist
    public void postPersist(TestEntity e) {
        logger.debug("postPersist(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("postPersist(TestEntity) - end"); //$NON-NLS-1$
    }

    @PostLoad
    public void postLoad(TestEntity e) {
        logger.debug("postLoad(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("postLoad(TestEntity) - end"); //$NON-NLS-1$
    }

    @PreUpdate
    public void preUpdate(TestEntity e) {
        logger.debug("preUpdate(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("preUpdate(TestEntity) - end"); //$NON-NLS-1$
    }

    @PostUpdate
    public void postUpdate(TestEntity e) {
        logger.debug("postUpdate(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("postUpdate(TestEntity) - end"); //$NON-NLS-1$
    }

    @PreRemove
    public void preRemove(TestEntity e) {
        logger.debug("preRemove(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("preRemove(TestEntity) - end"); //$NON-NLS-1$
    }

    @PostRemove
    public void postRemove(TestEntity e) {
        logger.debug("postRemove(TestEntity) - start"); //$NON-NLS-1$

        logger.debug("postRemove(TestEntity) - end"); //$NON-NLS-1$
    }
}

When I run my test, however, I do not see all of my callback methods being called as I would expect. I've run tests of the following scenarios:

  • Persisting a new item
  • Updating an existing item
  • Loading an item
  • Deleting an item

However, the only callbacks I see being called are:

  • @PrePersist
  • @PreRemove
  • @PostLoad
  • @PreUpdate

The remaining callbacks do not get executed as expected. Is this the normal behavior? Am I just misunderstanding it? Does this have something to do with the way Seam manages transactions? Or, am I just not doing something right?

I'd appreciate any help you can give.

EDIT: As requested, here is the exact code I'm calling and the output I receive:

Test 1:

public void runTest() {
    logger.debug("runTest() - start"); //$NON-NLS-1$

    TestEntity e = new TestEntity();
    e.setTest("XXX");

    this.entityManager.persist(e);
    this.entityManager.flush();
    this.entityManager.clear();

    logger.debug("runTest() - end"); //$NON-NLS-1$
}

Output 1:

12:27:56,307 INFO  [STDOUT] 29735 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest() - start
12:27:56,312 INFO  [STDOUT] 29740 DEBUG myapp.test.entities.TestCallback  -  - prePersist(TestEntity) - start
12:27:56,312 INFO  [STDOUT] 29740 DEBUG myapp.test.entities.TestCallback  -  - prePersist(TestEntity) - end
12:27:56,347 INFO  [STDOUT] 29775 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest() - end

Test 2:

public void runTest2() {
        logger.debug("runTest2() - start"); //$NON-NLS-1$

        String sql = "SELECT DISTINCT t FROM TestEntity t";
        Query q = this.entityManager.createQuery(sql);

        List<TestEntity> l = q.getResultList();
        for (int i = 0; i < l.size(); i++) {
            String x = l.get(i).getTest();
            logger.debug("runTest2() - String x=" + x); //$NON-NLS-1$
        }

        logger.debug("runTest2() - end"); //$NON-NLS-1$
    }

Output 2:

12:28:36,964 INFO  [STDOUT] 70392 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest2() - start
12:28:36,982 INFO  [STDOUT] 70410 DEBUG myapp.test.entities.TestCallback  -  - postLoad(TestEntity) - start
12:28:36,982 INFO  [STDOUT] 70410 DEBUG myapp.test.entities.TestCallback  -  - postLoad(TestEntity) - end
12:28:36,982 INFO  [STDOUT] 70410 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest2() - String x=XXX
12:28:36,983 INFO  [STDOUT] 70411 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest2() - end

Test 3:

public void runTest3() {
        logger.debug("runTest3() - start"); //$NON-NLS-1$

        String sql = "SELECT DISTINCT t FROM TestEntity t";
        Query q = this.entityManager.createQuery(sql);

        List<TestEntity> l = q.getResultList();
        for (int i = 0; i < l.size(); i++) {
            l.get(i).setTest("YYY" + System.currentTimeMillis());
            this.entityManager.persist(l.get(i));
        }
        this.entityManager.flush();
        this.entityManager.clear();

        Random rand = new SecureRandom();

        q = this.entityManager.createQuery(sql);
        l = q.getResultList();
        for (int i = 0; i < l.size(); i++) {
            this.entityManager.remove(l.get(i));
        }

        this.entityManager.flush();
        this.entityManager.clear();

        logger.debug("runTest3() - end"); //$NON-NLS-1$
    }

Output 3:

12:30:00,404 INFO  [STDOUT] 153832 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest3() - start
12:30:00,407 INFO  [STDOUT] 153835 DEBUG myapp.test.entities.TestCallback  -  - postLoad(TestEntity) - start
12:30:00,407 INFO  [STDOUT] 153835 DEBUG myapp.test.entities.TestCallback  -  - postLoad(TestEntity) - end
12:30:00,408 INFO  [STDOUT] 153836 DEBUG myapp.test.entities.TestCallback  -  - preUpdate(TestEntity) - start
12:30:00,408 INFO  [STDOUT] 153836 DEBUG myapp.test.entities.TestCallback  -  - preUpdate(TestEntity) - end
12:30:00,410 INFO  [STDOUT] 153838 DEBUG myapp.test.entities.TestCallback  -  - postLoad(TestEntity) - start
12:30:00,411 INFO  [STDOUT] 153839 DEBUG myapp.test.entities.TestCallback  -  - postLoad(TestEntity) - end
12:30:00,414 INFO  [STDOUT] 153842 DEBUG myapp.test.entities.TestCallback  -  - preRemove(TestEntity) - start
12:30:00,414 INFO  [STDOUT] 153842 DEBUG myapp.test.entities.TestCallback  -  - preRemove(TestEntity) - end
12:30:00,453 INFO  [STDOUT] 153881 DEBUG myapp.test.web.actions.test.TestAction  -  - runTest3() - end
Gaspard answered 4/12, 2011 at 3:25 Comment(3)
Please take a look at my answer, I've updated it. I hope it helps! And, if you let me to make one small remark: next time you update your answer post a comment on the answer, who's owner seems interested in your problem. I'm saying this, because I didn't get any notification from SO that you've updated your question (I've checked manually! :). Thanks in advance!Saviour
How do you inject your entityManager? Is the class containing the runTest methods a seam component (annotated with @Name)? Can you post your components.xml file too? I've tried really hard to reproduce your problem but no luck until now.Some
I inject my entitymanager with the standard @In EntityManager entityManager; declaration. My test class is a Seam component with @ Name("testAction"). The runTest*() methods are not declared as @ Transactional or anything. It's really a pretty simple use case, so that's why I can't figure out why it's not working.Gaspard
T
8

Sorry if i give a wrong answer... i don't know Seam.

But in your subject you say "Hibernate/JPA" which is unclear. Do you persist entities using a Session from a SessionFactory, or an EntityManager from an EntityManagerFactory?

There is a big difference because if you use Seam with a SessionFactory, the big difference is that by default the JPA listeners (which fire your annotated callbacks) are not registred by default, while they are with an EntityManagerFactory. So it may be possible that you are using a SessionFactory, and that someone else on your project, who configured that session factory, only registered a subset of all the JPA callback listeners.

See: http://docs.jboss.org/hibernate/entitymanager/3.5/reference/en/html/configuration.html#d0e865


Edit: Ok sorry, you use an EntityManager...

but perhaps it would be a good idea to try to get that SessionFactory behind the EntityManagerFactory, and see which event listeners are registred. Are you alone on that application? If someone tried to register a custom/legacy eventlistener or something, he may have overriden a JPA eventlistener.

This can be achieved by something like that:

EntityManager em = ...
Session session = (Session)em.getDelegage()
SessionFactoryImpl sessionFactoryImpl = (SessionFactoryImpl)session.getSessionFactory();
EventListeners el = sessionFactoryImpl.getEventListeners()

And then you can look what's inside, for exemple, according to your problem, you can compare:

el.getPreLoadEventListeners()
el.getPreDeleteEventListeners()

And remember the "default behaviour" is: http://docs.jboss.org/hibernate/stable/entitymanager/reference/en/html_single/#d0e865

It seems that it is possible to easily override JPA default listeners, see that: http://docs.jboss.org/hibernate/entitymanager/3.6/reference/en/html/listeners.html

It would be nice if you show us your persistence.xml

Tacket answered 9/12, 2011 at 22:38 Comment(6)
I'm calling from an EntityManager.Gaspard
I'm the sole developer on the app, so there are no additional eventlisteners registered, unless Seam declares one that I don't know about.Gaspard
that's why you'd rather give use the list of registred listeners like i said above ;)Tacket
I took another look at my persistence.xml file and see that Hibernate Search is declared as a series of FullTextIndexEventListeners. I'm assuming that this is the problem, correct? That said, how can I use the Hibernate Search listeners, as well as my custom ones? Is there chaining of some sort?Gaspard
You mean register your custom hibernate search listeners with also the default jpa listeners? Usually you can define multiple eventlisteners to react to a same event, according to hibernate code, for each event is associated an array of eventlisteners. You will have to find out how to register multiple event listeners for a single event with JPA. Again your persistence.xml would help ;) thanks for the bountyTacket
em.getDelegage() should be em.getDelegate()Orientate
T
3

Without the actual tests you've ran, the way you've ran them and the output you've got (from your listener) it is hard to say anything clever, however using MySQL with the following table and data

CREATE TABLE `test` (
  `id` int(11)
  `data` char(1),
  PRIMARY KEY (`id`)
);
+----+------+
| id | data |
+----+------+
|  1 | a    |
+----+------+

I've ran this test

EntityManagerFactory emf = ...
EntityManager em = emf.createEntityManager();
EntityTransaction tx = em.getTransaction();

// persisting new item
Test b = new Test();
b.id = 2;
b.data = 'b';

tx.begin();
em.persist(b);
tx.commit();

// update existing item
b.data = 'a';

tx.begin();
em.merge(b);
tx.commit();

// load existing
Test a = em.find(Test.class, 1);

// remove existing
tx.begin();
em.remove(b);
tx.commit();

em.close();
emf.close();

and got the following output

prePersist(2: b)
postPersist(2: b)
preUpdate(2: a)
postUpdate(2: a)
postLoad(1: a)
preRemove(2: a)
postRemove(2: a)

(I've implemented toString() in Test so it emits id + ": " + data and I've reduced the logging statements in my listener class to System.out.format("preXxx(%s)\n", e) so that it would be read better.)

Please see if this works for you in your environment for starters, so that we could narrow down the problem, but at least post some of your input/output.


I've tried to boot up a simple JBoss/Seam test application for myself to run a test, however I don't get Seam … at all. Anyway, I took a look at your examples and here's what I think your problem is.

Test 1 / Ouput 1

I assume that your runTest() method starts a managed persistence session or something like that, so before the method gets called entityManager.getTransaction().begin() is called by Seam, and when the method exists entityManager.getTransaction().commit() is called. Here's my opinion on what seems to happen in your scenario.

// transaction begin
// persist - @PrePersist called
this.entityManager.persist(e);
// flush - @PostPersist should be called
this.entityManager.flush();
// clear - the context is cleared
this.entityManager.clear();
// transaction end

I've tested this scenario, however using MySQL with manual persistence management @PostPersist is called.

I've tried setting entityManager.setFlushMode(...) to FlushModeType.AUTO and FlushModeType.COMMIT but it changes nothing. However in the Seam documentation there is a third enum, FlushModeType.MANUAL, which isn't in the JPA specification and is Seam specific. It should be fed to the @Begin annotation (this annotation probably indicates that the annotated method starts the transaction at hand).

I'm quite certain that in your case flush() commits nothing to the database until the transaction is over (the methods runs out). If you remove the call to the clear() method @PostPersist should be called.

Test 2 / Output 2

This seems just fine to me!

Test 3 / Output 3

I assume your problem is that @PrePersist and @PostPersist doesn't get called at all, but you call persist(). Because you use find() the returned instances will already be managed. Calling persist() on them does nothing. However mutating their state and calling flush() triggers @PreUpdate. @PostUpdate doesn't get called of the exact same reason @PostPersist didn't get called in the first test: you clear the persistence context before anything could propagate to the database.

Conclusion

Your problem comes down to the fact that you clear() your persistence context before anything gets committed to the database.

I suggest you to make some really simple tests and try playing with the FlushModeType settings I mentioned. Update your Hibernate version. I use the latest version from 3.x.x series (3.8.6.Final). By the way, you didn't exactly share your Hibernate version with us, but it could matter a lot!

Tuddor answered 9/12, 2011 at 6:51 Comment(4)
I do, however, see the changes reflected in the database when my code stops running. I see the values for "test" updated as expected. In fact, the entire code runs with no problems. The only issue is that some of my entity callback methods are not being called as expected. I'll make a couple of changes based on your recommendations and see what happens.Gaspard
@Gaspard I do, however, see the changes reflected in the database when my code stops running. So @PostPersist didn't get called, you clear() the session, but still, your data is persisted? :D Weird. Do you use Seam-ish annotations, like @Begin, @End in your code? If yes it would be helpful if you could post those too or your whole config altogether (persistence.xml too, if you have some magic there, that is). I would swap out Postgres for something else too, just to make sure it isn't the cause of the problem. Try narrowing down the problem.Saviour
No Begin or End tags in the code, as I'm not creating a Seam Conversation when running the test. I'll try and post my persistence.xml file in a bit. Yes, the data gets persisted successfully. I just don't see all of the listener methods being called, which is why I'm so confused.Gaspard
@Gaspard If you can post a full example (with Seam configuration and stuff, maybe in a ZIP or something) I can try and take a look at it. I never used Seam so I have no idea how to create a Seam application and it would be hard for me to mimic your setup anyway.Saviour
S
2

This is not the normal behavior. I work on a project that use seam 2.2.2 with seam managed persistence context, jpa/hibernate, jboss 5.1 and mysql and all the callbacks are correctly invoked. Maybe there is a bug on your test case.

Some answered 9/12, 2011 at 10:19 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.