Re: Snapshot problems
Re: Snapshot problems
- Subject: Re: Snapshot problems
- From: Chuck Hill <email@hidden>
- Date: Fri, 20 Apr 2007 11:05:58 -0700
Hi Mark,
Now we are getting somewhere! I have removed the mostly irrelevant
bits.
On Apr 20, 2007, at 9:44 AM, Steven Mark McCraw wrote:
Is awakeFromInsertion implemented in KitQuantity? Did you
remember to call super?
KitQuantity has never had any custom methods. It's class has
always been just an empty implementation.
What if you print the snapshots out in the removeItem method?
Here's the new code for removeItem:
public WOComponent removeItem() {
_nestedEC.revert();
ec.revert();
NSLog.out.appendln("Item being deleted BEFORE delete: " +
ec.committedSnapshotForObject( _kitQuantity ));
_nestedEC.deleteObject( _kitQuantity );
NSArray kitQuantities = ((CatalogItem)
selectedItem).kitQuantities();
for (int i = 0; i < kitQuantities.count(); i++) {
NSLog.out.appendln((i+1) + ": " +
_nestedEC.committedSnapshotForObject( (KitQuantity )
kitQuantities.objectAtIndex(i)));
}
_nestedEC.saveChanges();
int i = 0;
NSLog.out.appendln();
NSLog.out.appendln((i + 1) + ": " +
ec.committedSnapshotForObject( _kitQuantity ));
for (; i < kitQuantities.count(); i++) {
NSLog.out.appendln((i+1) + ": " +
ec.committedSnapshotForObject( (KitQuantity )
kitQuantities.objectAtIndex(i)));
}
NSLog.out.appendln("ec.deletedObjects(): " + ec.deletedObjects
());
ec.saveChanges();
setValueForBinding( "Changes Saved", "message" );
return context().page();
}
The output is fascinating. I'm no closer to understanding what is
going on, but you are clearly asking the right questions, because I
am able to identify more problems. Notice that ec's snapshot of
the deleted object changes after I call saveChanges on _nestedEC
(the green text is my annotation).
OK, that is a catastrophic, end stage failure in EOF. This is a
symptom, not the problem. You are looking in the wrong place, I am
certain of that. You will never find the cause looking at the delete
code. You need to go further back in the EO life cycle. More on
this below.
I added a toString method to KitQuantity so that its output in
ec.deletedObjects would match the output form
ec.committedSnapshotForObject for identification purposes. In this
test, I add then delete three KitQuantity objects:
Before removing the first item
INFO NSLog - Item being deleted BEFORE delete: {quantity = 1;
catalogItem = <CatalogItem pk:"43258">; inventoryItem =
<InventoryItem pk:"2875">; }
INFO NSLog - 1: {quantity = 2; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"12362">; }
INFO NSLog - 2: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"11642">; }
INFO NSLog - 3: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"2875">; }
INFO NSLog - 4: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"2873">; }
INFO NSLog - 5: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"7277">; }
INFO NSLog -
INFO NSLog - Item being deleted AFTER delete: {quantity = 1;
catalogItem = <CatalogItem pk:"43258">; inventoryItem =
<InventoryItem pk:"7277">; }
INFO NSLog - 1: {quantity = 2; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"12362">; }
INFO NSLog - 2: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"11642">; }
INFO NSLog - 3: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"2873">; }
INFO NSLog - 4: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"7277">; }
INFO NSLog - ec.deletedObjects(): ({quantity = 1; catalogItem =
null; inventoryItem = null; })
I guess it makes sense here that the relationships would be set to
null on the object shown in deletedObjects, since it had just been
deleted, and Nullify is the delete rule. But is there something
wrong with the fact that calling ec.committedSnapshotForObject on
the same object before and after the _nestedEC's saveChanges yields
different values? Now I'll remove the second item.
INFO NSLog - Item being deleted BEFORE delete: {quantity = 1;
catalogItem = <CatalogItem pk:"43258">; inventoryItem =
<InventoryItem pk:"2873">; }
INFO NSLog - 1: {quantity = 2; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"12362">; }
INFO NSLog - 2: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"11642">; }
INFO NSLog - 3: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"2873">; }
INFO NSLog - 4: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"7277">; }
INFO NSLog -
INFO NSLog - Item being deleted AFTER delete: {quantity = 1;
catalogItem = <CatalogItem pk:"43258">; inventoryItem =
<InventoryItem pk:"7277">; }
INFO NSLog - 1: {quantity = 2; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"12362">; }
INFO NSLog - 2: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"11642">; }
INFO NSLog - 3: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"7277">; }
INFO NSLog - ec.deletedObjects(): ({quantity = 1; catalogItem =
null; inventoryItem = null; })
Before removing the third item
INFO NSLog - Item being deleted BEFORE delete: {quantity = 1;
catalogItem = <CatalogItem pk:"43258">; inventoryItem =
<InventoryItem pk:"7277">; }
INFO NSLog - 1: {quantity = 2; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"12362">; }
INFO NSLog - 2: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"11642">; }
INFO NSLog - 3: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"7277">; }
INFO NSLog -
INFO NSLog - Item being deleted AFTER delete: {quantity = 1;
catalogItem = <com.webobjects.foundation.NSKeyValueCoding$Null>;
inventoryItem =
INFO NSLog - 1: {quantity = 2; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"12362">; }
INFO NSLog - 2: {quantity = 1; catalogItem = <CatalogItem
pk:"43258">; inventoryItem = <InventoryItem pk:"11642">; }
<com.webobjects.foundation.NSKeyValueCoding$Null>; }
INFO NSLog - ec.deletedObjects(): ({quantity = 1; catalogItem =
null; inventoryItem = null; })
Apr 20 12:07:06 KaraokeWarehouseManager[12004]
(ERXNSLogLog4jBridge.java:41) WARN NSLog -
<com.webobjects.appserver._private.WOComponentRequestHandler>:
Exception occurred while handling request:
java.lang.IllegalStateException: recordDeleteForObject:
com.webobjects.eoaccess.EODatabaseContext
com.webobjects.eoaccess.EODatabaseContext@a0fcdc failed to find a
snapshot for EO with Global ID:_EOIntegralKeyGlobalID[KitQuantity
(java.lang.Integer)1234] that has been deleted from
er.extensions.ERXECer.extensions.ERXEC@419cf7. Cannot delete an
object that has not been fetched from the database
[2007-04-20 12:07:06 EDT] <WorkerThread3>
java.lang.IllegalStateException: recordDeleteForObject:
com.webobjects.eoaccess.EODatabaseContext
com.webobjects.eoaccess.EODatabaseContext@a0fcdc failed to find a
snapshot for EO with Global ID:_EOIntegralKeyGlobalID[KitQuantity
(java.lang.Integer)1234] that has been deleted from
er.extensions.ERXECer.extensions.ERXEC@419cf7. Cannot delete an
object that has not been fetched from the database
...
After analyzing this a million times, I think I've identified a
pattern (and the problem). It always seems to die when deleting
the last item that I set up (the removal it died on depended on how
many items I had added when setting up the test, and I didn't
realize it until now). Notice how the default ec's snapshot always
points to the snapshot at the end of the array after _nestedEC
saves changes. I don't know why it would do this, but it looks
like it does. So when I get down to the last item, the last item
snapshot is gone because it has just been deleted, hence ec's
snapshot of the thing is missing. Is this ringing any bells? It
seems like it ALMOST makes sense to me, but not quite. Why does
the snapshot change after _nestedEC.saveChanges, and why is it
pointing to the end of the relationship array? Is there some kind
of off by one error in EODatabaseContext?
It seems more that is is confused as to which snapshot belongs to
which EO.
If I were to quit the application, restart, and come back to this
page and edit this item, I could delete the KitQuantities without
a care in the world. But if I immediately start deleting the
NEWLY CREATED KitQuantity items, I run into problems.
That sounds very, very familiar. I am sure I have had this happen
to me, but I am also pretty sure it turned out to not be an EOF
bug. I am wracking my brain trying to recall when / why this
happened...
I am pretty sure that I am thinking of the PK type problem that Peter
mentioned earlier. This is a very different problem.
So it appears that the nested EC is flushing its information to
the default ec correctly, and I can tell that the
editingContext's snapshots are fine until very shortly before the
operation. Just in case there was something funny going on in
the EO's, I commented out every line of code from CatalogItem,
InventoryItem, and KitQuantity (the three classes being dealt
with here), so that effectively they were all blank
implementations, and I still get the same result. This would
seem to rule out any possibility of EOF commandment violation.
So there is nothing in them now? Are there any super classes that
may be affecting things.
There was nothing in them at all last night when I tested. I went
ahead and uncommented everything this morning, because it seemed to
have no effect. The superclasses are just the generated classes
from EOGenerator. The only unusual thing about them is that I had
to change the template for the to-many relationships to make sure
that they returned an empty array rather than null if no
relationships had been set,
RIght here. This is where the red lights flash and the sirens start
whooping. This is also a symptom of the problem but it much closer
to the problem. Until you fix this, EOF is not right and you are
wasting time trying to fix a symptom of a deeper, underlying problem.
Does this happen for both newly created objects and fetched existing
objects? Just one of them? Does it happen for all EOs or just some
of them? Usually this means that you have forgotten a call to
super.awake... in awakeFromFetch or awakeFromInsertion. Are you
using inheritance at all? Check all the way up the inheritance
chain, even into frameworks.
The only other reason that this would happen is if it failed to find
a ClassDescription for the entity. It uses model information to
determine what relationships to initialize. Right now, I suspect
that this is your problem. Add your application as an omniscient
observer to NSNotificationCenter and log out all notifications. That
will probably show where the problem starts.
Now, before you do that, you might want to look at the model again.
Are you sharing classes across entities (have multiple entities using
the same class name)? Are some of the entities in another model that
is not getting loaded? Are using inheritance with non-unqiue
restricting qualifiers?
Chuck
because otherwise I kept getting null pointer exceptions everywhere
when I tried to check the relationships. For example, the
kitQuantities method of the generated _CatalogItem.java looks like
this:
public NSArray kitQuantities() {
if (storedValueForKey("kitQuantities") == null) {
return new NSArray();
}
return (NSArray)storedValueForKey("kitQuantities");
}
We actually had a discussion about this a bit back on the list, and
apparently it should be unnecessary,
Not should, IS. This is a symptom of a very, very serious problem.
Ignore it and and you end up in delete hell. You MUST fix this first.
but I didn't know what else to do since I kept getting the behavior
that theoretically should not happen anyway. This should not be an
issue here, because all of the relationships are populated already,
but for the sake of thoroughness I took out the first three lines
of kitQuantities() in both _CatalogItem.java and
_InventoryItem.java, and I still get the same results.
That was, I must say, a very, very good error report. See if any
of the above things provide any more insight and I will keep
trying to recall when this last happened to me.
Chuck
Thanks regarding the error report, and thank you so much for your
help. I feel like I'm getting closer to understanding things, even
if they still don't make sense. The only other thing I can think
of to try is creating a brand new application with just this page
and the EOModel, and don't even create custom subclasses for the
EOs, but just reference them as ERXGenericRecords and use
valueForKey and takeValueForKey everywhere. This would take a few
hours at least, but would for sure rule out any "EOF Commandment
violation" business. Does this seem worth the effort? Sometimes I
get pretty discouraged when working with EOF. I realized that I've
spent close to half a working week trying to do something as simple
as add and delete rows for a single table, and I still don't know
why it doesn't work.
That is because you hid the earlier symptom of the real problem.
Chuck
--
Practical WebObjects - for developers who want to increase their
overall knowledge of WebObjects or who are trying to solve specific
problems.
http://www.global-village.net/products/practical_webobjects
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden