Home » Eclipse Projects » EclipseLink » Ripple Load across optional ManyToOne using EclipseLink 2.6.0(Ripple Load across optional ManyToOne using EclipseLink 2.6.0)
Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1691285] |
Sat, 04 April 2015 15:21  |
Eclipse User |
|
|
|
Hello,
We are using EclipseLink 2.6.0 as our JPA 2 provider and are experiencing an unexpected ripple load when using an outer join fetch across an optional ManyToOne relationship. We have a class A that has an optional ManyToOne relationship to a class B and we are trying to hydrate all As, and their Bs, that meet criteria on the A instances. Our JPQL query is of the form :
"from A a left join fetch a.b where a.property = ..."
What we see is that this reads the 30 A instances as we expect, but requires 31 database queries. The first query reads the 30 A rows, whereas each subsequent query reads a B row. We would expect this would just work with at most two queries to the database due to the join fetch present in the JPQL query.
What we have seen is that if we use an EclipseLink specific QueryHint of BATCH, we do in fact get the desired number of queries emitted at the database, just two, but then we are using an extension that is outside the JPA standard. We would like our query to just need to use JPA standard techniques.
I expect this is a defect though, that the original query we had written should have just worked without having to resort to the use of a QueryHint.
In our environment, we use MySQL as our RDBMS, Spring as our container, JDK 1.7, and of course EclipseLink 2.6.0.
Has anyone else had this experience or found a standard JPA solution? One thing I need to verify is that our classes are being weaved correctly. I suspect that is the case though since we use lazy loading across relationships, including the one noted above, and are not experiencing any errors to our knowledge.
Thanks, Doug
|
|
| |
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1691386 is a reply to message #1691289] |
Mon, 06 April 2015 21:08   |
Eclipse User |
|
|
|
Another update. We did in fact have weaving disabled. However, after enabling load time weaving, we are still seeing the ripple load if we do not use a QueryHint. I see the following kinds of entries in our log file indicating that load time weaving is taking place :
[EL Finer]: weaver: 2015-04-06 20:04:18.451--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.OpportunitySegmentSpec] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.455--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.OpportunityFamilyLink] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.455--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.Opportunity] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.455--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.OpportunityFamily] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.455--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.Placeholder] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.455--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.ActionSpec] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.455--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.OpportunitySpec] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.456--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.OpportunitySegment] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.456--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.EmployeeTest] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.456--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.Segment] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.456--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.DepartmentTest] registered to be processed by weaver.
[EL Finer]: weaver: 2015-04-06 20:04:18.456--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Class [com.castlight.opportunityservice.model.RecommendationSpec] registered to be processed by weaver.
[EL Finer]: metamodel: 2015-04-06 20:04:18.662--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.ActionSpec_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.663--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.DepartmentTest_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.664--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.EmployeeTest_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.664--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.Opportunity_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.665--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.OpportunityFamily_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.665--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.OpportunityFamilyLink_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.666--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.OpportunitySegment_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.666--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.OpportunitySegmentSpec_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.667--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.OpportunitySpec_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.667--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.Placeholder_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.668--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.RecommendationSpec_] not found during initialization.
[EL Finer]: metamodel: 2015-04-06 20:04:18.668--ServerSession(887443069)--Thread(Thread[localhost-startStop-1,5,main])--Canonical Metamodel class [com.castlight.opportunityservice.model.Segment_] not found during initialization.
Is anyone aware of what might be the problem? Maybe those Canonical Metamodel classes not found during initialization is contributing here?
Any thoughts appreciated. Thanks,
Doug
|
|
|
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1691621 is a reply to message #1691386] |
Wed, 08 April 2015 13:59   |
Eclipse User |
|
|
|
Logging on Finest might show some details of what is happening while the query is executing. Are the 'A' instance being read in already in the cache? You might try the refresh query hint just to see if the problem is that they are already built, and so have an existing contract on how referenced Bs should be obtained. Using a refresh will force the relationship to be rebuilt using the current query.
|
|
| |
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1691827 is a reply to message #1691621] |
Fri, 10 April 2015 01:14   |
Eclipse User |
|
|
|
Ok, I have reason to believe we have load time weaving now working. I see entries like the following in our log file :
[EL Finest]: weaver: 2015-04-10 01:04:04.96--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Begin weaver class transformer processing class [com/castlight/planservice/model/ProcedureFamilyEntity].
[EL Finest]: weaver: 2015-04-10 01:04:04.96--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Weaved change tracking (ChangeTracker) [com/castlight/planservice/model/ProcedureFamilyEntity].
[EL Finest]: weaver: 2015-04-10 01:04:04.96--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Weaved fetch groups (FetchGroupTracker) [com/castlight/planservice/model/ProcedureFamilyEntity].
[EL Finest]: weaver: 2015-04-10 01:04:04.96--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--End weaver class transformer processing class [com/castlight/planservice/model/ProcedureFamilyEntity].
[EL Finest]: properties: 2015-04-10 01:04:04.972--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--property=eclipselink.logging.level; value=FINEST
[EL Finest]: properties: 2015-04-10 01:04:04.972--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--property=eclipselink.logging.level; value=FINEST
[EL Finest]: properties: 2015-04-10 01:04:04.972--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--property=eclipselink.target-database; value=org.eclipse.persistence.platform.database.MySQLPlatform
[EL Info]: 2015-04-10 01:04:04.976--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--EclipseLink, version: Eclipse Persistence Services - 2.6.0.v20150309-bf26070
To answer your question though Chris, the As being read are not in the shared cache. I start up the Java runtime, no cache warming is taking place, I issue a request that causes the offending read to occur and the ripple loading is evidenced by log file entries of the form :
[EL Finest]: query: 2015-04-10 01:04:05.298--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--Execute query ReadAllQuery(referenceClass=BenefitExplanation sql="SELECT ID, created_at, employer_id, end_date, explanation_text, generate_search_link, help_text, hyperlink_text, insurance_company_id, insurance_plan_id, oop_text_json, preventive_text, service_category, service_name, service_name_order, service_subcategory, start_date, subject_to_rbb, updated_at, procedure_family_id FROM my_health_plan_blurbs WHERE (((employer_id = ?) AND (CURRENT_DATE BETWEEN start_date AND end_date)) AND (insurance_plan_id = ?))")
[EL Finest]: connection: 2015-04-10 01:04:05.3--ServerSession(1107754505)--Connection(2007559584)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection acquired from connection pool [read].
[EL Finest]: connection: 2015-04-10 01:04:05.3--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--reconnecting to external connection pool
[EL Fine]: sql: 2015-04-10 01:04:05.3--ServerSession(1107754505)--Connection(1938350271)--Thread(Thread[http-bio-8860-exec-1,5,main])--SELECT ID, created_at, employer_id, end_date, explanation_text, generate_search_link, help_text, hyperlink_text, insurance_company_id, insurance_plan_id, oop_text_json, preventive_text, service_category, service_name, service_name_order, service_subcategory, start_date, subject_to_rbb, updated_at, procedure_family_id FROM my_health_plan_blurbs WHERE (((employer_id = ?) AND (CURRENT_DATE BETWEEN start_date AND end_date)) AND (insurance_plan_id = ?))
bind => [9, 19125]
[EL Finest]: connection: 2015-04-10 01:04:05.331--ServerSession(1107754505)--Connection(2007559584)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection released to connection pool [read].
[EL Finer]: transaction: 2015-04-10 01:04:05.346--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--begin unit of work commit
[EL Finer]: transaction: 2015-04-10 01:04:05.347--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--end unit of work commit
[EL Finer]: transaction: 2015-04-10 01:04:05.348--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--resume unit of work
[EL Finer]: transaction: 2015-04-10 01:04:05.348--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--release unit of work
[EL Finer]: connection: 2015-04-10 01:04:05.348--ClientSession(1060733533)--Thread(Thread[http-bio-8860-exec-1,5,main])--client released
[EL Finest]: query: 2015-04-10 01:04:05.439--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Execute query ReadObjectQuery(name="procedureFamily" referenceClass=ProcedureFamilyEntity )
[EL Finest]: connection: 2015-04-10 01:04:05.44--ServerSession(1107754505)--Connection(1105143746)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection acquired from connection pool [read].
[EL Finest]: connection: 2015-04-10 01:04:05.44--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--reconnecting to external connection pool
[EL Fine]: sql: 2015-04-10 01:04:05.44--ServerSession(1107754505)--Connection(564876119)--Thread(Thread[http-bio-8860-exec-1,5,main])--SELECT ID, name FROM procedure_families WHERE (ID = ?)
bind => [133]
[EL Finest]: connection: 2015-04-10 01:04:05.441--ServerSession(1107754505)--Connection(1105143746)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection released to connection pool [read].
[EL Finest]: transaction: 2015-04-10 01:04:05.442--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--Register the existing object com.castlight.planservice.model.ProcedureFamilyEntity@1a0074fb[id=133]
[EL Finest]: query: 2015-04-10 01:04:05.443--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Execute query ReadObjectQuery(name="procedureFamily" referenceClass=ProcedureFamilyEntity )
[EL Finest]: connection: 2015-04-10 01:04:05.443--ServerSession(1107754505)--Connection(304910759)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection acquired from connection pool [read].
[EL Finest]: connection: 2015-04-10 01:04:05.443--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--reconnecting to external connection pool
[EL Fine]: sql: 2015-04-10 01:04:05.443--ServerSession(1107754505)--Connection(739144771)--Thread(Thread[http-bio-8860-exec-1,5,main])--SELECT ID, name FROM procedure_families WHERE (ID = ?)
bind => [134]
[EL Finest]: connection: 2015-04-10 01:04:05.444--ServerSession(1107754505)--Connection(304910759)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection released to connection pool [read].
[EL Finest]: transaction: 2015-04-10 01:04:05.444--UnitOfWork(2039227923)--Thread(Thread[http-bio-8860-exec-1,5,main])--Register the existing object com.castlight.planservice.model.ProcedureFamilyEntity@6b8ca025[id=134]
[EL Finest]: query: 2015-04-10 01:04:05.444--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Execute query ReadObjectQuery(name="procedureFamily" referenceClass=ProcedureFamilyEntity )
[EL Finest]: connection: 2015-04-10 01:04:05.444--ServerSession(1107754505)--Connection(1488894331)--Thread(Thread[http-bio-8860-exec-1,5,main])--Connection acquired from connection pool [read].
[EL Finest]: connection: 2015-04-10 01:04:05.445--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--reconnecting to external connection pool
[EL Fine]: sql: 2015-04-10 01:04:05.445--ServerSession(1107754505)--Connection(1367566273)--Thread(Thread[http-bio-8860-exec-1,5,main])--SELECT ID, name FROM procedure_families WHERE (ID = ?)
bind => [91]
For what its worth, warnings of the following nature are still being seen at startup, prior to any inbound requests to the Java runtime :
[EL Finer]: metamodel: 2015-04-10 01:04:05.033--ServerSession(1107754505)--Thread(Thread[http-bio-8860-exec-1,5,main])--Canonical Metamodel class [com.castlight.planservice.model.BenefitExplanation_] not found during initialization.
So, any further ideas? We can certainly resort to QueryHints for the short term, but for the long term do not want to use facilities outside the JPA spec.
Thanks, Doug
|
|
| |
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1692133 is a reply to message #1692126] |
Mon, 13 April 2015 18:33   |
Eclipse User |
|
|
|
Hi Chris, sorry for not posting that earlier, but yes, let me share that code in question:
IdentifiedEntity.java:
@MappedSuperclass
@Access(AccessType.FIELD)
public abstract class IdentifiedEntity {
@Id
@GeneratedValue(strategy = GenerationType.IDENTITY)
private long id;
...
}
AuditedEntity.java:
@MappedSuperclass
@Access(AccessType.FIELD)
public abstract class AuditedEntity extends IdentifiedEntity {
...
@Temporal(TemporalType.TIMESTAMP)
@Column(name = "created_at", nullable=false, updatable=false)
private Date createdAt;
@Temporal(TemporalType.TIMESTAMP)
@Column(name = "updated_at", nullable=false)
private Date updatedAt;
...
}
BenefitExplanation.java:
@Access(AccessType.FIELD)
@Entity
@Table(name = "my_health_plan_blurbs") // eventually will rename this table
public class BenefitExplanation extends AuditedEntity {
...
@ManyToOne(fetch = FetchType.LAZY)
@JoinColumn(name = "procedure_family_id")
private ProcedureFamilyEntity procedureFamily;
...
}
BenefitExplanationRepository.java:
@Transactional(value = JPAConfiguration.TX_MANAGER_NAME, readOnly = true)
public List<BenefitExplanation> findBy(long employerId, long insurancePlanId, Long dentalInsurancePlanId) {
logger.debug("getExplanations() called: employerId [" + employerId
+ "] insurancePlanId [" + insurancePlanId + "] dentalInsurancePlanId [" + dentalInsurancePlanId + "]");
String jpql = "FROM BenefitExplanation be left join fetch be.procedureFamily"
+ " WHERE be.employerId = :employerId"
+ " AND (current_date BETWEEN be.startDate AND be.endDate)";
final String clause2 = "be.insurancePlanId = :insurancePlanId";
if (dentalInsurancePlanId == null) {
jpql += " AND " + clause2;
}
else {
jpql += " AND (" + clause2 + " or be.insurancePlanId = :dentalInsurancePlanId)";
}
TypedQuery<BenefitExplanation> q = em.createQuery(jpql, BenefitExplanation.class);
q.setHint(QueryHints.LEFT_FETCH, "be.procedureFamily");
q.setParameter("employerId", employerId);
q.setParameter("insurancePlanId", insurancePlanId);
if (dentalInsurancePlanId != null) {
q.setParameter("dentalInsurancePlanId", dentalInsurancePlanId);
}
return q.getResultList();
}
There is no JPA mapping from ProcedureFamilyEntity to BenefitExplanation.
Note that query as written does not experience the ripple load due to the use of the LEFT_FETCH query hint, but with that line of code commented out, the ripple load is experienced.
Thanks,
Doug
|
|
| |
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1692281 is a reply to message #1692268] |
Tue, 14 April 2015 17:40   |
Eclipse User |
|
|
|
Hi Dmitry,
Yes, we did try that to see if that would resolve the issue, but haven't tried it again since we enabled load time weaving. It did not resolve the issue at that time.
The reality though is that we do not want that particular relationship to always be eagerly loaded, hence why it is marked to be lazy loaded, so that we can eagerly load the relationship on a query by query basis.
Thanks,
Doug
|
|
|
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1692724 is a reply to message #1692281] |
Fri, 17 April 2015 13:04   |
Eclipse User |
|
|
|
I cannot explain why both the fetch and the fetch query hint would be ignored In EclipseLink, but this is still not quite complete as your 'jpql' variable is only showing a statement beginning with the from clause - I thought JPA/EclipseLink requires a complete JQPL statement that includes the select clause. Can you try printing off the string you pass to the createQuery and then show the logs from that point on?
|
|
| |
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1692812 is a reply to message #1692724] |
Sun, 19 April 2015 16:00   |
Eclipse User |
|
|
|
Hey Chris,
If we use the LEFT_FETCH QueryHint, the ripple load is in fact eliminated, only two SQL select statements are emitted by EclipseLink rather than some 31. However, when we comment out the QueryHint, we do see the ripple loading taking place and thus some 31 SQL select statements. With both of these, we use left join fetch in the JPQL query itself.
In any case, I will respond later today with the additional information you have requested.
Thanks, Doug
|
|
|
Re: Ripple Load across optional ManyToOne using EclipseLink 2.6.0 [message #1692815 is a reply to message #1692724] |
Sun, 19 April 2015 18:10  |
Eclipse User |
|
|
|
Hi Chris,
You read that correctly. Our JPQL statement was of the form "FROM BenefitExplanation be left join fetch be.procedureFamily ...", there was no beginning "select be " in our JPQL statement. That was by intent due to previous experience with Hibernate.
In any case, by changing our JPQL statement to be of the form "select be FROM BenefitExplanation be left join fetch ....", the ripple loading was eliminated without the use of QueryHints!
In my reading on this topic, I don't see where the select or expression elements are optional in a JPQL "select expression from ..." statement, at least not per JPA. Maybe Hibernate allows you to omit that part of a statement. Still not sure why EclipseLink didn't simply reject the query for being malformed.
So, between getting load time weaving working properly and tweaking that JPQL query to begin with "select be ", our ripple loading issue appears to have been resolved.
Thank you, Doug
|
|
|
Goto Forum:
Current Time: Mon Feb 10 04:05:28 GMT 2025
Powered by FUDForum. Page generated in 0.05176 seconds
|