New Posts New Posts RSS Feed: keeping an eye on EntityManager in SL4
  FAQ FAQ  Forum Search   Calendar   Register Register  Login Login

keeping an eye on EntityManager in SL4
 Post Reply Post Reply
Author
  Share Topic Share Topic  Topic Search Topic Search  Topic Options Topic Options
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Topic: keeping an eye on EntityManager in SL4
    Posted: 02-Aug-2010 at 4:28am
Hi.

I am trying to extract some information from the EntityManager (EM) on its inner workings when you submit an Async query. I mostly want this information so that I can make better performance decisions.

After little digging I found these 3 events: Querying,Fetching,Queried.

After some hours of development I failed to extract useful information for the client when it is in debug mode.

What am I missing here? I read up on the developers guide about how everything works but those events fire nothing like what you would expect. Let me give a simple example:

Query:NorthwindIBEntities.DefaultManager.Customers
Event sequence: Querying->Fetching->Queried
Interpretation: All good. EM searches it's cache finds nothing thus resubmits the query as a "fetch from datasource". Results are returned. So far so good.

Query:NorthwindIBEntities.DefaultManager.Customers.Where(c => c.ContactName.StartsWith("a")).With(QueryStrategy.Normal)
Event sequence: Querying->Querying->Fetching->Fetching->Queried->Queried
Interpretation: Not cool at all. That result should be fetched from cache? Instead it fires 2 Fetching events and I receive 2 Queried events because of it.Using Fiddler I can see that it only received 1 result from the data source. But why the spamming of the events? It makes it very hard to make sense what just happened?

All I wanted from that second query was a string generated that looks like this: "Queried Customer [1 record(s); 0.2s, 300r/s]" but there is no way I can combine all information given by those events to do this.

Further more, if i change my QueryStratigy to CacheOnly it suddenly works as expected, why could the normal query stratigy not accomplish a cache hit also?

Any thoughts?










Edited by pompomJuice - 02-Aug-2010 at 5:33am
Back to Top
GregD View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 374 		Post Options Post Options   Quote GregD Quote  Post ReplyReply Direct Link To This Post Posted: 02-Aug-2010 at 4:42pm
The documentation was in error regarding the behavior after an unrestricted query. The correct rule is that DevForce always goes to the data source unless it has seen a specific query before.

The documented behavior remains true in DevForce Classic. It was   originally motivated there in support of something called enumeration entities, which were based on data that seldom changed.
Back to Top
jsobell View Drop Down
Groupie
Groupie
Avatar

Joined: 02-Apr-2009
Location: Australia
Posts: 80 		Post Options Post Options   Quote jsobell Quote  Post ReplyReply Direct Link To This Post Posted: 02-Aug-2010 at 11:09pm
I don't follow what this has to do with double-events firing.
If the first case (unrestricted) always goes to the database, why would the second one call Query twice then Fetch twice?
I could sort of understand Query-Fectch-Query-Fetch...
Back to Top
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Posted: 03-Aug-2010 at 12:58am
Originally posted by GregD

The documentation was in error regarding the behavior after an unrestricted query. The correct rule is that DevForce always goes to the data source unless it has seen a specific query before.

The documented behavior remains true in DevForce Classic. It was   originally motivated there in support of something called enumeration entities, which were based on data that seldom changed.


That is quite a significant "error".

I was wondering how you could accurately determine that a particular query already has a similar unrestricted query in the query cache. That can't be easy to achieve?



Back to Top
GregD View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 374 		Post Options Post Options   Quote GregD Quote  Post ReplyReply Direct Link To This Post Posted: 04-Aug-2010 at 4:13pm
Originally posted by jsobell

I don't follow what this has to do with double-events firing.
If the first case (unrestricted) always goes to the database, why would the second one call Query twice then Fetch twice?
I could sort of understand Query-Fectch-Query-Fetch...


I am unable to reproduce the scenario of double events firing. In a test, I set up handlers for querying, fetching, and queried, then issued an unrestricted query for Customers, then a restricted one for Customers. Handlers were hit only once for each query.   How did you determine they were hit twice?
Back to Top
jsobell View Drop Down
Groupie
Groupie
Avatar

Joined: 02-Apr-2009
Location: Australia
Posts: 80 		Post Options Post Options   Quote jsobell Quote  Post ReplyReply Direct Link To This Post Posted: 04-Aug-2010 at 4:17pm
This was just a question relating to "pompomJuice's" (?!) comment:
Event sequence: Querying->Querying->Fetching->Fetching->Queried->Queried
I haven't tried tracing this in our code, I was just interested to know why the manager might generate this sequence in such an odd order when data was cached.
Back to Top
GregD View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 374 		Post Options Post Options   Quote GregD Quote  Post ReplyReply Direct Link To This Post Posted: 04-Aug-2010 at 4:24pm
Originally posted by pompomJuice

 
I was wondering how you could accurately determine that a particular query already has a similar unrestricted query in the query cache. That can't be easy to achieve?

