Broken 'with key(...)' operator on entity-key maps

Description

I think I find a regression in Hibernate 5.4.22 when 'with key(...)' operator is used on a map using entity as key.

I push two branch on a forked github repo to expose this use-case. Both use exactly the same patch to add a new test class.

I launch the test-case with : ./gradlew :hibernate-core:test --tests org.hibernate.test.jpa.ql.MapIssueTest -Pdb=pgsql --debug

https://github.com/lalmeras/hibernate-orm/tree/issue-with-key : based on 5.4.22 -> OK
https://github.com/lalmeras/hibernate-orm/tree/issue-with-key-5.4.21 : based on 5.4.21 -> KO for MapIssueTest.testWhereSubqueryMapKeyIsEntityWhereWithKey

Use case and issue description :

MapOwner has a field 'contents' that is a Map<Relationship, MapContent>
map key Relationship is determined from MapContent.relationship field

JPQL query select r from Relationship r where exists (select 1 from MapOwner as o left join o.contents c with key(c) = r) fails with :

2020-10-23T16:47:16.405+0200 [DEBUG] [TestEventLogger] org.hibernate.test.jpa.ql.MapIssueTest > testWhereSubqueryMapKeyIsEntityWhereWithKey FAILED
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]     javax.persistence.PersistenceException: org.hibernate.exception.SQLGrammarException: could not extract ResultSet
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1542)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.hibernate.test.jpa.ql.MapIssueTest.testWhereSubqueryMapKeyIsEntityWhereWithKey(MapIssueTest.java:31)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:498)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.hibernate.testing.junit4.ExtendedFrameworkMethod.invokeExplosively(ExtendedFrameworkMethod.java:45)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         at java.lang.Thread.run(Thread.java:748)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger] 
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         Caused by:
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]         org.hibernate.exception.SQLGrammarException: could not extract ResultSet
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:103)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:67)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.getResultSet(Loader.java:2304)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2057)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2019)
2020-10-23T16:47:16.406+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.doQuery(Loader.java:948)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.doList(Loader.java:2850)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.doList(Loader.java:2832)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2664)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.Loader.list(Loader.java:2659)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:506)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:400)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1414)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1565)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1533)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             ... 16 more
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger] 
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             Caused by:
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]             org.postgresql.util.PSQLException: ERROR: missing FROM-clause entry for table "contents2_"
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]               Position: 250
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2497)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2233)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:310)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:446)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:370)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:149)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:108)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57)
2020-10-23T16:47:16.407+0200 [DEBUG] [TestEventLogger]                 ... 31 more

SQL generated is wrong with 5.4.22 ; contents2_ is used before its availability :

SELECT
	relationsh0_.id AS id1_3_,
	relationsh0_.name AS name2_3_
FROM
	Relationship relationsh0_
WHERE
	EXISTS (
	SELECT
		1
	FROM
		MapOwner mapowner1_
	LEFT OUTER JOIN Relationship relationsh4_ ON
		(
		SELECT
			a15.relationship_id
		FROM
			MapContent a15
		WHERE
			a15.id = contents2_.contents_id)= relationsh4_.id
	LEFT OUTER JOIN (MapOwner_MapContent contents2_
	LEFT OUTER JOIN MapContent mapcontent3_ ON
		contents2_.contents_id = mapcontent3_.id) ON
		mapowner1_.id = contents2_.MapOwner_id
		AND ((
		SELECT
			a15.relationship_id
		FROM
			MapContent a15
		WHERE
			a15.id = contents2_.contents_id)= relationsh0_.id))

SQL generated with 5.4.21 (working) (join order is different) :

SELECT
	relationsh0_.id AS id1_3_,
	relationsh0_.name AS name2_3_
FROM
	Relationship relationsh0_
