Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"Convert silent rollbacks into exception if application sends commit command" breaks client code #1739

Closed
1 of 2 tasks
lukas-krecan opened this issue Mar 20, 2020 · 17 comments

Comments

@lukas-krecan
Copy link

I'm submitting a ...

  • bug report
  • feature request

Describe the issue
Changed introduced by #1729 breaks ShedLock and most likely other clients as well

ShedLock tries to coordinate scheduled tasks using a database lock. In pseudocode it works like this:

try {
  insert into locktable ('lock_id')
} catch (DuplicateKeyException) {
  // lock record exists, proceed to update
}
commit; // caused by Spring JdbcTemplate, throws exception now, used to be OK before

try to update the row to obtain lock // not important here

Driver Version?
42.2.11

Java Version?

PostgreSQL Version?
10.6

To Reproduce
Steps to reproduce the behaviour:

Checkout https://github.com/lukas-krecan/ShedLock/pull/new/postgre-bug

Run net.javacrumbs.shedlock.provider.jdbctemplate.PostgresJdbcTemplateLockProviderIntegrationTest

Expected behaviour
To not throw exception on commit.

Logs

org.springframework.transaction.TransactionSystemException: Could not commit JDBC transaction; nested exception is org.postgresql.util.PSQLException: The database returned ROLLBACK, so the transaction cannot be committed. Transaction failure cause is <<ERROR: duplicate key value violates unique constraint "shedlock_pkey"
  Detail: Key (name)=(name) already exists.>>

	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:333)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714)
	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152)
	at net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateStorageAccessor.insertRecord(JdbcTemplateStorageAccessor.java:64)
	at net.javacrumbs.shedlock.support.StorageBasedLockProvider.doLock(StorageBasedLockProvider.java:81)
	at net.javacrumbs.shedlock.support.StorageBasedLockProvider.lock(StorageBasedLockProvider.java:65)
	at net.javacrumbs.shedlock.test.support.AbstractLockProviderIntegrationTest.shouldNotReturnSecondLock(AbstractLockProviderIntegrationTest.java:59)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:567)
	at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:675)
	at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:125)
	at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:132)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:124)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:74)
	at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:104)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:62)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:43)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:35)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:202)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:198)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:135)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:69)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:135)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1540)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1540)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:229)
	at org.junit.platform.launcher.core.DefaultLauncher.lambda$execute$6(DefaultLauncher.java:197)
	at org.junit.platform.launcher.core.DefaultLauncher.withInterceptedStreams(DefaultLauncher.java:211)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:191)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:128)
	at com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:69)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33)
	at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:230)
	at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:58)
Caused by: org.postgresql.util.PSQLException: The database returned ROLLBACK, so the transaction cannot be committed. Transaction failure cause is <<ERROR: duplicate key value violates unique constraint "shedlock_pkey"
  Detail: Key (name)=(name) already exists.>>
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2209)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:331)
	at org.postgresql.jdbc.PgConnection.executeTransactionCommand(PgConnection.java:833)
	at org.postgresql.jdbc.PgConnection.commit(PgConnection.java:855)

Related issue: lukas-krecan/ShedLock#207

@davecramer
Copy link
Member

Well we aren't likely to revert this change. You should either fix your code to expect an exception or disable the feature using raiseExceptionOnSilentRollback=false.

That said it is possible that the server will be changed to throw an error as this discussion is ongoing. In which case we may remove the option to disable it.

@lukas-krecan
Copy link
Author

It's fine by me, I just wanted to give you heads up. The same code works in all other databases and older Postgres JDBC drivers so you can expect lots of error reports like this.

@davecramer
Copy link
Member

Why are you committing at that point anyway? It's possible that the transaction threw an exception.

@vlsi
Copy link
Member

vlsi commented Mar 20, 2020

The same code works in all other databases and older Postgres JDBC drivers so you can expect lots of error reports like this.

Technically speaking, commit is declared as

void commit() throws SQLException;

That is why you must be prepared to handle SQLException.

The same code works in all other databases and older Postgres JDBC drivers so you can expect lots of error reports like this.

Exactly. PostgreSQL follows a model where any single exception marks the transaction as an aborted one, so the database forbids patterns like

catch (DuplicateKeyException) {
  // lock record exists, proceed to update
}

Note: your comment suggests "proceed to update", however, in practice you can never proceed to update. Even older driver was not able to update a record after catching SQLException.

The thing is the database silently rolls back the transaction, so the old behavior was to rollback the transaction. So the transaction looked like a successful one, however, it was rolled back.

Now we make the failure explicit, so, yes, it is expected that everybody who adopts PostgreSQL must be prepared to write exception-less SQL code, or they must ask PostgreSQL developers to allow Oracle-like behavior.

Note: pgjdbc has autosave connection property that would emulate Oracle-like behavior. That is it would create an implicit savepoint before each SQL, so the application would be able to catch the exception, and still continue the transaction.

@vlsi
Copy link
Member

vlsi commented Mar 20, 2020

TL;DR: the exception is expected. If you see it you need to double-check why the code is trying to commit a failing transaction.

If you want to continue the transaction even in case of SQLExceptions, then you need to configure autosave=always (which might have performance impact because of extra savepoints).

