Wrong response when an Exception happens when an object will be saved in a Controller with Transactional annotation

AmaliaMV commented 5 years ago

I have a Person class which does an evaluation inside of beforeDelete() method an depending on the result could throw an exception. Something like that:

class Person {
    String name
    static constraints = {
        name unique: true
    }
    void beforeDelete() {
        throw new RuntimeException('just for test')
    }
}

In addition, I have a controller which has Transactional annotation and this delete() action:

@Transactional(readOnly = true)
class PersonController {  // this doesn't work as I expected

    //....
    @Transactional
    def delete(Long id) {
        if (id == null) {
            render status: NOT_FOUND
            return
        }

        personService.delete(id)

        respond ([status: OK], [message: 'Object deleted'])
    }
}

Problem When I want to delete a Person object using PersonController, I don't have any exception before to send the response. So, the server response is a 200 and the exception happens then (when the beforeDelete is executed)

Expected I expect that when I want to delete a Person object using PersonController, I will have the exception before to send the response and the response will be a 500.

Note: When I was trying to reproduce this error, first I used the generate-all grails command to create the controller. The command created this (I changed the name):

class PersonWithoutTransactionController {  // this works as I expected
   //...
    def delete(Long id) {
        if (id == null) {
            render status: NOT_FOUND
            return
        }

        personService.delete(id)

        respond ([status: OK], [message: 'Object deleted'])
    }
}

This controller doens't have the Transactional annotation and works I expected. What is the correct way to do it? Should works the same in both cases?

Reproduce the error To reproduce the error I have created these tests:

class PersonFunctionalSpec extends GebSpec {

    RestBuilder getRestBuilder() {
        new RestBuilder()
    }

    void setup() {
        if (!Person.findByName('Tomy')) {
            new Person(name: 'Tomy').save(flush:true, failOnError:true)
        }
    }

    void "Test the delete action with Transaction Notation"() {
        when:
        def id = Person.findByName('Tomy').id
        def response = restBuilder.delete("${baseUrl}/person/$id")

        then:"you should have an error"
        response.status == INTERNAL_SERVER_ERROR.value() // <-- this fail 
    }

    void "Test the delete action without Transaction Notation"() {
        when:
        def id = Person.findByName('Tomy').id
        def response = restBuilder.delete("${baseUrl}/personWithoutTransaction/$id")

        then:"you should have an error"
        response.status == INTERNAL_SERVER_ERROR.value()
    }
}

Here is the sample app: https://github.com/AmaliaMV/neo4j-transactional

The versions I am using are:

grailsVersion=3.3.8
gormVersion=6.1.11.BUILD-SNAPSHOT
grailsNeo4jPluginVersion=6.2.0.BUILD-SNAPSHOT

jameskleeh commented 5 years ago

Is the personService transactional?

AmaliaMV commented 5 years ago

@jameskleeh . Yes, it's transactional.

jameskleeh commented 5 years ago

@AmaliaMV Then the controller should not be transactional

AmaliaMV commented 5 years ago

@jameskleeh, I did what you told me. However, I have an exception. The message of the exception is: "Cannot run more statements in this transaction, it has been committed"

Finally, I could reproduce the problem. I updated the sample app to reproduce the same error that I have in the app: https://github.com/AmaliaMV/neo4j-transactional.

If you run gradle integrationTest --tests com.example.PersonFunctionalSpec, this will fail:

  void "Test update action without Transaction Notation"() {
        when:
        println "\n[START] test\n"
        def id = Person.findByName('Person 1').id
        def response = restBuilder.put("${baseUrl}/personWithoutTransaction/$id", {
            json([
                pets: [
                    [
                        name: "Pet 2"
                    ]
                ]
            ])
        })

        then: "you should have save it"
        response.status == OK.value()  // <-- this fail
        response.json.pets.size() == 1
    }

The changes I made were:

added pets as a many-to-one relationship in Person class

added a call to the database in afterLoad() in Pet class

void afterLoad() {
    log.info("Pet - afterLoad()")
    A.findByName('A')
}

added a property called createdBy in Person and Pet classes
added AutoUserstampEventListener to set createdBy when PreInsertEvent is fired. This class has a call to another service to search the current user.
changed to use a custom id generator.

Log

This is the log I have when I run the test:


[START] test

