X-CGP-ClamAV-Result: CLEAN X-VirusScanner: Niversoft's CGPClamav Helper v1.22.2a (ClamAV engine v0.102.2) X-Junk-Score: 0 [] X-KAS-Score: 0 [] From: "OCsite" Received: from smtp-beta-1.zoner.com ([217.198.120.66] verified) by post.selbstdenker.com (CommuniGate Pro SMTP 6.3.3) with ESMTPS id 26007652 for webobjects-dev@wocommunity.org; Fri, 11 Jun 2021 15:21:20 +0200 Received-SPF: none receiver=post.selbstdenker.com; client-ip=217.198.120.66; envelope-from=ocs@ocs.cz Received: from smtp.zoner.com (smtp.zoner.com [217.198.120.6]) (using TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp-beta-1.zoner.com (Postfix) with ESMTPS id 61D5C1800AD9 for ; Fri, 11 Jun 2021 15:21:00 +0200 (CEST) Received: from smtpclient.apple (smtp2stechovice.cli-eurosignal.cz [77.240.99.254]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) (Authenticated sender: ocs@ocs.cz) by smtp.zoner.com (Postfix) with ESMTPSA id BA404300007D for ; Fri, 11 Jun 2021 15:20:59 +0200 (CEST) Content-Type: multipart/alternative; boundary="Apple-Mail=_F93FDF68-916B-48D9-BEC7-15934E85372B" Mime-Version: 1.0 (Mac OS X Mail 14.0 \(3654.100.0.2.22\)) Subject: Re: [WO-DEV] Cannot determine primary key for entity Date: Fri, 11 Jun 2021 15:20:59 +0200 References: To: WebObjects & WOnder Development In-Reply-To: Message-Id: X-Mailer: Apple Mail (2.3654.100.0.2.22) --Apple-Mail=_F93FDF68-916B-48D9-BEC7-15934E85372B Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 P.S. When log4j.logger.er.transaction.adaptor.EOAdaptorDebugEnabled is = set to DEBUG, it seems the offending fetch looks like this: =3D=3D=3D 15:03:36.633 DEBUG =3D=3D=3D Begin Internal Transaction = //log:NSLog [WorkerThread1] 15:03:36.633 DEBUG evaluateExpression: = //log:NSLog [WorkerThread1] 15:03:37.155 DEBUG 5749 row(s) processed //log:NSLog = [WorkerThread1] 15:03:37.196 DEBUG =3D=3D=3D Commit Internal Transaction = //log:NSLog [WorkerThread1] =3D=3D=3D A number of times it runs all right; then something like this happens: =3D=3D=3D 15:05:48.528 DEBUG =3D=3D=3D Begin Internal Transaction = //log:NSLog [WorkerThread5] 15:05:48.528 DEBUG evaluateExpression: = //log:NSLog [WorkerThread5] 15:05:49.937 DEBUG fetch canceled //log:NSLog [WorkerThread5] 15:05:49.937 DEBUG 164 row(s) processed //log:NSLog = [WorkerThread5] 15:05:49.941 DEBUG =3D=3D=3D Commit Internal Transaction = //log:NSLog [WorkerThread5] 15:05:49.941 INFO Database Exception occured: = java.lang.IllegalArgumentException: Cannot determine primary key for = entity DBRecord from row: {... uid =3D = ; ... } = //log:er.transaction.adaptor.Exceptions [WorkerThread5] =3D=3D=3D Any idea what might go wrong and how to fix it? Thanks! OC > On 11. 6. 2021, at 13:37, OCsite = wrote: >=20 > Hi there, >=20 > just bumped into another weird EOF case. A pretty plain fetch caused a = =E2=80=9CCannot determine primary key for entity=E2=80=9D exception. The = row contains a number of columns whose values makes sense, some null, = some non-null, with one exception =E2=80=94 the primary key, modelled as = an attribute uid, is indeed a null, thus the exception makes a perfect = sense. >=20 > How can this happen? >=20 > =3D=3D=3D > IllegalArgumentException: Cannot determine primary key for entity = DBRecord from row: {... uid =3D = ; ... } > at = com.webobjects.eoaccess.EODatabaseChannel._fetchObject(EODatabaseChannel.j= ava:348) > ... skipped 2 stack elements > at = com.webobjects.eocontrol.EOObjectStoreCoordinator.objectsWithFetchSpecific= ation(EOObjectStoreCoordinator.java:488) > at = com.webobjects.eocontrol.EOEditingContext.objectsWithFetchSpecification(EO= EditingContext.java:4069) > at = er.extensions.eof.ERXEC.objectsWithFetchSpecification(ERXEC.java:1215) > ... skipped 1 stack elements > at = com.webobjects.eocontrol.EOObjectStoreCoordinator.objectsForSourceGlobalID= (EOObjectStoreCoordinator.java:634) > at = com.webobjects.eocontrol.EOEditingContext.objectsForSourceGlobalID(EOEditi= ngContext.java:3923) > at er.extensions.eof.ERXEC.objectsForSourceGlobalID(ERXEC.java:1178) > ... skipped 1 stack elements > at = com.webobjects.eoaccess.EOAccessArrayFaultHandler.completeInitializationOf= Object(EOAccessArrayFaultHandler.java:77) > at = com.webobjects.eocontrol._EOCheapCopyMutableArray.willRead(_EOCheapCopyMut= ableArray.java:45) > at = com.webobjects.eocontrol._EOCheapCopyMutableArray.count(_EOCheapCopyMutabl= eArray.java:103) > at com.webobjects.foundation.NSArray.isEmpty(NSArray.java:1888) > ... > =3D=3D=3D >=20 > Just in case it happens to be important (I believe it is not), the = problem happens at row >=20 > ... =3Deolist.representedObject.records().isEmpty()?...:... >=20 > where records just returns storedValueForKey('records'), = self-evidently a fault, which fires to fetch the rows. >=20 > Searching the Web, all I've found is this = (linked from = here = ), which does not really help :) Truth is, some = background threads do run at the moment; they are comparatively plain = though and I can't see why they should cause the problem for the R/R = thread. All they do is to >=20 > 1. get their own OSC from the pool, making sure they never get the = same OSC normal sessions have > 2. create a new ERXEC in this OSC > 3. get a local instance of an object in the EC >=20 > =3D=3D=3D this is the code of the background thread; a number of those = runs: > def store > for (def pool=3DERXObjectStoreCoordinatorPool._pool();;) { > store=3Dpool.nextObjectStore > if (store!=3D_sessionosc) break // there's one OSC for all = sessions, stored in _sessionosc > } > return = eo.localInstanceIn(ERXEC.newEditingContext(store)).numberOfMasterRowsWitho= utOwner() > =3D=3D=3D >=20 > and the method simply fetches: >=20 > =3D=3D=3D > int numberOfMasterRowsWithoutOwner { > def = mymasterrow=3DEOQualifier.qualifierWithQualifierFormat("importObject.dataB= lock =3D %@ AND recordOwner =3D NULL",[this] as NSA) > return = ERXEOControlUtilities.objectCountWithQualifier(this.editingContext, = 'DBRecord', mymasterrow) > } > =3D=3D=3D >=20 > Most time it works properly. Occasionally =E2=80=94 rather rarely =E2=80= =94 the problem above happens. Can you see what am I doing wrong? >=20 > Thanks a lot, > OC >=20 >=20 --Apple-Mail=_F93FDF68-916B-48D9-BEC7-15934E85372B Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 P.S. = When log4j.logger.er.transaction.adaptor.EOAdaptorDebugEnabled = is set to DEBUG, it seems the offending fetch looks like this:

