Hello,
I'm a newbie :) Help me please to solve my problem. I am using JPA2 with Hibernate 3.3.0-SP1 implementation.
There are 2 entities: CdsVehicleIdentify and Vehicle with one-to-one relationship to each other. Here is the code:
Code:
public class Vehicle implements Serializable {
private static final long serialVersionUID = 7734103370740339135L;
@Id
@Basic(optional = false)
@Column(name = "vehicleNumber")
private Integer vehicleNumber;
............
@OneToOne(cascade = CascadeType.ALL, mappedBy = "vehicle")
private CdsVehicleIdentify cdsVehicleIdentify;
=============================================================
public class CdsVehicleIdentify implements Serializable {
private static final long serialVersionUID = 1L;
@Id
@GeneratedValue(strategy = GenerationType.IDENTITY)
@Basic(optional = false)
@Column(name = "id")
private Integer id;
.........
@JoinColumn(name = "vehicle_id", referencedColumnName = "vehicleNumber")
@OneToOne(optional=false)
private Vehicle vehicle;
The problem is the query "SELECT c FROM CdsVehicleIdentify c JOIN FETCH c.vehicle" is not executed in single SQL query, but if we have 1000 rows in database there will be 1001 SQL-query.
That happens because of Hibernate for some reason cannot lookup in cache just loaded CdsVehicleIdentify entity anre reloads it from database. Here are the logs:
Code:
2011-01-02 02:59:11.134 .ЕТАЛЬНО(2) [su.vistar.gps.cdsforward.core.BusesCache]: О.нов.ен.е к..а авто.усов
2011-01-02 02:59:11.139 .ЕТАЛЬНО(1) [org.hibernate.impl.SessionImpl]: opened session at timestamp: 12939263511
2011-01-02 02:59:11.143 .ЕТАЛЬНО(4) [org.hibernate.engine.query.QueryPlanCache]: located HQL query plan in cache (SELECT c FROM CdsVehicleIdentify c JOIN FETCH c.vehicle)
2011-01-02 02:59:11.147 .ЕТАЛЬНО(4) [org.hibernate.engine.query.QueryPlanCache]: located HQL query plan in cache (SELECT c FROM CdsVehicleIdentify c JOIN FETCH c.vehicle)
2011-01-02 02:59:11.147 .ЕТАЛЬНО(4) [org.hibernate.engine.query.HQLQueryPlan]: find: SELECT c FROM CdsVehicleIdentify c JOIN FETCH c.vehicle
2011-01-02 02:59:11.149 .ЕТАЛЬНО(4) [org.hibernate.engine.QueryParameters]: named parameters: {}
2011-01-02 02:59:11.151 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2011-01-02 02:59:11.152 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: opening JDBC connection
2011-01-02 02:59:11.153 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: total checked-out connections: 0
2011-01-02 02:59:11.153 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: using pooled JDBC connection, pool size: 0
2011-01-02 02:59:11.154 .ЕТАЛЬНО(1) [org.hibernate.SQL]: select cdsvehicle0_.id as id0_0_, vehicle1_.vehicleNumber as vehicleN1_1_1_, cdsvehicle0_.objectCode as objectCode0_0_, cdsvehicle0_.projectCode as projectC3_0_0_, cdsvehicle0_.routeCode as routeCode0_0_, cdsvehicle0_.simPhoneNumber as simPhone5_0_0_, cdsvehicle0_.vehicle_id as vehicle6_0_0_, vehicle1_.comments as comments1_1_, vehicle1_.numsim as numsim1_1_, vehicle1_.numtel as numtel1_1_, vehicle1_.realNumber as realNumber1_1_ from cdsVehicleIdentify cdsvehicle0_ inner join vehicles vehicle1_ on cdsvehicle0_.vehicle_id=vehicle1_.vehicleNumber
2011-01-02 02:59:11.154 .ЕТАЛЬНО(4) [org.hibernate.jdbc.AbstractBatcher]: preparing statement
2011-01-02 02:59:11.158 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to open ResultSet (open ResultSets: 0, globally: 0)
2011-01-02 02:59:11.159 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: processing result set
2011-01-02 02:59:11.160 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result set row: 0
2011-01-02 02:59:11.162 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result row: EntityKey[su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1], EntityKey[su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.163 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: Initializing object from ResultSet: [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1]
2011-01-02 02:59:11.165 .ЕТАЛЬНО(4) [org.hibernate.persister.entity.AbstractEntityPersister]: Hydrating entity: [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1]
2011-01-02 02:59:11.171 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: Initializing object from ResultSet: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.172 .ЕТАЛЬНО(4) [org.hibernate.persister.entity.AbstractEntityPersister]: Hydrating entity: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.172 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result set row: 1
2011-01-02 02:59:11.173 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result row: EntityKey[su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2], EntityKey[su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.173 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: Initializing object from ResultSet: [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2]
2011-01-02 02:59:11.174 .ЕТАЛЬНО(4) [org.hibernate.persister.entity.AbstractEntityPersister]: Hydrating entity: [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2]
2011-01-02 02:59:11.174 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: Initializing object from ResultSet: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.177 .ЕТАЛЬНО(4) [org.hibernate.persister.entity.AbstractEntityPersister]: Hydrating entity: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.177 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: done processing result set (2 rows)
2011-01-02 02:59:11.178 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to close ResultSet (open ResultSets: 1, globally: 1)
2011-01-02 02:59:11.178 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2011-01-02 02:59:11.179 .ЕТАЛЬНО(4) [org.hibernate.jdbc.AbstractBatcher]: closing statement
2011-01-02 02:59:11.179 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: aggressively releasing JDBC connection
2011-01-02 02:59:11.179 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2011-01-02 02:59:11.180 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: returning connection to pool, pool size: 1
2011-01-02 02:59:11.180 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: total objects hydrated: 4
2011-01-02 02:59:11.181 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: resolving associations for [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1]
2011-01-02 02:59:11.181 .ЕТАЛЬНО(4) [org.hibernate.event.def.DefaultLoadEventListener]: loading entity: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.182 .ЕТАЛЬНО(4) [org.hibernate.event.def.DefaultLoadEventListener]: attempting to resolve: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.183 .ЕТАЛЬНО(4) [org.hibernate.event.def.DefaultLoadEventListener]: resolved object in session cache: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.184 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: done materializing entity [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1]
2011-01-02 02:59:11.184 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: resolving associations for [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
Cannot find just loaded CdsVehicleIdentify#1Code:
2011-01-02 02:59:11.187 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: loading entity: [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1]
2011-01-02 02:59:11.187 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2011-01-02 02:59:11.188 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: opening JDBC connection
2011-01-02 02:59:11.188 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: total checked-out connections: 0
2011-01-02 02:59:11.189 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: using pooled JDBC connection, pool size: 0
2011-01-02 02:59:11.189 .ЕТАЛЬНО(1) [org.hibernate.SQL]: select cdsvehicle0_.id as id0_1_, cdsvehicle0_.objectCode as objectCode0_1_, cdsvehicle0_.projectCode as projectC3_0_1_, cdsvehicle0_.routeCode as routeCode0_1_, cdsvehicle0_.simPhoneNumber as simPhone5_0_1_, cdsvehicle0_.vehicle_id as vehicle6_0_1_, vehicle1_.vehicleNumber as vehicleN1_1_0_, vehicle1_.comments as comments1_0_, vehicle1_.numsim as numsim1_0_, vehicle1_.numtel as numtel1_0_, vehicle1_.realNumber as realNumber1_0_ from cdsVehicleIdentify cdsvehicle0_ inner join vehicles vehicle1_ on cdsvehicle0_.vehicle_id=vehicle1_.vehicleNumber where cdsvehicle0_.vehicle_id=?
2011-01-02 02:59:11.190 .ЕТАЛЬНО(4) [org.hibernate.jdbc.AbstractBatcher]: preparing statement
2011-01-02 02:59:11.193 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to open ResultSet (open ResultSets: 0, globally: 0)
2011-01-02 02:59:11.193 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: processing result set
2011-01-02 02:59:11.194 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result set row: 0
2011-01-02 02:59:11.195 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result row: EntityKey[su.vistar.gps.cdsforward.persistence.entities.Vehicle#1], EntityKey[su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#1]
2011-01-02 02:59:11.195 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: done processing result set (1 rows)
2011-01-02 02:59:11.196 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to close ResultSet (open ResultSets: 1, globally: 1)
2011-01-02 02:59:11.196 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2011-01-02 02:59:11.197 .ЕТАЛЬНО(4) [org.hibernate.jdbc.AbstractBatcher]: closing statement
2011-01-02 02:59:11.197 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: aggressively releasing JDBC connection
2011-01-02 02:59:11.198 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2011-01-02 02:59:11.198 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: returning connection to pool, pool size: 1
2011-01-02 02:59:11.199 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: total objects hydrated: 0
2011-01-02 02:59:11.199 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: done entity load
2011-01-02 02:59:11.200 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: done materializing entity [su.vistar.gps.cdsforward.persistence.entities.Vehicle#1]
2011-01-02 02:59:11.200 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: resolving associations for [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2]
2011-01-02 02:59:11.201 .ЕТАЛЬНО(4) [org.hibernate.event.def.DefaultLoadEventListener]: loading entity: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.201 .ЕТАЛЬНО(4) [org.hibernate.event.def.DefaultLoadEventListener]: attempting to resolve: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.201 .ЕТАЛЬНО(4) [org.hibernate.event.def.DefaultLoadEventListener]: resolved object in session cache: [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.202 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: done materializing entity [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2]
2011-01-02 02:59:11.202 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: resolving associations for [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.203 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: loading entity: [su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2]
2011-01-02 02:59:11.203 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2011-01-02 02:59:11.204 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: opening JDBC connection
2011-01-02 02:59:11.204 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: total checked-out connections: 0
2011-01-02 02:59:11.205 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: using pooled JDBC connection, pool size: 0
2011-01-02 02:59:11.205 .ЕТАЛЬНО(1) [org.hibernate.SQL]: select cdsvehicle0_.id as id0_1_, cdsvehicle0_.objectCode as objectCode0_1_, cdsvehicle0_.projectCode as projectC3_0_1_, cdsvehicle0_.routeCode as routeCode0_1_, cdsvehicle0_.simPhoneNumber as simPhone5_0_1_, cdsvehicle0_.vehicle_id as vehicle6_0_1_, vehicle1_.vehicleNumber as vehicleN1_1_0_, vehicle1_.comments as comments1_0_, vehicle1_.numsim as numsim1_0_, vehicle1_.numtel as numtel1_0_, vehicle1_.realNumber as realNumber1_0_ from cdsVehicleIdentify cdsvehicle0_ inner join vehicles vehicle1_ on cdsvehicle0_.vehicle_id=vehicle1_.vehicleNumber where cdsvehicle0_.vehicle_id=?
2011-01-02 02:59:11.206 .ЕТАЛЬНО(4) [org.hibernate.jdbc.AbstractBatcher]: preparing statement
2011-01-02 02:59:11.209 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to open ResultSet (open ResultSets: 0, globally: 0)
2011-01-02 02:59:11.209 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: processing result set
2011-01-02 02:59:11.210 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result set row: 0
2011-01-02 02:59:11.211 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: result row: EntityKey[su.vistar.gps.cdsforward.persistence.entities.Vehicle#2], EntityKey[su.vistar.gps.cdsforward.persistence.entities.CdsVehicleIdentify#2]
2011-01-02 02:59:11.211 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: done processing result set (1 rows)
2011-01-02 02:59:11.212 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to close ResultSet (open ResultSets: 1, globally: 1)
2011-01-02 02:59:11.212 .ЕТАЛЬНО(1) [org.hibernate.jdbc.AbstractBatcher]: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2011-01-02 02:59:11.213 .ЕТАЛЬНО(4) [org.hibernate.jdbc.AbstractBatcher]: closing statement
2011-01-02 02:59:11.213 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: aggressively releasing JDBC connection
2011-01-02 02:59:11.214 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2011-01-02 02:59:11.214 .ЕТАЛЬНО(4) [org.hibernate.connection.DriverManagerConnectionProvider]: returning connection to pool, pool size: 1
2011-01-02 02:59:11.214 .ЕТАЛЬНО(4) [org.hibernate.loader.Loader]: total objects hydrated: 0
2011-01-02 02:59:11.215 .ЕТАЛЬНО(1) [org.hibernate.loader.Loader]: done entity load
2011-01-02 02:59:11.215 .ЕТАЛЬНО(1) [org.hibernate.engine.TwoPhaseLoad]: done materializing entity [su.vistar.gps.cdsforward.persistence.entities.Vehicle#2]
2011-01-02 02:59:11.216 .ЕТАЛЬНО(1) [org.hibernate.engine.StatefulPersistenceContext]: initializing non-lazy collections
2011-01-02 02:59:11.216 .ЕТАЛЬНО(4) [org.hibernate.jdbc.JDBCContext]: after autocommit
2011-01-02 02:59:11.217 .ЕТАЛЬНО(1) [org.hibernate.jdbc.ConnectionManager]: aggressively releasing JDBC connection
2011-01-02 02:59:11.217 .ЕТАЛЬНО(4) [org.hibernate.impl.SessionImpl]: after transaction completion
2011-01-02 02:59:11.218 .ЕТАЛЬНО(4) [org.hibernate.impl.SessionImpl]: closing session
2011-01-02 02:59:11.218 .ЕТАЛЬНО(4) [org.hibernate.jdbc.ConnectionManager]: connection already null in cleanup : no action
2011-01-02 02:59:11.220 .ЕТАЛЬНО(4) [su.vistar.gps.cdsforward.core.BusesCache]: О.нов.ен.е к..а авто.усов .авер.ено
It does not resolve because of EntityType.isReferenceToPrimaryKey() returns false in EntityType.resolve(...) at EntityType.java:411, and sure it is not a primary key, because of it is only hold on another side. But shouldn't Hibernate also look in the cache in case of fetch joins? Or am i doing something wrong? Please help.
Also, the assotiation for CdsVehicleIdentify is determined as ManyToOne as a debugger says in initializeEntity(...): Type[] types = persister.getPropertyTypes(); (TwoPhaseLoad.java:135)
Login
FAQ
Search