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

WARN 764 --- [ main] SpelExpressionStringQueryParameterBinder : Setting the parameter with name '__$synthetic$__4' and position 'null' lead to an exception. #293

Closed
PawelJagus opened this issue Sep 17, 2017 · 7 comments

Comments

@PawelJagus
Copy link

I have just switched from Spring Boot 1.5.3 to 1.5.7 and suddenly the following warning started to show up on executing one of my JPA Repository unit test.

WARN 764 --- [           main] SpelExpressionStringQueryParameterBinder : Setting the parameter with name '__$synthetic$__4' and position 'null' lead to an exception.

java.lang.IllegalArgumentException: Unknown parameter name : __$synthetic$__4
	at org.hibernate.query.internal.QueryParameterBindingsImpl.getBinding(QueryParameterBindingsImpl.java:208) ~[hibernate-core-5.2.11.Final.jar:5.2.11.Final]
	at org.hibernate.query.internal.AbstractProducedQuery.setParameter(AbstractProducedQuery.java:486) ~[hibernate-core-5.2.11.Final.jar:5.2.11.Final]
	at org.hibernate.query.internal.AbstractProducedQuery.setParameter(AbstractProducedQuery.java:104) ~[hibernate-core-5.2.11.Final.jar:5.2.11.Final]
	at org.springframework.data.jpa.repository.query.SpelExpressionStringQueryParameterBinder.potentiallyBindExpressionParameters(SpelExpressionStringQueryParameterBinder.java:100) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.SpelExpressionStringQueryParameterBinder.bind(SpelExpressionStringQueryParameterBinder.java:76) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.ParameterBinder.bindAndPrepare(ParameterBinder.java:161) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.ParameterBinder.bindAndPrepare(ParameterBinder.java:152) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.AbstractStringBasedJpaQuery.doCreateQuery(AbstractStringBasedJpaQuery.java:81) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.AbstractJpaQuery.createQuery(AbstractJpaQuery.java:190) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.JpaQueryExecution$CollectionExecution.doExecute(JpaQueryExecution.java:121) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:85) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:116) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:106) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:483) [spring-data-commons-1.13.7.RELEASE.jar:na]
	at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:461) [spring-data-commons-1.13.7.RELEASE.jar:na]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:56) [spring-data-commons-1.13.7.RELEASE.jar:na]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) [spring-tx-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) [spring-tx-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) [spring-tx-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136) [spring-tx-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:133) [spring-data-jpa-1.11.7.RELEASE.jar:na]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:57) [spring-data-commons-1.13.7.RELEASE.jar:na]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) [spring-aop-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at com.sun.proxy.$Proxy115.findIdsOfPlayersSuspendedByYellowCardsOnMatchdayWhoReceived2YellowCardsOnLastMatchday(Unknown Source) [na:na]
	at com.example.PlayerStatisticsRepositoryTest.findIdsOfPlayersSuspendedByYellowCardsOnMatchdayWhoReceived2YellowCardsOnLastMatchday(PlayerStatisticsRepositoryTest.java:514) [test-classes/:na]
	at com.example.PlayerStatisticsRepositoryTest.ifPlayerHad3YellowCardsAndReceived2OnLastMatchdayThenShouldBeSuspendedOnNextOne(PlayerStatisticsRepositoryTest.java:819) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_144]
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_144]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_144]
	at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.8.0_144]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) [junit-4.12.jar:4.12]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.12.jar:4.12]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) [junit-4.12.jar:4.12]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.12.jar:4.12]
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) [junit-4.12.jar:4.12]
	at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) [junit-4.12.jar:4.12]
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:252) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:94) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) [junit-4.12.jar:4.12]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) [junit-4.12.jar:4.12]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) [junit-4.12.jar:4.12]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) [junit-4.12.jar:4.12]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) [junit-4.12.jar:4.12]
	at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363) [junit-4.12.jar:4.12]
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:191) [spring-test-4.3.11.RELEASE.jar:4.3.11.RELEASE]
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:86) [.cp/:na]
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38) [.cp/:na]
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459) [.cp/:na]
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:678) [.cp/:na]
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382) [.cp/:na]
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192) [.cp/:na]

This does not happen when I fall back to 1.5.3. It looks like this is printed with Throwable.printStackTrace() because the tests are running all green.

@PawelJagus
Copy link
Author

To reproduce please unpack the attached *.zip file, import the project into an STS workspace and run the JUnit test PlayerStatisticsRepositoryTest.
demo.zip

@schauder
Copy link
Contributor

Thanks for this.

We added the logging recently, to hunt down when exactly a certain exception handler was triggered. So it looks like we found at least one case. I'll look into it.

@schauder
Copy link
Contributor

schauder commented Sep 18, 2017

In any case, you can probably ignore the exception, e.g. by excluding the logger 'org.springframework.data.jpa.repository.query.SpelExpressionStringQueryParameterBinder'
this is the only kind of logging it does.

If you ever see other exceptions related to parameter binding gone wrong (like the claim that a required parameter wasn't bound, the information from this logger might actually contain more helpful information.

The logging was introduced as part of https://jira.spring.io/browse/DATAJPA-1172

@schauder
Copy link
Contributor

This issue will be tracked under https://jira.spring.io/browse/DATAJPA-1179 since it is not related to the examples.

@PawelJagus
Copy link
Author

PawelJagus commented Sep 21, 2017

Thanks for all the hints. Switching off the logging for SpelExpressionStringQueryParameterBinder solves the problem.

@mostafaarefaat
Copy link

@PawelJagus I have the same issue with spring boot 1.5.9 could you help me how it work with you by example

@PawelJagus
Copy link
Author

@mostafaarefaat I added the following line to my application.properties file.

logging.level.org.springframework.data.jpa.repository.query.SpelExpressionStringQueryParameterBinder: OFF

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