Can someone explain this OpenJPA trace?

I'm executing the following code:
        CriteriaBuilder cb = em.getCriteriaBuilder();
        CriteriaQuery<?> q = cb.createQuery();
        Root<?> c = q.from(AnzoURIToPK.class);
        ParameterExpression<String> uriParam = cb.parameter(String.class);
        ParameterExpression<String> typeUriParam =
cb.parameter(String.class);
        q.multiselect(c).where(cb.and(cb.equal(c.get("uriHash"), uriParam),
cb.equal(c.get("typeUriHash"), typeUriParam)));
        TypedQuery<?> query = em.createQuery(q);
        query.setParameter(uriParam, uriHash);
        query.setParameter(typeUriParam, typeUriHash);
        Object result = query.getSingleResult();

I'm assigning this object to be the pk of another object and at commit time
I'm getting following trace. I can't understand where the second query is
coming from with a lookup with pk 0. Anyone have any ideas?


<t 807465830, conn 689339766> executing prepstmnt 571361198 SELECT t0.pk,
t0.datasetUri, t0.datasetUriHash, t0.persitedFully, t0.typeUri,
t0.typeUriHash, t0.uri, t0.uriHash FROM anzouritopk t0 WHERE (t0.uriHash = ?
AND t0.typeUriHash = ?) [params=(String)
a970c5c56f105448f56709071f5cbc647ddbfdad, (String)
4b77c3c0518556463d2a45298a73afbff3d69d16]
<t 807465830, conn 689339766> [0 ms] spent
<t 807465830, conn 0> [1 ms] close
Cache miss while looking up key "0".
<t 807465830, conn 689339766> executing prepstmnt 1800965748 SELECT
t0.datasetUri, t0.datasetUriHash, t0.persitedFully, t0.typeUri,
t0.typeUriHash, t0.uri, t0.uriHash FROM anzouritopk t0 WHERE t0.pk = ?
[params=(long) 0]
<t 807465830, conn 689339766> [0 ms] spent
<t 807465830, conn 0> [0 ms] close
 Executing query: [Query: org.apache.openjpa.kernel.QueryImpl@6c4c4e99;
candidate class: class
com.cambridgesemantics.anzo.relationalreplicator.jpa.model.AnzoURIToPKImpl;
query: null] with parameters: ?

a) why a multiselect() ?
b) what does q.toString() print?




-----
Pinaki Poddar
Chair, Apache OpenJPA Project

q.toString returns:

SELECT a FROM AnzoURIToPKImpl a WHERE (a.uriHash = :param AND a.typeUriHash
= :param)

and this is correct...

It turns out the statement
SELECT t0.datasetUri, t0.datasetUriHash, t0.persistedFully, t0.typeUri,
t0.typeUriHash, t0.uri, t0.uriHash FROM FILM.anzouritopk t0 WHERE t0.pk = ?
[params=(long) 0]

occurs when entityManager.persist(ObjectToPersist) is called.. where obj has
a primary key of anzouritopk object where pk is not yet populated because
it's a generated value.

To illustrate
ObjectToPersist(id=AnzouritopkInstance)
AnzouritopkInstance(pk=null)

here is mapping for AnzoURITOPK id column:
    @Id
    @Column(updatable = false)
    @GeneratedValue(strategy = GenerationType.AUTO)
    public Long getPk() {
        return pk;
    }

Following the code path
return persistInternal(obj, id, explicit, call, fireEvent); in
BrokerImpl.java on line 2571 is called
id == null at line 2639
meta.getIdentityType() is ClassMetaData.ID_APPLICATION
at line 2651 id is now 0
bad select occurs on line 152 as below in stack trace.

Here is stack trace
FinderQueryImpl.execute(OpenJPAStateManager, StoreManager,
FetchConfiguration) line: 152	
JDBCStoreManager.getInitializeStateResult(OpenJPAStateManager, ClassMapping,
JDBCFetchConfiguration, int) line: 537	
JDBCStoreManager.initializeState(OpenJPAStateManager, PCState,
JDBCFetchConfiguration, ConnectionInfo) line: 349	
JDBCStoreManager.initialize(OpenJPAStateManager, PCState,
FetchConfiguration, Object) line: 304	
ROPStoreManager(DelegatingStoreManager).initialize(OpenJPAStateManager,
PCState, FetchConfiguration, Object) line: 112	
ROPStoreManager.initialize(OpenJPAStateManager, PCState, FetchConfiguration,
Object) line: 57	
FinalizingBrokerImpl(BrokerImpl).initialize(StateManagerImpl, boolean,
FetchConfiguration, Object) line: 1036	
FinalizingBrokerImpl(BrokerImpl).find(Object, FetchConfiguration, BitSet,
Object, int, FindCallbacks) line: 994	
FinalizingBrokerImpl(BrokerImpl).find(Object, FetchConfiguration, BitSet,
Object, int) line: 916	
FinalizingBrokerImpl(BrokerImpl).isDetached(Object, boolean) line: 4594	
FinalizingBrokerImpl(BrokerImpl).isDetached(Object) line: 4563	
SingleFieldManager.persist(OpCallbacks) line: 270	
StateManagerImpl.cascadePersist(OpCallbacks) line: 3045	
FinalizingBrokerImpl(BrokerImpl).persistInternal(Object, Object, boolean,
OpCallbacks, boolean) line: 2670	
FinalizingBrokerImpl(BrokerImpl).persist(Object, Object, boolean,
OpCallbacks, boolean) line: 2571	
FinalizingBrokerImpl(BrokerImpl).persist(Object, Object, boolean,
OpCallbacks) line: 2554	
FinalizingBrokerImpl(BrokerImpl).persist(Object, OpCallbacks) line: 2458	
DelegatingBroker.persist(Object, OpCallbacks) line: 1077	
EntityManagerImpl.persist(Object) line: 716

I'd suggest trying to reword your question... I'm struggling to follow what
you're asking here.On Fri, Sep 21, 2012 at 8:42 AM, garpinc  wrote:

> Please someone help here.. I'm dying with this one.. (last big issue I
> think)....
>
>
>
> --

I created a test case for this:
https://issues.apache.org/jira/browse/OPENJPA...

What i'm seeing is that for every persist as select first occurs to db for a
row with a 0 primary key value.. (at least in the event that my primary key
value is a Long). This is a performance issue for me since my application is
processing millions of rows..