onSet called multiple times when PersevereDataStore.save called in too short an interval

[Jake]

Hi,

I've had the opportunity to attempt to use Persevere for a research
project in
distributed user interfaces. Unfortunately, I've run into some
unexpected
behaviour involving the PersevereDataStore (with and without comet),
which I'm
hoping someone could help me resolve.

The issue I am seeing appears to be triggered by
invoking save too frequently on the data store, in too short an
interval. To
understand this issue, please consider the following code snippet:


dojo.connect(document.documentElement,"onkeypress",function(evt){
for(var i = 0; i<3;i++){
translateREST(mdl,{dx:1,dy:1});
graphicsStore.save();
}
});

This connects a keypress event so that it triggers a tight loop, which
at each
step updates an item in the data store, and then invokes save on the
data store.

I then get the following trace from Firebug:

set item received
transform
matrix(1,0,0,1,256,324)
matrix(1,0,0,1,257,325)
PUT http://localhost:8080/Graphics/2

200 OK
189ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,257,325)
matrix(1,0,0,1,258,326)
PUT http://localhost:8080/Graphics/2

200 OK
90ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,258,326)
matrix(1,0,0,1,259,327)
PUT http://localhost:8080/Graphics/2

200 OK
50ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,259,327)
matrix(1,0,0,1,257,325)
set item received
transform
matrix(1,0,0,1,257,325)
matrix(1,0,0,1,258,326)
set item received
transform
matrix(1,0,0,1,258,326)
matrix(1,0,0,1,259,327)


The problem is that the final three calls to onSet, as indicated by
the log "set
item received", appear to be anomalous, as we have already received
calls to
onSet for each of the changes in question.

If I then change the code so that it does not execute three quick
saves, but
allows the user to slowly trigger the event three times, then these
extra calls
to onSet never occur:

dojo.connect(document.documentElement,"onkeypress",function(evt){
translateREST(mdl,{dx:1,dy:1});
graphicsStore.save();
});


set item received
transform
matrix(1,0,0,1,256,324)
matrix(1,0,0,1,257,325)
PUT http://localhost:8080/Graphics/2

200 OK
189ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,257,325)
matrix(1,0,0,1,258,326)
PUT http://localhost:8080/Graphics/2

200 OK
90ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,258,326)
matrix(1,0,0,1,259,327)
PUT http://localhost:8080/Graphics/2

200 OK
50ms bootstrap.js (line 1115)


This is the trace that I would also expect from the tight loop.

This is behaviour occurs reliably, and so I've attempted to debug it.
I
set a conditional breakpoint to break on the extra onSet, and walked
up the
stack to find where this onSet is being initiated. At the top of the
stack is
_watchInFlight in xhr.js. It then ends up in JSONRestStore, in the
following
anonymous function:

dojo.connect(dojox.rpc.Rest._index,"onUpdate",this,function
(obj,attrName,oldValue,newValue){
var prefix = this.service.servicePath;
if(!obj.__id){
console.log("no id on updated object ", obj);
}else if(obj.__id.substring(0,prefix.length) == prefix){
this.onSet(obj,attrName,oldValue,newValue);
}
});


I'm not yet sure why this is occuring, but it seems that, as
_watchInFlight
"checks each inflight XMLHttpRequest to see if it has completed or if
the
timeout situation applies", then possibly this situation arises when
save is
called before the XHR caused by a previous save resolves. The exact
reason why
this would be occurring is not clear to me though.

I'd appreciate any guidance anyone could offer as to why this is
occurring,
how to resolve it, or even if it should be marked as a bug.

Thanks,

Jake

[Jake]

FYI, the issue persists in the 1.0 release.

Any guidance would be appreciated. Thanks,

Jake

> PUThttp://localhost:8080/Graphics/2

>
> 200 OK
>                 189ms   bootstrap.js (line 1115)
> set item received
> transform
> matrix(1,0,0,1,257,325)
> matrix(1,0,0,1,258,326)

> PUThttp://localhost:8080/Graphics/2

>
> 200 OK
>                 90ms    bootstrap.js (line 1115)
> set item received
> transform
> matrix(1,0,0,1,258,326)
> matrix(1,0,0,1,259,327)

> PUThttp://localhost:8080/Graphics/2

> PUThttp://localhost:8080/Graphics/2

>
> 200 OK
>                 189ms   bootstrap.js (line 1115)
> set item received
> transform
> matrix(1,0,0,1,257,325)
> matrix(1,0,0,1,258,326)

> PUThttp://localhost:8080/Graphics/2

>
> 200 OK
>                 90ms    bootstrap.js (line 1115)
> set item received
> transform
> matrix(1,0,0,1,258,326)
> matrix(1,0,0,1,259,327)