@vlsi vlsi closed this as completed Mar 20, 2020
@lukas-krecan
Copy link
Author

lukas-krecan commented Mar 20, 2020

The thing is that developers working on higher level code usually do not commit the transaction manually but by using a library. For example

You are basically breaking all such libraries, but if it's according to the spec then I guess it does not matter.

@davecramer
Copy link
Member

Well given that Oracle (and others) do throw an exception when commit fails, how do these frameworks deal with this. Also looking at the spring template it is prepared to throw a transaction exception. No idea what Kotlin is doing there.

@vlsi
Copy link
Member

vlsi commented Mar 20, 2020

You are basically breaking all such libraries, but if it's according to the spec then I guess it does not matter.

  1. The exception message is very same as if there were deferred integrity constraint violations

  2. It is according to the spec

The thing is that developers working on higher level code usually do not commit the transaction

The question here is what do application developers expect when they catch SQLException within the application code.

For instance, you have this code: https://github.com/lukas-krecan/ShedLock/blob/57211b0a6f74b0b9a38206b14b109670df12da99/shedlock-core/src/main/java/net/javacrumbs/shedlock/support/StorageBasedLockProvider.java#L86-L87

            if (storageAccessor.insertRecord(lockConfiguration)) {
                lockRecordRegistry.addLockRecord(name);
                // we were able to create the record, we have the lock
                return true;
            }
            // we were not able to create the record, it already exists, let's put it to the cache so we do not try again
            lockRecordRegistry.addLockRecord(name);

In practice, insertRecord fails with SQLException, so there's NO way to proceed if you are using vanilla PostgreSQL.
The database would enforce the transaction to rollback, so actions like lockRecordRegistry.addLockRecord make absolutely no sense in PostgreSQL world.

I know it might be extremely unexpected (e.g. when coming from Oracle DB background), but it is the way PostgreSQL works.

So if you want to work with PostgreSQL, you have two options:
a) Write exception-less code. That is write statements in such a way that the database would never have to throw exceptions.
For instance, your if (fail to insert) { add } might be rewritten as insert .. on conflict ...

b) Use autosave=always pgjdbc feature to emulate Oracle-like behavior.

c) Write a post to pgsql-hackers mailing list, and ask PostgreSQL developers to provide a compatibility mode (e.g. avoid failing the transaction on each and every exception)

@vlsi
Copy link
Member

vlsi commented Mar 20, 2020

Just in case: I believe what we discuss here is a true Shedlock bug that was previously hidden.

PS. @lukas-krecan , if you like, we can try adding a Travis CI job that would run Shedlock against each pgjdbc head commit as an integration test.

@lukas-krecan
Copy link
Author

I was just trying to help, I am able to change my code, I just wanted to warn you that you are potentially breaking lot of stuff in minor release, that's all. Thanks for your time.

@vlsi
Copy link
Member

vlsi commented Mar 20, 2020

@lukas-krecan , thanks for raising the question, however this change in behavior was exactly what we planned. It would still be great to know if there are false positives, however, so far it looks like your case is true positive.

@lukas-krecan
Copy link
Author

What about code like this:

    @org.springframework.transaction.annotation.Transactional
    public void insert() {
        try {
            jdbcTemplate.update("insert into my_table values('test')");
        } catch(DataAccessException e) {
            // ignored, expected behavior
            logger.info("action=error_on_insert {}", e.getMessage());
        }
    }

The flow is like this:

  1. Insert fails
  2. The exception is caught and processed, not re-thrown
  3. The method is marked as Transactional so Spring will try to commit the transaction (it does not know it should be rolled-back since no exception was re-thrown)
  4. Commit fails in 42.2.11

In order to use 42.2.11, all users would have to move exception handling out of their transactions or more likely, Spring would somehow have to detect that it's supposed to rollback the transaction.

The demo code is available here https://github.com/lukas-krecan/datasource-demo

@vlsi
Copy link
Member

vlsi commented Mar 22, 2020

Commit fails in 42.2.11

Exactly.

What do you expect?
Do you expect that the commit would complete without exception, and the transaction still to be rolled back?

For instance: what if you add a REST controller that calls this #insert() method?

Do you really expect that http://server:port/insert to return 200 OK even for the case when insert was rolled back?

PS. Thanks for taking the time for creating a reproducer.

@vlsi
Copy link
Member

vlsi commented Mar 22, 2020

PS. An application can mark a transaction as a rollback-only via

@Resource
private SessionContext context;

context.getRollbackOnly();

@lukas-krecan
Copy link
Author

I do not dispute correctness or incorrectness. What I am trying to say is that such change deserves to be released in major version to warn people that their code might break.

@davecramer
Copy link
Member

This is debatable as it is quite likely that the server is going to make the same change and all versions of the driver will have this behaviour.

@vlsi
Copy link
Member

vlsi commented Mar 22, 2020

What I am trying to say is that such change deserves to be released in major version to warn people that their code might break

Ok. that is a different story.

We can indeed re-brand 42.2.11 as 42.3.0.

However, the change is mentioned twice in the notable changes (see https://jdbc.postgresql.org/ ), so people should be more-or-less expecting the change.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants