CODEWITHSUNDEEP
javahibernatejpaspring-boot
robbin
robbin

Reputation: 1954

Spring JPA skips inserting entity sometimes

I have a springboot application, and have a custom implementation to record history of changes on JPA entities.

My main entity is Test, which extends from a Base class. The base class has the following annotations

@EntityListeners(HistoryEntityUpdater.class)
@Inheritance(strategy = InheritanceType.JOINED)
@DiscriminatorColumn(name = "object_type")

I have a custom entity listener with methods annotated with @PostPersist and @PostUpdate. In these methods I create an instance of TestHistory and call entityManager.persist. Although this works, but some of the history records are not getting inserted. Here's the log when the save is called, but database is not updated.

2016-04-22 19:57:58.428 TRACE 18060 --- [nio-9285-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Releasing statement [sql : 'update managed_object set last_updated_time=?, name=?, workflow_status=? where id=?', parameters : ['2016-04-22 19:57:26.185','tests1','ERROR',1]]
2016-04-22 19:57:58.429 TRACE 18060 --- [nio-9285-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Closing prepared statement [sql : 'update managed_object set last_updated_time=?, name=?, workflow_status=? where id=?', parameters : ['2016-04-22 19:57:26.185','tests1','ERROR',1]]
2016-04-22 19:57:58.429 TRACE 18060 --- [nio-9285-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Starting after statement execution processing [ON_CLOSE]
2016-04-22 19:57:58.429 TRACE 18060 --- [nio-9285-exec-2] o.h.internal.util.SerializationHelper    : Starting clone through serialization
2016-04-22 19:57:58.429 TRACE 18060 --- [nio-9285-exec-2] o.h.internal.util.SerializationHelper    : Starting serialization of object [2016-04-22T14:27:26.185Z]
2016-04-22 19:57:58.429 TRACE 18060 --- [nio-9285-exec-2] o.h.internal.util.SerializationHelper    : Starting deserialization of object
2016-04-22 19:57:58.433 TRACE 18060 --- [nio-9285-exec-2] o.h.internal.util.SerializationHelper    : Attempting to locate class [java.time.Ser]
2016-04-22 19:57:58.434 DEBUG 18060 --- [nio-9285-exec-2] c.b.b.m.db.history.HistoryEntityUpdater  : postUpdate com.xyz.model.db.Test@4dcfc8b8
2016-04-22 19:57:58.435 TRACE 18060 --- [nio-9285-exec-2] o.hibernate.engine.spi.IdentifierValue   : ID unsaved-value strategy UNDEFINED
2016-04-22 19:57:58.436 TRACE 18060 --- [nio-9285-exec-2] o.h.e.i.AbstractSaveEventListener        : Transient instance of: com.xyz.model.db.history.TestHistory
2016-04-22 19:57:58.436 TRACE 18060 --- [nio-9285-exec-2] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2016-04-22 19:57:58.437 DEBUG 18060 --- [nio-9285-exec-2] o.h.e.i.AbstractSaveEventListener        : Generated identifier: component[id,revisionTime,revisionType]{revisionType=UPDATED, id=1, revisionTime=Fri Apr 22 19:57:58 IST 2016}, using strategy: org.hibernate.id.CompositeNestedGeneratedValueGenerator
2016-04-22 19:57:58.437 TRACE 18060 --- [nio-9285-exec-2] o.h.e.i.AbstractSaveEventListener        : Saving [com.xyz.model.db.history.TestHistory#component[id,revisionTime,revisionType]{revisionType=UPDATED, id=1, revisionTime=Fri Apr 22 19:57:58 IST 2016}]
2016-04-22 19:57:58.437 TRACE 18060 --- [nio-9285-exec-2] org.hibernate.engine.spi.ActionQueue     : Adding an EntityInsertAction for [com.xyz.model.db.history.TestHistory] object
2016-04-22 19:57:58.437 TRACE 18060 --- [nio-9285-exec-2] org.hibernate.engine.spi.ActionQueue     : Adding insert with no non-nullable, transient entities: [EntityInsertAction[com.xyz.model.db.history.TestHistory#com.xyz.model.db.history.HistoryObject$HistoryId@4b74eea0]]
2016-04-22 19:57:58.437 TRACE 18060 --- [nio-9285-exec-2] org.hibernate.engine.spi.ActionQueue     : Adding resolved non-early insert action.
2016-04-22 19:57:58.437 TRACE 18060 --- [nio-9285-exec-2] o.h.a.i.UnresolvedEntityInsertActions    : No unresolved entity inserts that depended on [[com.xyz.db.history.TestHistory#com.xyz.db.history.HistoryObject$HistoryId@4b74eea0]]
2016-04-22 19:57:58.437 TRACE 18060 --- [nio-9285-exec-2] o.h.a.i.UnresolvedEntityInsertActions    : No entity insert actions have non-nullable, transient entity dependencies.
2016-04-22 19:57:58.438 TRACE 18060 --- [nio-9285-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Starting after statement execution processing [ON_CLOSE]
2016-04-22 19:57:58.438 TRACE 18060 --- [nio-9285-exec-2] o.h.e.i.AbstractFlushingEventListener    : Post flush
2016-04-22 19:57:58.438 TRACE 18060 --- [nio-9285-exec-2] org.hibernate.internal.SessionImpl       : before transaction completion
2016-04-22 19:57:58.440 DEBUG 18060 --- [nio-9285-exec-2] o.h.e.t.internal.jdbc.JdbcTransaction    : committed JDBC Connection
2016-04-22 19:57:58.440 DEBUG 18060 --- [nio-9285-exec-2] o.h.e.t.internal.jdbc.JdbcTransaction    : re-enabling autocommit
2016-04-22 19:57:58.441 TRACE 18060 --- [nio-9285-exec-2] o.h.e.t.i.TransactionCoordinatorImpl     : after transaction completion
2016-04-22 19:57:58.442 TRACE 18060 --- [nio-9285-exec-2] org.hibernate.internal.SessionImpl       : after transaction completion
2016-04-22 19:57:58.443 TRACE 18060 --- [nio-9285-exec-2] org.hibernate.internal.SessionImpl       : Closing session
2016-04-22 19:57:58.443 TRACE 18060 --- [nio-9285-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@5be5a598]
2016-04-22 19:57:58.443 DEBUG 18060 --- [nio-9285-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl  : HHH000420: Closing un-released batch
2016-04-22 19:57:58.443 TRACE 18060 --- [nio-9285-exec-2] o.h.e.j.internal.LogicalConnectionImpl   : Closing logical connection
2016-04-22 19:57:58.443 DEBUG 18060 --- [nio-9285-exec-2] o.h.e.j.internal.LogicalConnectionImpl   : Releasing JDBC connection
2016-04-22 19:57:58.443 DEBUG 18060 --- [nio-9285-exec-2] o.h.e.j.internal.LogicalConnectionImpl   : Released JDBC connection
2016-04-22 19:57:58.443 TRACE 18060 --- [nio-9285-exec-2] o.h.e.j.internal.LogicalConnectionImpl   : Logical connection closed

The postUpdate and postPersist methods on HistoryEntityUpdater are annotated with @Transactional

Upvotes: 0

Views: 688

Answers (1)

Stefan Isele - prefabware.com
Stefan Isele - prefabware.com

Reputation: 9546

The JPA specs state that EntityListeners should not use the EntityManager. This makes them useless for most use cases, including yours.

I was not aware of that either.

From your stacktrace it looks like the JDBC transaction is already committed and the entitymanager is flushed. So at least you don't have any transaction when your listener runs. And this might lead to situations where the written history entities are not written to the database. The EntityListener is called by hibernate and not by spring, so any @Transactional annotations on your listener will not work.

Finally there is a solution for you, use 'Envers' to implement entity auditing :

database auditing jpa

Upvotes: 2

Related Questions