> PUThttp://localhost:8080/Graphics/2

[Jake B]

Hi,

I hate to keep replying to my own messages, but I believe I've
discovered why the onSet event is getting called twice for each call
to setValue.

The first time, it is getting called by the setValue method in JsonRestStore.

setValue: function(item, attribute, value){
// summary:
// sets 'attribute' on 'item' to 'value'

var old = item[attribute];
var store = item.__id ? dojox.data._getStoreForItem(item) : this;
if(dojox.json.schema && store.schema && store.schema.properties){
// if we have a schema and schema validator available
we will validate the property change

dojox.json.schema.mustBeValid(dojox.json.schema.checkPropertyChange(value,store.schema.properties[attribute]));
}
if(attribute == store.idAttribute){
throw new Error("Can not change the identity attribute
for an item");
}
store.changing(item);
item[attribute]=value;
store.onSet(item,attribute,old,value);
},

The second time, onSet is triggered by dojox.rpc.Rest._index.onUpdate:

dojo.connect(dojox.rpc.Rest._index,"onUpdate",this,function(obj,attrName,oldValue,newValue){

var prefix = this.service.servicePath;
if(!obj.__id){
console.log("no id on updated object ", obj);
}else if(obj.__id.substring(0,prefix.length) == prefix){
this.onSet(obj,attrName,oldValue,newValue);
}
});

What is not clear is what is the expected behaviour here.

The behaviour I would like is for onSet to only be called only once
for each call to setValue. This means it could either be triggered
directly by calling setValue on the data store, or it could be
triggered by dojox.rpc.Rest._index.onUpdate, which would only occur if
the value had changed on the server, and was not triggered by a change
in the local data store. Without this constraint it is not clear to me
how to program against the onSet API, unless on introduces the
constraint that all actions triggered by onSet are idempotent.

I've tried to enforce this constraint by creating my own subclass of
PercevereStore, where the setValue method is overrided, such that
onSet is no longer called:

setValue: function(item, attribute, value){
// summary:
// sets 'attribute' on 'item' to 'value'

var old = item[attribute];
var store = item.__id ? dojox.data._getStoreForItem(item) : this;
if(dojox.json.schema && store.schema && store.schema.properties){
// if we have a schema and schema validator available
we will validate the property change

dojox.json.schema.mustBeValid(dojox.json.schema.checkPropertyChange(value,store.schema.properties[attribute]));
}
if(attribute == store.idAttribute){
throw new Error("Can not change the identity attribute
for an item");
}
store.changing(item);
item[attribute]=value;
},

The reasoning behind this is that onSet would then only be triggered
by dojox.rpc.Rest._index.onUpdate, and there would thus no longer be
duplicate calls to onSet. Unfortunately, this does not seem to work in
the way I was expecting, as onSet does not get called for every update
sent to the server. For example, for the tight loop I mentioned in my
first post, triggered by a keypress event, does not cause onSet to be
called on the client. At the moment, I have no idea why. Could this be
a reliability issue?

In any case, the main question is, how may I implement the constraint
that onSet gets called only once for each call to setValue? Am I
missing something fundamental? Is it expected that all side effects of
onSet be idempotent?

If anyone could provide some insight into this, I would greatly appreciate it.

Thanks,

Jake

[Kris Zyp]

Are both onSet events providing different new values (is the old value
always different than the new)? Is the client changing the value of the
property and then the server changing it to something else, or is the
second event being triggered even the value isn't changed?
Kris

[Jake B]

Hi Kris,

Thank you for the response. I'll reply to you inline:

On Sat, Nov 14, 2009 at 7:38 PM, Kris Zyp <kri...@gmail.com> wrote:
>
> Are both onSet events providing different new values (is the old value
> always different than the new)?

The old value is always different than the new value. onSet is never
called with arguments set such that oldValue == newValue. However,
onSet is consistently called with all arguments equal to the arguments
that had been set when onSet had been called a previous time. Ordering
also appears to be respected.

I think the original trace I included is fairly representative:

set item received
transform
matrix(1,0,0,1,256,324)
matrix(1,0,0,1,257,325)

PUT http://localhost:8080/Graphics/2

200 OK
189ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,257,325)
matrix(1,0,0,1,258,326)

PUT http://localhost:8080/Graphics/2

200 OK
90ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,258,326)
matrix(1,0,0,1,259,327)

PUT http://localhost:8080/Graphics/2

200 OK
50ms bootstrap.js (line 1115)
set item received
transform
matrix(1,0,0,1,259,327)
matrix(1,0,0,1,257,325)
set item received
transform
matrix(1,0,0,1,257,325)
matrix(1,0,0,1,258,326)
set item received
transform
matrix(1,0,0,1,258,326)
matrix(1,0,0,1,259,327)