2018-11-26 15:11:41.805 DEBUG --- [    Test worker] o.g.d.g.n.engine.Neo4jEntityPersister    : unmarshalling entity [com.example.Person] with id [1067118710528933888], props node<1>, {}
2018-11-26 15:11:41.832 DEBUG --- [    Test worker] o.g.d.gorm.neo4j.Neo4jTransaction        : TX ROLLBACK ONLY: Neo4J failure()
2018-11-26 15:11:41.832 DEBUG --- [    Test worker] o.g.d.gorm.neo4j.Neo4jTransaction        : TX CLOSE: Neo4j tx.close()
2018-11-26 15:11:42.007 DEBUG --- [qtp981933781-88] o.g.datastore.gorm.neo4j.Neo4jSession    : Session created
2018-11-26 15:11:42.009 DEBUG --- [qtp981933781-88] c.e.PersonWithoutTransactionController   : [START] update action
2018-11-26 15:11:42.010 DEBUG --- [qtp981933781-88] c.e.PersonWithoutTransactionController   : [START] - personService.get()
2018-11-26 15:11:42.010 DEBUG --- [qtp981933781-88] o.g.d.gorm.neo4j.Neo4jTransaction        : TX START: Neo4J beginTx()
2018-11-26 15:11:42.013 DEBUG --- [qtp981933781-88] o.g.d.g.n.engine.Neo4jEntityPersister    : Retrieving entity [class com.example.Person] by node id [1067118710528933888]
2018-11-26 15:11:42.055 DEBUG --- [qtp981933781-88] o.g.d.g.n.engine.Neo4jEntityPersister    : unmarshalling entity [com.example.Person] with id [1067118710528933888], props node<1>, {}
2018-11-26 15:11:42.055 DEBUG --- [qtp981933781-88] o.g.d.gorm.neo4j.Neo4jTransaction        : TX COMMIT: Neo4J success()
2018-11-26 15:11:42.055 DEBUG --- [qtp981933781-88] o.g.d.gorm.neo4j.Neo4jTransaction        : TX CLOSE: Neo4j tx.close()
2018-11-26 15:11:42.057 DEBUG --- [qtp981933781-88] c.e.PersonWithoutTransactionController   : [END] - personService.get()
2018-11-26 15:11:42.057 DEBUG --- [qtp981933781-88] c.e.PersonWithoutTransactionController   : [START] - binding
2018-11-26 15:11:42.102 DEBUG --- [qtp981933781-88] o.g.d.g.n.engine.Neo4jEntityPersister    : unmarshalling entity [com.example.Pet] with id [1067118710528933888], props node<2>, {}
2018-11-26 15:11:42.103  INFO --- [qtp981933781-88] com.example.Pet                          : Pet - afterLoad()
2018-11-26 15:11:42.105 DEBUG --- [qtp981933781-88] o.g.d.gorm.neo4j.Neo4jTransaction        : TX START: Neo4J beginTx()
2018-11-26 15:11:42.119 DEBUG --- [qtp981933781-88] o.g.d.g.n.engine.Neo4jEntityPersister    : unmarshalling entity [com.example.A] with id [1067118707962019840], props node<0>, {}
2018-11-26 15:11:42.129 DEBUG --- [qtp981933781-88] c.e.PersonWithoutTransactionController   : [END] - binding
2018-11-26 15:11:42.129 DEBUG --- [qtp981933781-88] c.e.PersonWithoutTransactionController   : [START] - personService.save()
2018-11-26 15:11:42.130  INFO --- [qtp981933781-88] com.example.PersonService                : [START] person.save()
2018-11-26 15:11:42.133  INFO --- [qtp981933781-88] com.example.PersonService                : [END] person.save()
2018-11-26 15:11:42.133  INFO --- [qtp981933781-88] com.example.Pet                          : Pet - beforeInsert()
2018-11-26 15:11:42.133 DEBUG --- [qtp981933781-88] com.example.AutoUserstampEventListener   : AutoUserstampEventListener .... 
2018-11-26 15:11:42.133  INFO --- [qtp981933781-88] com.example.AutoUserstampEventListener   : [doing call] getSecurityService().getCurrentLoggedInUser()
2018-11-26 15:11:42.134 DEBUG --- [qtp981933781-88] com.example.SecurityService              : [START] SecurityService.getCurrentUser()
2018-11-26 15:11:42.135  INFO --- [qtp981933781-88] com.example.SecurityService              : [END] SecurityService.getCurrentUser()
2018-11-26 15:11:42.135 DEBUG --- [qtp981933781-88] o.g.d.gorm.neo4j.Neo4jTransaction        : TX COMMIT: Neo4J success()
2018-11-26 15:11:42.135 DEBUG --- [qtp981933781-88] o.g.d.gorm.neo4j.Neo4jTransaction        : TX CLOSE: Neo4j tx.close()
2018-11-26 15:11:42.137  INFO --- [qtp981933781-88] com.example.AutoUserstampEventListener   : [finishing call] getSecurityService().getCurrentLoggedInUser()
2018-11-26 15:11:42.138 DEBUG --- [qtp981933781-88] o.g.datastore.gorm.neo4j.Neo4jSession    : CREATE Cypher [UNWIND {petBatch} as row
CREATE (pet:Pet)
SET pet += row.props
] for parameters [{petBatch=[{props={name=Pet 2, version=0, id=1067118713766936576}}]}]
2018-11-26 15:11:42.143 ERROR --- [qtp981933781-88] StackTrace                               : Full Stack Trace:

org.neo4j.driver.v1.exceptions.ClientException: Cannot run more statements in this transaction, it has been committed

Summarizing

During the binding, a new transaction is opened because I'm doing a call to A.findByName('A') and is still opens when the binding finishes.

When person.save() is called, AutoUserstampEventListener.onPersistenceEvent() is invoked. The transaction is closed when getSecurityService().getCurrentUser() ends.

Then, when trying to insert the new pet in the database, I have an error because there isn't any active transaction.

jameskleeh commented 5 years ago

@AmaliaMV I believe this behavior is correct. You should be wrapping new database access inside a listener in a new session.

AmaliaMV commented 5 years ago

@jameskleeh, we are wondering if there is a pattern to write a controller.

As you can see in the new sample app (https://github.com/AmaliaMV/grails-transaction2), we are doing the binding in the controller. In some cases, during the binding we have access to the databases to search for an object, add or remove an object from a collection, and bind dynamic properties. If the controller isn't transactional, should the binding process be in a service? Is it right to do it in a service?

On the other hand, if we need to access the database within a listener, should we always do in a new session? Is wrong access the database within a listener without starting a new session even though the controller is transactional?

Finally, if we need to access the database to read operation inside json views and the controller isn't transactional, how do we have to do?

Thanks!

jameskleeh commented 5 years ago

@AmaliaMV The binding can happen in a service, however the object that is bound isn't persisted in the controller. Unless its causing some sort of problem, I don't consider that an issue.

You should always be wrapping any database logic in a new session if it's executed in any GORM listener.

You shouldn't be accessing the database in a JSON view at all. All of the necessary data to render the response should be passed to the view.

grails / gorm-neo4j

Wrong response when an Exception happens when an object will be saved in a Controller with Transactional annotation #99