Grails 4.1.4 integration test not able to update Domain class via Data service, unless using withNewTransaction

Question

I have created a public Github repo replicating and illustrating the issue:

https://github.com/SparkersData/grails414-dataservice-int-test

Introduction

The integration test aims to update an existing Book object by calling a transactional service, which in turn calls a GORM Data service to update the Book.

BookServiceIntSpec -> [ BookService -> BookDataService ]

The execution of the portion between square brackets should be guarded by a Transaction introduced by the @Transactional annotation of the BookService

I have created 3 different Spec methods that demonstrate the odd behavior.

The preamble of the integration tests is a follows:

import acme.domain.Book
import grails.gorm.transactions.Rollback
import grails.testing.mixin.integration.Integration
import spock.lang.Specification
import spock.lang.Subject

@Integration
@Rollback
@Subject(BookService)
class BookServiceIntSpec extends Specification {

    BookService bookService

    Book book

    void setup() {
        book = new Book(title: "The Hobbit")
        book.save(flush: true, failOnError: true)
    }

    void cleanup() {
        Book.where {}.deleteAll()
    }
}

Test cases

It is able to update a Book without creating a new transaction, by using GORM in the service

Production code in BookService:

    Book updateWithGORM(Book toUpdate) {
        toUpdate.save(flush: true, failOnError: true)
    }

This is the Integration test:

    def "It is able to update a Book without creating a new transaction, by using GORM in the service."() {
        when:
        book.title = updatedTitle
        bookService.updateWithGORM(book)

        then:
        Book.findByTitle(updatedTitle) != null

        where:
        updatedTitle = "Bilbo The Hobbit"
    }

It is NOT able to update a Book without creating a new transaction, if using a Data Service

Production code in BookService

    Book updateWithDataService(Book toUpdate) {
        bookDataService.save(toUpdate)
    }

This is the Integration test:

    def "It is NOT able to update a Book without creating a new transaction, if using a Data Service."() {
        when:
        book.title = updatedTitle
        bookService.updateWithDataService(book)

        then:
        Book.findByTitle(updatedTitle) == null //<1>

        where:
        updatedTitle = "Bilbo The Hobbit"
    }

<1> The updated book cannot be found after requesting an update

It is able to update a Book by creating a new transaction, if using a Data Service

    Book updateWithDataService(Book toUpdate) {
        bookDataService.save(toUpdate)
    }

This is the Integration test:

    def "It is able to update a Book by creating a new transaction, if using a Data Service."() {
        when:
        book.title = updatedTitle
        Book.withNewTransaction { //<1>
            bookService.updateWithDataService(book)
        }

        then:
        Book.findByTitle(updatedTitle) != null //<2>

        where:
        updatedTitle = "Bilbo The Hobbit"
    }

<1> By usign withNewTransaction, the update succeeds
<2> The updated book CAN be found after requesting an update

Conclusion

Either this is a bug in the integration test runtime of Grails 4.1.4 or the documentation is not clear on how to use transactional services in integration tests. My guesses for the explanation of the behavior:

• the test runtime is not flushing the session after closing the transaction
• the transaction is created in the integration test, and somehow my GORM code in the integration test is not able to access the same hibernate session

Has anyone else stumbled on this behavior or has an explanation of this? Wrapping every call with withNewTransaction seems like a nightmare.

Updates

Update 1: Explicitly flushing the session in the service method

By modifying the service method as follows:

    Book updateWithDataService(Book toUpdate) {
        def res = bookDataService.save(toUpdate)
        sessionFactory.currentSession.flush()
        res
    }

The tests behave properly, without having to mess with creating new transactions, and potentially disturbing the Hibernate session.

I still don't understand why this is not the default behavior!

Update 2: Is this a caching issue?

@mike-w Suggests that I may be hitting some kind of cache when using findByTitle in my test. I think, however, that it is, on the contrary, when he uses findById() that we are hitting a cache in my test.

This is substantiated by the fact that, when I activate hibernate tracing in logback.groovy:

logger("org.hibernate.type.descriptor.sql.BasicBinder", TRACE, ['STDOUT'], false)
logger("org.hibernate.SQL", DEBUG, ['STDOUT'], false)