Here, onSet is called six times in total. The first three times were
triggered by calls to setValue. Each one creates a new XHR to PUT and
update a resource on the server. These occur inside of a tight loop.

The last three times onSet is called, it is triggered by
_watchInFlight in xhr.js, which is connected to
dojox.rpc.Rest._index.onUpdate. You can see that the arguments are the
same as in the first three events, and ordering is also preserved. The
problem is that these events have already been handled by onSet.

> Is the client changing the value of the
> property and then the server changing it to something else, or is the
> second event being triggered even the value isn't changed?

No, the issue is not consistency in the data between the client and
the server, but is simply in the number of times onSet gets called for
each call to setValue.

I want to be a little bit formal in how I answer this, just so that
there's no confusion.

The server has a resource R. The client has a local store S which
contains a resource R'. The resource R and R' have properties p. R'.p
and R.p initially have values of x0. The client will update R'.p to a
value x1 via S.setValue, onSet will be called with arguments (R', p,
x0, x1). The client will then call S.save(), and an XHR PUT xhr1 will
be created to asynchronously update R.p to x1.

Before xhr1 completes, the client will update R'.p to a new value x2.
onSet will again be called from the setValue method, this time with
args (R', p, x1, x2). The client will then call S.save(), and an XHR
PUT xhr2 will be created to asynchronously update R.p to x2.

When xhr1 completes, the value of R.p will be x1, and onSet will be
called When xhr2 completes, the value of R.p will be x2. So, the
value of the data resources is completely consistent between client
and server.

The problem is that when xhr1 completes, _watchInFlight will be
called which triggers dojox.rpc.Rest._index.onUpdate, which calls
onSet(R',p,x0,x1). Likewise, when xhr2 completes, onSet will be called
with (R',p,x1,x2).

The problem is, onSet has already been called with these values once
before. This behaviour does not seem to me to be consistent.

Please let me know if you have any more questions. I'll put a sample
online soon so that, if it is still unclear, you will be able to trace
this behaviour yourself.

Thanks for looking into this,

Jake

[Jake B]

I'm hosting it here:

http://echo-flow.com:8080/graphics/graphics.xhtml

You can trace it yourself with firebug. Pressing any key will trigger
the behaviour in question.

Please let me know what you think. Thanks,

Jake

[Kris Zyp]

When I run this I see a single onSet call for each PUT (3 onSets and
PUTs for each keystroke). Should I be seeing multiple onSet calls at
some point for a PUT?
Kris

[Jake B]

Hi Kris,

Thank you for looking into this. In short, yes, when I run this, I see
6 onSets and 3 PUTs for each keystroke, in the following order:

set
PUT
set
PUT
set
PUT
set
set
set

Visually, the rect should move southeast, and will appear to
"stutter", as it moves 3 pixels down and to the right, and then
suddenly moves back to when it began as it re-receives the first
onSet, and then moves three pixels down and to the right again as it
re-receives the other onSets. This should be very apparent if you hold
down a key to send in many events.

I just tested this again on Firefox 3.5.5, Safari 4.0.3, and Google
Chrome 3.0.195.27, all on Windows Vista 64. All manifest this
behaviour without fail.

Please let me know if I can be of further help, or provide further
information. Thanks,

Jake

[Jake B]

Hi Kris,

Are you still getting the same results?

Let me know. Thanks,

Jake

>> --~--~---------~--~----~------------~-------~--~----~
>> You received this message because you are subscribed to the Google Groups "Persevere" group.
>> To post to this group, send email to persevere...@googlegroups.com
>> To unsubscribe from this group, send email to persevere-frame...@googlegroups.com
>> For more options, visit this group at http://groups.google.com/group/persevere-framework?hl=en
>> -~----------~----~----~----~------~----~------~--~---
>>
>>
>

[Kris Zyp]

I'm unable to access it now.
Kris

> --

>
> You received this message because you are subscribed to the Google Groups "Persevere" group.

> To post to this group, send email to persevere...@googlegroups.com.
> To unsubscribe from this group, send email to persevere-frame...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/persevere-framework?hl=.
>
>
>

[Jake B]

Sorry, server needed to be restarted. Should work now.

Thanks,

Jake

[Kris Zyp]

The problem is that the you are changing the value three times quickly,
and then afterwards you are receiving the first update which is
different than the present value after the final update, so it goes back
to that state, and you get the second update and then the final update
(putting it back in the final state). Is there a reason you can't call
save() after all three updates are finished (and trigger a single PUT)?
I would think that would solve your problem.
Kris

> <mailto:persevere...@googlegroups.com>

> >>> To unsubscribe from this group, send email to
> persevere-frame...@googlegroups.com

> <mailto:persevere-framework%2Bunsu...@googlegroups.com>

> >>> For more options, visit this group at
> http://groups.google.com/group/persevere-framework?hl=en
> >>> -~----------~----~----~----~------~----~------~--~---
> >>>
> >>>
> >>>
> >
> > --
> >
> > You received this message because you are subscribed to the
> Google Groups "Persevere" group.
> > To post to this group, send email to
> persevere...@googlegroups.com

> <mailto:persevere...@googlegroups.com>.

> > To unsubscribe from this group, send email to
> persevere-frame...@googlegroups.com

> <mailto:persevere-framework%2Bunsu...@googlegroups.com>.

> > For more options, visit this group at
> http://groups.google.com/group/persevere-framework?hl=.
> >
> >
> >
>
> --
>
> You received this message because you are subscribed to the Google
> Groups "Persevere" group.
> To post to this group, send email to
> persevere...@googlegroups.com

> <mailto:persevere...@googlegroups.com>.

> To unsubscribe from this group, send email to
> persevere-frame...@googlegroups.com

> <mailto:persevere-framework%2Bunsu...@googlegroups.com>.

[Jake B]

Hi Kris,

I believe you are correct, that is indeed the behaviour I have observed. Unfortunately, I cannot follow your suggestion of scaling back saves on the data store if I am to fulfill my use case. More importantly, though, it is still not clear to me why this behaviour is manifesting in this way. 

The example of triggering three quick updates in a loop was contrived simply to illustrate, in a testable, reliable, isolated way, the problematic behaviour I have been encountering. However, it is representative of the actual problem I am trying to solve, which has to do with "dragging" the rect. When dragging the rect on the client, for each mousemove event, I want to update its representation in the data store and then save. This entails initiating many data store saves very quickly. My hope is that this will allow fairly fluid animation on the client performing the drag, and on all other clients subscribed to updates on the rect. This will facilitate a distributed user interface. So, to solve this particular problem, I need to be able to rapidly update and save to the data store. Incidentally, the dragging behaviour has been implemented in the example, so you can drag the rect and see the effect that receiving multiple onSets has on the dragging animation. Please feel free to try it.

Per your suggestion of scaling back saves, I am experimenting with using batch updates in a clever way on the client, but I don't want to go down this path unless I can clearly justify, and have a clear understanding of, why the naive solution will not work. 

Right now, I still don't understand why this behaviour manifests itself in this peculiar fashion. Just to recap, the behaviour is as follows: I will always receive at least one onSet event for every call to setValue on the data store, because there is a call directly from the setValue function to the onSet listener on the data store. Then, if and only if I send multiple events very quickly, do I then receive a second round of onSet events on the client. 

My questions are: 

* Why would a second round of onSet events be triggered only when multiple saves are called in quick succession? 

* Should the PersevereDataStore support rapid updates and saves?

* Or, is this observed behaviour expected behaviour? 

* If this is expected behaviour, then how should one filter out duplicate onSet events (the one originating from the client, and the one originating from the server)? 

* Is there a data store API to allow clients to listen to only updates that are triggered by resources being updated on the server?

Please let me know what you think. Thanks,

Jake

[Kris Zyp]

Jake B wrote:
> Hi Kris,
>

> I believe you are correct, that is indeed the behaviour I have
> observed. Unfortunately, I cannot follow your suggestion of scaling
> back saves on the data store if I am to fulfill my use case. More

> importantly, though, it is still not clear to me /why/ this behaviour

> /if and only if/ I send multiple events very quickly, do I then

> receive a second round of onSet events on the client.
>
> My questions are:
> * Why would a second round of onSet events be triggered only when
> multiple saves are called in quick succession?

Because the responses from the server come after subsequent client-side
data changes.

> * Should the PersevereDataStore support rapid updates and saves?

It does support the rapid updates, it is just that the network isn't
fast enough to get the responses to the client, and the client honors
any data it gets from the server in case the server has modified the
data (even though it comes later).

> * Or, is this observed behaviour expected behaviour?
> * If this is expected behaviour, then how should one filter out
> duplicate onSet events (the one originating from the client, and the
> one originating from the server)?

You could eliminate the events triggered by the server responses by
deleting the update mechanism:
delete dojox.rpc.Rest._index.onUpdate;
Might be worth trying that to see if it would make things more smoother.

> * Is there a data store API to allow clients to listen to only updates
> that are triggered by resources being updated on the server?

If you want to eliminate the client side events, you could replace the
event handlers while doing sets:
var currentOnSet = store.onSet;
store.onSet = function(){/*suppress*/};
store.setValue(...
store.onSet=currentOnSet;
But, I don't think you would want to do that because you would not get
any notifications for single saves.
Kris