WHERE
	EXISTS (
	SELECT
		1
	FROM
		MapOwner mapowner1_
	LEFT OUTER JOIN (MapOwner_MapContent contents2_
	LEFT OUTER JOIN MapContent mapcontent3_ ON
		contents2_.contents_id = mapcontent3_.id) ON
		mapowner1_.id = contents2_.MapOwner_id
		AND ((
		SELECT
			a6.relationship_id
		FROM
			MapContent a6
		WHERE
			a6.id = contents2_.contents_id)= relationsh0_.id)
	LEFT OUTER JOIN Relationship relationsh4_ ON
		(
		SELECT
			a6.relationship_id
		FROM
			MapContent a6
		WHERE
			a6.id = contents2_.contents_id)= relationsh4_.id)

This use-case in an extract of a real issue we encounter when we update Hibernate to 5.4.22 on one of our project. As observed with this test-case, Hibernate 5.4.21 is working fine on the same codebase (and is know to work fine since Hibernate 5.1.

During my work on this use-case, it seems to me that :

Issue is linked to the use of entity-based map key (using a value is not a issue)
Issue also exists where key is part of the relation (only key extracted from target value field included in use-case)
Issue triggers with HSQL and JPQL queries (only JPQL case included in use-case)

Linked issues

Activity

Laurent AlmerasNovember 3, 2020 at 4:37 PM

Thanks for you quick reply !

Christian BeikovNovember 3, 2020 at 7:12 AM

You are correct, the fix isn’t part of 5.4.23. Sanne added the fix version on the other issue which I fixed so I assumed he merged it already, but apparently it slipped through. Anyway, you can track the progress on https://hibernate.atlassian.net/browse/HHH-14288

Laurent AlmerasNovember 2, 2020 at 5:22 PM

Can you confirm that this fix is not embedded in just released 5.4.23 version ? Not sure if I miss something in git history, but it seems to me that proposed fix was not applied to 5.4 branch.

Can you update fix version consistently ?

Duplicate

Details
Assignee
Christian Beikov
Reporter
Laurent Almeras
Worked in
5.4.21
Components
hibernate-core
Fix versions
5.5.0.Alpha1
5.4.24
Affects versions
5.4.22
Priority
Major

Created October 23, 2020 at 3:22 PM

Updated December 19, 2020 at 12:58 PM

Resolved November 3, 2020 at 7:12 AM

Broken 'with key(...)' operator on entity-key maps

Description

Linked issues

caused by

causes

duplicates

Activity

Laurent AlmerasNovember 3, 2020 at 4:37 PM

Christian BeikovNovember 3, 2020 at 7:12 AM

Laurent AlmerasNovember 2, 2020 at 5:22 PM

Details
Assignee
Christian Beikov
Reporter
Laurent Almeras
Worked in
5.4.21
Components
hibernate-core
Fix versions
5.5.0.Alpha1
5.4.24
Affects versions
5.4.22
Priority
Major

Details

Assignee

Reporter

Worked in

Components

Fix versions

Affects versions

Priority

Flag notifications

Something's gone wrong

Broken 'with key(...)' operator on entity-key maps

Description

Linked issues

caused by

causes

duplicates

Activity

Laurent AlmerasNovember 3, 2020 at 4:37 PM

Christian BeikovNovember 3, 2020 at 7:12 AM

Laurent AlmerasNovember 2, 2020 at 5:22 PM

DetailsAssigneeChristian BeikovChristian BeikovReporterLaurent AlmerasLaurent AlmerasWorked in5.4.21Componentshibernate-coreFix versions5.5.0.Alpha15.4.24Affects versions5.4.22PriorityMajor

Details

Assignee

Reporter

Worked in

Components

Fix versions

Affects versions

Priority

Flag notifications

Something's gone wrong

Details
Assignee
Christian Beikov
Reporter
Laurent Almeras
Worked in
5.4.21
Components
hibernate-core
Fix versions
5.5.0.Alpha1
5.4.24
Affects versions
5.4.22
Priority
Major