I didn't write the code, and Classic was a different animal, as there was no Entity Framework and no LINQ.  And since we're not checking this in the current version, there is no current implementation.  But I don't think that's because there's anything particularly hard about identifying a given query as "unrestricted". I think it's more because we're not sure the use case is compelling (and unequivocal).



Edited by GregD - 04-Aug-2010 at 6:03pm
Back to Top
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Posted: 05-Aug-2010 at 1:30am
Originally posted by GregD

Originally posted by jsobell

I don't follow what this has to do with double-events firing.
If the first case (unrestricted) always goes to the database, why would the second one call Query twice then Fetch twice?
I could sort of understand Query-Fectch-Query-Fetch...


I am unable to reproduce the scenario of double events firing. In a test, I set up handlers for querying, fetching, and queried, then issued an unrestricted query for Customers, then a restricted one for Customers. Handlers were hit only once for each query.   How did you determine they were hit twice?

Strange.

You are using Silverlight right? I did nothing fancy on my side. I connected to that Northwind database that comes with the installs and made a async query. I determined the order by using breakpoints in each event handler. Regardless, even though I might have measured asynchronous events incorrectly that is not what is bothering me. Those two queried events that fire are the ones confusing me, because it makes it hard to follow what the EntityManager is doing... I made 1 query it says it made 2, with both having WasFetched=true;


Edited by pompomJuice - 05-Aug-2010 at 2:00am
Back to Top
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Posted: 05-Aug-2010 at 1:47am
Originally posted by GregD

I think it's more because we're not sure the use case is compelling (and unequivocal).


That must have been a interesting discussion. All this caching is terribly wonderful until you have multiple clients that CRUD the same tables. Then it becomes something else... O_o


Edited by pompomJuice - 05-Aug-2010 at 2:00am
Back to Top
GregD View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 374 		Post Options Post Options   Quote GregD Quote  Post ReplyReply Direct Link To This Post Posted: 05-Aug-2010 at 10:37am
[/QUOTE]That must have been a interesting discussion. All this caching is terribly wonderful until you have multiple clients that CRUD the same tables. Then it becomes something else... O_o[/QUOTE]

Well, the good news is that you have the option of staying off the server when you don't need to go there. Or going there when it makes sense.
Back to Top
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Posted: 06-Aug-2010 at 12:20am
Originally posted by GregD

Originally posted by pompomJuice

That must have been a interesting discussion. All this caching is terribly wonderful until you have multiple clients that CRUD the same tables. Then it becomes something else... O_o

Well, the good news is that you have the option of staying off the server when you don't need to go there. Or going there when it makes sense.

Agreed. 

DevForce gives excellent control over almost anything you can think of. Now that I know what behavior is intended I can continue customizing it to my needs.

PS-There is something weird in these forums where it keeps on adding massive amounts of whitespace at the end of a post if you edit it a lot.


Edited by pompomJuice - 06-Aug-2010 at 12:25am
Back to Top
GregD View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 374 		Post Options Post Options   Quote GregD Quote  Post ReplyReply Direct Link To This Post Posted: 06-Aug-2010 at 7:54am
Originally posted by pompomJuice

PS-There is something weird in these forums where it keeps on adding massive amounts of whitespace at the end of a post if you edit it a lot.

I dunno. The thing I've noticed is that if you use tags like QUOTE, CODE, etc., it likes them squeezed up as close as possible to the content; otherwise, it inserts a bunch of white space.  I have absolutely no extra characters (including end-of-line) at the end of this post, so let's see what happens.
Back to Top
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Posted: 10-Aug-2010 at 4:24am
In any case.

I implemented my little bit of code that attempts to report on what the EntityManager (EM) is doing. 

To reiterate... I have 2 queries, the second one slightly modified to include "Order" information:

1.) NorthwindIBEntities.DefaultManager.Customers
2.) NorthwindIBEntities.DefaultManager.Customers.Where(c => c.ContactName.StartsWith("a")).Include("Orders")

Disaster once again. I installed that "web development helper" that reports what the browser is doing. The results I am getting is that the first query's response was sized at 57KB for all 93 records. The second query's response size is 52KB for 1 record.

If I dig a little deeper into EM the second query reports that it has caused "95" changed entities in the EM's cache. A bunch of customers and a lot of orders. (even though the query returned 1 customer and 10 orders for that customer)

Basically I looked at the results from all angles and I just cannot get the kind of numbers that EM gets when executing that second query. To put it bluntly, I feel that EM is not reporting what it is doing correctly, which makes it helluva hard to check that the EM is actually doing things optimally.

Should I just leave this and accept I will never really know what the EM is doing and that is working optimally?

Surely we need some kind of feedback from EM if we are going to customize it for certain situations.

I don't understand why I am the only person with these kinds of issues, which to me are rather large ones.


Edited by pompomJuice - 10-Aug-2010 at 4:27am
Back to Top
GregD View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 374 		Post Options Post Options   Quote GregD Quote  Post ReplyReply Direct Link To This Post Posted: 10-Aug-2010 at 1:25pm
Originally posted by pompomJuice

