Large OData feed, method GetQueryRootForResourceSet being used several times

Question

Hi,

I'm in the process of finishing our custom provider odata service, and I got a small question.

When I'm using larger odata feeds (100.000+ rows), the method is being accessed multiple times. This is not really a problem, but we are now using that method to log in our system that a user has accessed a feed.

Thus when it get accessed multiple times, it also logs multiple times that a user x has accessed feed y.

Is there a way we can identify the 1st time it goes throug the method, or is there another method we can use to identify the beginning of the request sequence?

Thanks,
Steven

Answer 1

Hi,

You could use processing pipeline to detect the request start and request end (DataService<T>.ProcessingPipeline).

But I would be interested why it happens in the first place:

What version of WCF DS are you using? I vaguely remember seeing this problem (multiple calls for GetQueryRootForResourceSet), but I think it should be fixed in the latest version.

Is it really a single request coming from the client? You can verify using fiddler.

If you could capture the callstacks of those multiple calls, somebody might have a better idea.

Thanks,

---

Vitek Karas [MSFT]

Answer 2

is there any easy means of checking which version is installed on the server?

this is the log given by Fiddler:

#	Result	Protocol	Host	URL	Body	Caching	Content-Type	Process	Comments	Custom
7	401	HTTP	devprt03	/ODataServiceTest/ODataService.svc/	1.293		text/html	excel:7396
8	200	HTTP	devprt03	/ODataServiceTest/ODataService.svc/	1.130	no-cache	application/xml;charset=utf-8	excel:7396
9	401	HTTP	devprt03	/ODataServiceTest/ODataService.svc/t_mex_drillback_item	1.293		text/html	excel:7396
10	200	HTTP	devprt03	/ODataServiceTest/ODataService.svc/t_mex_drillback_item	150.658.503	no-cache	application/atom+xml;charset=utf-8	excel:7396
15	401	HTTP	devprt03	/ODataServiceTest/ODataService.svc/t_mex_drillback_item?$skiptoken=100000L	1.293		text/html	excel:7396
16	200	HTTP	devprt03	/ODataServiceTest/ODataService.svc/t_mex_drillback_item?$skiptoken=100000L	150.905.762	no-cache	application/atom+xml;charset=utf-8	excel:7396
17	401	HTTP	devprt03	/ODataServiceTest/ODataService.svc/t_mex_drillback_item?$skiptoken=200000L	1.293		text/html	excel:7396
18	200	HTTP	devprt03	/ODataServiceTest/ODataService.svc/t_mex_drillback_item?$skiptoken=200000L	53.514.835	no-cache	application/atom+xml;charset=utf-8	excel:7396

as you can see, the multiple requests seem to occur from the paging (there are 230.000 records, and the paging was set on 100.000)

could this be the reason?

Answer 3

just ran some more tests, it appears from PowerPivot there is actually 1 request at the beginning, and 1 at the end

this results in 4 entries in my log, so 4 times it passes GetQueryRootForResourceSet

Answer 4

if I do the same request in internet explorer, I less amount of logs from GetQueryRootForResourceSet, but still more then 1,  and I only get 2 calls in fiddler (at the beginning and at the end)

Answer 5

Checking version: See what is the version of the WCF DS assembly your service is using. For starters, see if you're using System.Data.Services.dll or Microsoft.Data.Services.dll. If you own the project for the service, did you get the WCF DS using NuGet or not?

Each GET request to any of the entity sets will result in a call to that method. So if the set is paged and the client requests all the pages, there will be n number of GET requests (n is the number of pages) and thus n calls to the method.

The requests which return 401 should not get as far as the method call, so those should not be visible in your logs, but it depends how you implement authentication in your service.

Thanks,

---

Vitek Karas [MSFT]

Answer 6

thanks a lot! that makes sense

the 401 requests indeed don't arrive in my logs

Answer 7

in addition, the versions of WCF:

System.Data.Services
runtime version: v4.0.30319
Version: 4.0.0.0

We did not get the dlls using NuGet though.

Could this version be the issue?

Answer 8

If you want the latest greatest I would suggest you use the version from NuGet (it's 5.0.2 right now). See https://nuget.org/packages/Microsoft.Data.Services/5.0.2.

I'm not sure if your case is the one which was fixed, but it is possible.

Thanks,

---

Vitek Karas [MSFT]

Answer 9

Just tried using the nuget dlls, but it's the same issue, well nog really an issue, since it's because of the paging.

Will investigate the pipeline workaround :)

Answer 10

Hi,

If you're seeing exactly one call to the method per GET request, then it's behaving as it should. There's no effective way to "merge" the multiple requests which are used to gather all the pages of the results. Processing pipeline will not help you there.

The reason you can't really correlate the page requests is that they can come much later on. Some clients would download all of the pages as soon as possible, but other clients can wait (for very long time or never) to download the next page. Also from the point of view of the server they are really separate GET requests, there's no real connection between them, and this was intentional.

Thanks,

---

Vitek Karas [MSFT]

Answer 11

I'm currently investigating your idea to use the processing pipeline:

You could use processing pipeline to detect the request start and request end (DataService<T>.ProcessingPipeline).

do you have any more information in how to implement it easily? haven't succeeded so far ...

Answer 12

As noted above, the processing pipeline won't help with the paged responses. I don't think there's a way to "group" the page requests into one unit for logging purposes. There's definitely nothing in the standard OData which would allow you to do that.

Thanks,

---

Vitek Karas [MSFT]

Answer 13

it appears paging is not the main issue with the processing pipelines, but the client is.

when requesting a (large) feed using IE, it does give me 1 pass by in the pipeline on the url of the feed.

but when using PowerPivot, it passes by multiple times, so in that scenario filtering our the 'first' request is not possible again..

I'll just leave this for now and log each request :)