I'm facing an odd issue after migrating an app from Grails 2.5 to Grails 3.1 - database exceptions never bubble up to the controller.
The typical scenario looks like this: controller's delete action attempts to remove an entry, but a database-level constraint prevents the delete. This leads to an exception (see below) - in Grails 2.5, if uncaught, this would lead to "Error 500 internal server error". Now, we have a custom mapping for these, so even in case an uncaught error occurs, it is handled in a user-friendly way and the user knows something happened.
In Grails 3, this stopped working. The exception is logged, but would never bubble up to the controller. So in this specific case, our controller just goes on and returns "204" HTTP status code as if nothing happened, and the end user doesn't even know something went wrong.
I'm puzzled and I think this must be something stupid I'm missing, but can't figure it out. I have tested this Grails 2.5.5, 3.1.16, 3.2.12 and 3.3.2, but all tested 3.x releases behaved pretty much the same way. Also tested with both Hibernate 4 and 5, and tried H2 and PostgreSQL but I'm getting the same behavior regardless.
The easiest way to reproduce is to manually add a FK relationship (with delete no action) to the hibernate-generated database schema and attempt to delete via the controller (example #1 below) but the issue may also occur with some many-to-many relationships or other scenarios such as persisting a new entry (and failing at the database level).
UPDATE #1, April 25, 2018: To create a minimal reproducible test case using PostgreSQL as the database and Grails 3.3.x, just create a blank grails application via grails create-app testapp. Then adjust the application.yml to configure data source for your PostgreSQL instance, and use dbCreate: validate mode as the schema is provided below.
Add one minimal domain object:
class Book {
String name
}
And a controller to test object deletion, i.e. BookController:
class BookController {
@Transactional
def delete(Long id) {
Book.get(id).delete()
render "Book $id deleted"
}
}
The schema below creates 2 tables with a FK and a few entries. Book with id 1 will fail to be removed, books with id 2 and 3 will be removed successfully. Controller will return 200 OK in all 3 cases. You can test using the default UrlMappings via curl calls, i.e. curl http://localhost:8080/book/delete/1.
The database schema follows:
CREATE TABLE book (
id bigint NOT NULL,
version bigint NOT NULL,
name character varying(255) NOT NULL,
CONSTRAINT book_pkey PRIMARY KEY (id)
);
CREATE TABLE chapter (
id bigint NOT NULL,
book_id bigint NOT NULL,
name character varying(255),
CONSTRAINT chapter_pkey PRIMARY KEY (id),
CONSTRAINT fk_book FOREIGN KEY (book_id) REFERENCES book(id)
);
INSERT INTO book VALUES (1, 0, 'Book 1');
INSERT INTO book VALUES (2, 0, 'Book 2');
INSERT INTO book VALUES (3, 0, 'Book 3');
INSERT INTO chapter VALUES (1, 1, 'Book 3 Chapter');
CREATE SEQUENCE hibernate_sequence START WITH 1 INCREMENT BY 1 NO MINVALUE NO MAXVALUE CACHE 1;
SELECT pg_catalog.setval('hibernate_sequence', 4, true);
For the sake of completeness, here's the stack trace:
2018-04-25 16:23:22.462 ERROR --- [nio-8080-exec-1] o.h.engine.jdbc.spi.SqlExceptionHelper : ERROR: update or delete on table "book" violates foreign key constraint "fk_book" on table "chapter"
Detail: Key (id)=(1) is still referenced from table "chapter".
2018-04-25 16:23:22.473 ERROR --- [nio-8080-exec-1] org.hibernate.internal.SessionImpl : HHH000346: Error during managed flush [could not execute statement]
2018-04-25 16:23:22.720 ERROR --- [nio-8080-exec-1] o.g.web.errors.GrailsExceptionResolver : PSQLException occurred when processing request: [GET] /test/delete/1
ERROR: update or delete on table "book" violates foreign key constraint "fk_book" on table "chapter"
Detail: Key (id)=(1) is still referenced from table "chapter".. Stacktrace follows:
java.lang.reflect.InvocationTargetException: null
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:211)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:188)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:90)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:77)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:67)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.dao.DataIntegrityViolationException: could not execute statement; SQL [n/a]; constraint [fk_book]; nested exception is org.hibernate.exception.ConstraintViolationException: could not execute statement
at org.springframework.orm.hibernate5.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:241)
at org.springframework.orm.hibernate5.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:755)
at org.springframework.orm.hibernate5.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:590)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:765)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:734)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:150)
at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91)
... 14 common frames omitted
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:112)
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207)
at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3311)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3548)
at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:98)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:586)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:460)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1295)
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:468)
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3135)
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2352)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:491)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:147)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:65)
at org.springframework.orm.hibernate5.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:582)
... 18 common frames omitted
Caused by: org.postgresql.util.PSQLException: ERROR: update or delete on table "book" violates foreign key constraint "fk_book" on table "chapter"
Detail: Key (id)=(1) is still referenced from table "chapter".
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2433)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2178)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:306)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:155)
at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:132)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
... 36 common frames omitted
UPDATE #2, April 25, 2018: the fact that there is a database table that Hibernate isn't aware of was the point of the above example. It was an easy way to force a database-level exception that would only be logged, but wouldn't make it all the way up to the controller so on HTTP level it would appear as if no error occurred.
UPDATE #3, April 25, 2018: Another test case for Grails 3.3 that doesn't rely on any manual database schema "hacks" is below, with a many-to-many relationship between the same domain (User). It consists of 2 domain classes:
class User {
String name
static hasMany = [relationships: Relationship]
static mappedBy = [relationships: 'user']
static mapping = { table 'table_user' }
}
class Relationship implements Serializable {
User user
User related
static belongsTo = [ user: User, related: User ]
static mapping = {
table 'table_relationship'
id composite: ['user', 'related']
version false
}
}
And a minimal controller:
class TestController {
@Transactional
def delete(Long id) {
User.get(id).delete()
render "User $id deleted"
}
}
This can be reproduced with PostgreSQL or H2, just use the create-drop mode and the following BootStrap code to create 2 User entries:
def init = { servletContext ->
def user1 = new User(name: 'User 1').save()
new User(name: 'User 2', relationships: [new Relationship(related: user1)]).save()
}
Attempting to delete user 2 and then user 1 will work OK. Attempting to first remove user 1 will fail with an exception, yet the controller would still return "200 OK". Just try curl http://localhost/test/delete/1.
For convenience you can download the zipped archive with a runnable Grails 3.3.5 app here: https://www.dropbox.com/s/pycwuxm7r0wyxem/grails3_exception_issue_testapp.zip?dl=0
If you are going to use @Transactional you should use grails.gorm.transactions.Transactional instead of grails.transaction.Transactional.
Separate from that, the problem doesn't appear to be that the exception doesn't make its way up to the controller as much as what is really happening is the transaction isn't being committed until after you call render and the exception doesn't get thrown until the transaction is committed. Calling .delete(flush: true) will show different behavior but putting the transaction boundary in the controller is a bad idea anyway. A better plan is to put your database interactions in a transactional service.
I put your code in the project at https://github.com/jeffbrown/many33. The commit at https://github.com/jeffbrown/many33/commit/f8804c8793b399994c34043c1d340e4bf0d462cd shows a better way to organize this code and yields less surprising behavior.
I hope that helps.