=3D=3D=3D
15:03:36.633 DEBUG  =3D=3D=3D= Begin Internal Transaction       //log:NSLog = [WorkerThread1]
15:03:36.633 = DEBUG  evaluateExpression: = <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: = "SELECT ... t0."C_UID", ... FROM "T_RECORD" t0 WHERE t0."C_IMPORT_ID" =3D = 1003547" withBindings: >       //log:NSLog = [WorkerThread1]
15:03:37.155 = DEBUG 5749 row(s) processed       = //log:NSLog [WorkerThread1]
15:03:37.196 DEBUG  =3D=3D=3D Commit Internal = Transaction       //log:NSLog = [WorkerThread1]
=3D=3D=3D

A number of times it = runs all right; then something like this happens:
=3D=3D=3D
15:05:48.528 DEBUG  =3D=3D=3D Begin Internal = Transaction       //log:NSLog = [WorkerThread5]
15:05:48.528 = DEBUG  evaluateExpression: = <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: = "SELECT ... t0."C_UID", ... FROM "T_RECORD" t0 WHERE t0."C_IMPORT_ID" =3D = 1003547" withBindings: >       //log:NSLog = [WorkerThread5]
15:05:49.937 DEBUG fetch canceled       = //log:NSLog [WorkerThread5]
15:05:49.937 DEBUG 164 row(s) processed   =     //log:NSLog [WorkerThread5]
15:05:49.941 DEBUG  =3D=3D=3D Commit Internal = Transaction       //log:NSLog = [WorkerThread5]
15:05:49.941 = INFO  Database Exception occured: = java.lang.IllegalArgumentException: Cannot determine primary key for = entity DBRecord from row: {... uid =3D = <com.webobjects.foundation.NSKeyValueCoding$Null>; ... }   =     //log:er.transaction.adaptor.Exceptions = [WorkerThread5]
=3D=3D=3D