Then I can see the following, if I keep the session unflushed:

2024-04-21 01:15:36.620 DEBUG --- [    Test worker] org.hibernate.SQL                        : select this_.id as y0_ from book this_ where this_.title=? limit ?
2024-04-21 01:15:36.621 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [The Hobbit]
2024-04-21 01:15:36.621 DEBUG --- [    Test worker] org.hibernate.SQL                        : insert into book (id, version, title) values (null, ?, ?)
2024-04-21 01:15:36.622 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [0]
2024-04-21 01:15:36.622 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [The Hobbit]
2024-04-21 01:15:36.625 DEBUG --- [    Test worker] org.hibernate.SQL                        : select this_.id as y0_ from book this_ where this_.title=? limit ?
2024-04-21 01:15:36.626 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [Bilbo The Hobbit]
2024-04-21 01:15:36.627 DEBUG --- [    Test worker] org.hibernate.SQL                        : select this_.id as id1_0_0_, this_.version as version2_0_0_, this_.title as title3_0_0_ from book this_ where this_.title=? limit ?
2024-04-21 01:15:36.627 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [Bilbo The Hobbit]
2024-04-21 01:15:36.638 DEBUG --- [    Test worker] org.hibernate.SQL                        : delete from book

i.e. no update statement whatsoever.

If, however, i add sessionFactory.currentSession.flush() then I can see the following:

2024-04-21 01:21:29.612 DEBUG --- [    Test worker] org.hibernate.SQL                        : select this_.id as y0_ from book this_ where this_.title=? limit ?
2024-04-21 01:21:29.613 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [The Hobbit]
2024-04-21 01:21:29.614 DEBUG --- [    Test worker] org.hibernate.SQL                        : insert into book (id, version, title) values (null, ?, ?)
2024-04-21 01:21:29.614 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [0]
2024-04-21 01:21:29.614 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [The Hobbit]
2024-04-21 01:21:29.618 DEBUG --- [    Test worker] org.hibernate.SQL                        : select this_.id as y0_ from book this_ where this_.title=? limit ?
2024-04-21 01:21:29.618 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [Bilbo The Hobbit]
2024-04-21 01:21:29.621 DEBUG --- [    Test worker] org.hibernate.SQL                        : update book set version=?, title=? where id=? and version=?
2024-04-21 01:21:29.621 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1]
2024-04-21 01:21:29.621 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [Bilbo The Hobbit]
2024-04-21 01:21:29.622 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [2]
2024-04-21 01:21:29.622 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [0]
2024-04-21 01:21:29.625 DEBUG --- [    Test worker] org.hibernate.SQL                        : select this_.id as id1_0_0_, this_.version as version2_0_0_, this_.title as title3_0_0_ from book this_ where this_.title=? limit ?
2024-04-21 01:21:29.625 TRACE --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [Bilbo The Hobbit]
2024-04-21 01:21:29.627 DEBUG --- [    Test worker] org.hibernate.SQL                        : delete from book

So I don't believe that in the first case the book has been updated at all, but in Mike's solution, we are hitting the cache when trying to get the Book by id (i.e. the updated book instance in the hibernate session of the integration test).

Answer 1

It's worth noting that data added in setup in grails integration tests is not cleared between test runs unless you do it yourself so you're ending up with 3 rows in your book table by the end of the 3rd test, setup uses a different transaction to the test transaction. I don't think this affects your tests on this occasion but I doubt it's what you want. You can either do the setup in a separate method you call from your test or add a cleanup, something like...

void cleanup() {
    Book.where {}.deleteAll()
}

Not 100% sure why but I think your calls to findByTitle are affected by caching, switching to a dynamic finder get, or findById or get on your data service fetches the updated book (added both in example) e.g.

def "It is able to update a Book by creating a new transaction, if using a Data Service."() {
    when:
        book.title = updatedTitle
        bookService.updateWithDataService(book)
    then:
        bookDataService.get(book.id).title == updatedTitle //<2>
        Book.findById(book.id).title == updatedTitle
    where:
        updatedTitle = "Bilbo The Hobbit"
}

You are flushing in the non-data service example which is why it's okay I think.