I implemented my little bit of code that attempts to report on what the EntityManager (EM) is doing. 

To reiterate... I have 2 queries, the second one slightly modified to include "Order" information:

1.) NorthwindIBEntities.DefaultManager.Customers
2.) NorthwindIBEntities.DefaultManager.Customers.Where(c => c.ContactName.StartsWith("a")).Include("Orders")

Originally posted by pompomJuice

The results I am getting is that the first query's response was sized at 57KB for all 93 records. The second query's response size is 52KB for 1 record.

[snip] 

...the query returned 1 customer and 10 orders for that customer)

So the second query returned 11 records, not 1 - correct? And you're concerned about the small relative size difference between the two results sets (as reported by your "web development helper" tool)?

If I dig a little deeper into EM the second query reports that it has caused "95" changed entities in the EM's cache. A bunch of customers and a lot of orders. (even though the query returned 1 customer and 10 orders for that customer) 

Your tool determined that 95 entities were changed? How does it determine that?

 To put it bluntly, I feel that EM is not reporting what it is doing correctly, which makes it helluva hard to check that the EM is actually doing things optimally.

Don't be concerned about hurting our feelings. 8-)  If there's a problem we'll certainly fix it, but right now I don't have any idea what exactly your custom tool does, or how; or exactly how you're determining that EM is not reporting what it is doing correctly. So, fill us in.
Back to Top
pompomJuice View Drop Down
Newbie
Newbie
Avatar

Joined: 29-Jul-2010
Location: ZA
Posts: 28 		Post Options Post Options   Quote pompomJuice Quote  Post ReplyReply Direct Link To This Post Posted: 11-Aug-2010 at 5:03am
Basically what I wanted to achieve is if a query gets fired my back end implementation reports on what is going on with this query. (how long did it take how many records and of what type etc etc.)

There are 2 approaches that can solve this problem. 

Approach1:
Write a wrapper around EntityManager that intercepts what is going on and report on it. I chose not to go this route because...

Approach2:
...I saw that the EntityManager exposes 3 events that looks like it might tell me what is going on with the queries. I implemented those 3 event handlers (Fetching,Querying,Queried), but it was a complete disaster. Those events fire nothing like you'd expect. 

And its not like they fire roughly correctly, they fire almost at random. (Even though EM works perfect) I thought that because those events are so uninformative I could come here and get someone to confirm it. That way I can safely implement approach 1 knowing that approach 2 wont work.

Unfortunately this has not happened so I believe I am doing something wrong. 

So here are my assumptions so far: (I am always guessing what EM is doing since I don't have the code)

1.) For a particular query those 3 events should tell me what EM is doing. Right?
2.) To "see" what EM loaded from the server I need to look at the EntityQueriedEventArgs of the Queried event. Item 6 explains what I needed assume to make this "work".
3.) To determine whether a query was a loaded from the server or a cache hit I check the EntityQueriedEventArgs.WasFetched & IsCompletedSynchronously. (Those two variables seem to function properly)
4.) To determine how many records were fetched from the server I check the EntityQueriedEventArgs.ChangedEntities collection as this seems to be the most accurate representation of how many records EM loaded. (why else would they be changed right? Assumptions!)
5.) If a query was served by EM's cache, there is no way to determine how many records were in that result set from any of the the 3 events. You just know the cache was hit and thats it.
6.) To keep track of what query I am actually looking at in the Queried event I tag the queries with a unique number as they enter the EM. My assumption here is that if a single query spawns multiple other events that they all will have this tag. This helps me combine all the Queried events usually resulting from a single query and extract stats from it. (A single query like the one described in the above posts could sometimes end up making five or six of those Queried events all with the same information in them. I could not find a pattern that explained why sometimes there are many queried events and why other times there are not so many)

To answer some of your questions:

Originally posted by GregD

So the second query returned 11 records, not 1 - correct? And you're concerned about the small relative size difference between the two results sets (as reported by your "web development helper" tool)?
That is correct, it returned 11. 1 Customer and 10 orders. i thought something looked suspicious there. 

Originally posted by GregD

Your tool determined that 95 entities were changed? How does it determine that?
By looking at EntityQueriedEventArgs.ChangedEntities.

Originally posted by GregD

Don't be concerned about hurting our feelings. 8-)  If there's a problem we'll certainly fix it, but right now I don't have any idea what exactly your custom tool does, or how; or exactly how you're determining that EM is not reporting what it is doing correctly. So, fill us in.

Good :) I't a LOB application framework that I am starting to build for a 2 year project. I want to use devforce instead of RIA this time because RIA is horrible. This application is my attempt to see how devforce is going to play along.

The thing is for me those events fire so strange that I cannot even come here to explain how they misfire. I am finding it very difficult to make a short post that describe the behavior...the best I can come up with is: Random.


Edited by pompomJuice - 11-Aug-2010 at 5:14am
Back to Top
 Post Reply Post Reply

Forum Jump Forum Permissions View Drop Down