Any idea what might = go wrong and how to fix it? Thanks!
OC

On 11. 6. 2021, at 13:37, OCsite <webobjects-dev@wocommunity.org> wrote:

Hi = there,

just = bumped into another weird EOF case. A pretty plain fetch caused a = =E2=80=9CCannot determine primary key for entity=E2=80=9D exception. The = row contains a number of columns whose values makes sense, some null, = some non-null, with one exception =E2=80=94 the primary key, modelled as = an attribute uid, is indeed a null, thus the exception makes a perfect = sense.

How can this = happen?

=3D=3D=3D
IllegalArgumentException: = Cannot determine primary key for entity DBRecord from row: {... uid =3D = <com.webobjects.foundation.NSKeyValueCoding$Null>; ... = }
  at = com.webobjects.eoaccess.EODatabaseChannel._fetchObject(EODatabaseChannel.j= ava:348)
    =  ... skipped 2 stack elements
  at = com.webobjects.eocontrol.EOObjectStoreCoordinator.objectsWithFetchSpecific= ation(EOObjectStoreCoordinator.java:488)
  at = com.webobjects.eocontrol.EOEditingContext.objectsWithFetchSpecification(EO= EditingContext.java:4069)
  at = er.extensions.eof.ERXEC.objectsWithFetchSpecification(ERXEC.java:1215)
     ... skipped = 1 stack elements
  at = com.webobjects.eocontrol.EOObjectStoreCoordinator.objectsForSourceGlobalID= (EOObjectStoreCoordinator.java:634)
  at = com.webobjects.eocontrol.EOEditingContext.objectsForSourceGlobalID(EOEditi= ngContext.java:3923)
  at = er.extensions.eof.ERXEC.objectsForSourceGlobalID(ERXEC.java:1178)
     ... skipped = 1 stack elements
  at = com.webobjects.eoaccess.EOAccessArrayFaultHandler.completeInitializationOf= Object(EOAccessArrayFaultHandler.java:77)
  at = com.webobjects.eocontrol._EOCheapCopyMutableArray.willRead(_EOCheapCopyMut= ableArray.java:45)
  at = com.webobjects.eocontrol._EOCheapCopyMutableArray.count(_EOCheapCopyMutabl= eArray.java:103)
  at = com.webobjects.foundation.NSArray.isEmpty(NSArray.java:1888)=
...
=3D=3D=3D

Just in case it happens to be important (I = believe it is not), the problem happens at row

  =       ... = =3Deolist.representedObject.records().isEmpty()?...:...

where records = just returns storedValueForKey('records'), = self-evidently a fault, which fires to fetch the rows.

Searching = the Web, all I've found is this (linked from here), which does not really = help :) Truth is, some background threads do run at = the moment; they are comparatively plain though and I can't see why they = should cause the problem for the R/R thread. All they do is to

1. get their own OSC = from the pool, making sure they never get = the same OSC normal sessions have
2. = create a new ERXEC in this OSC
3. get a local = instance of an object in the EC

=3D=3D=3D this is the code of the = background thread; a number of those runs:
        def store
    =     for = (def = pool=3DERXObjectStoreCoordinatorPool._pool();;) {
            = store=3Dpool.nextObjectStore
        =     if (store!=3D_sessionosc) = break // there's one OSC for all sessions, = stored in _sessionosc
      =   }
      =   return eo.localInstanceIn(ERXEC.newEditingContext(s= tore)).numberOfMasterRowsWithoutOwner()
=3D=3D=3D

and the method simply = fetches:

=3D=3D=3D
  =   int = numberOfMasterRowsWithoutOwner {
      =   def = mymasterrow=3DEOQualifier.qualifierWithQualifierFormat("importObject.dataBlock =3D = %@ AND recordOwner =3D NULL",[this] as NSA)
        return ERXEOControlUtilities.objectCountWithQualifier(this.editingContext, 'DBRecord', mymasterrow)
    }
=3D=3D=3D

Most time it works = properly. Occasionally =E2=80=94 rather rarely =E2=80=94 the problem = above happens. Can you see what am I doing wrong?
Thanks a lot,
OC



= --Apple-Mail=_F93FDF68-916B-48D9-BEC7-15934E85372B--