Multitenancy issue very slow

Topics: Core, General
Aug 3, 2013 at 8:52 AM
Edited Aug 3, 2013 at 8:56 AM
We have built an application as a module into Orchard that communicate with WCF services.
This one works fine and fast (every page render in less that 600 ms)
But when we have setup the application in mulitenancy environnement, we got from 2 seconds to 15 to render pages.
First we thought it was a WCF issue, but it's not.
We put some trace in code to know and it appears the this the last step thats involve time consumption.
The time is used doing hard work since CPU use onr full HEART on our 16 hearts machine.
Also, when we did put the log in DEBUG mode, we saw that Orchard deals with other sites when rendering a single page of a single site !
Logs below (see time between last twho lines of each).
Thanks for help

Patrick
PS: we don't use output caching beacause data is changing each for each request.

With 2 teanants
2013-08-02 18:50:00,583 [8] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 18:50:00,615 [8] CDTrade.Filters.StoreContextActionFilter - 031:StoreContextActionFilter:OnActionExecuting:CDTrade.Controllers.CatalogController
2013-08-02 18:50:00,616 [8] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 18:50:00,672 [8] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 18:50:00,783 [8] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 18:50:00,915 [8] CDTrade.Controllers.CatalogController - 000:Catalog:RegisterCanonicalLink:
2013-08-02 18:50:00,916 [8] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 18:50:00,965 [8] CDTrade.Controllers.CatalogController - 349:Catalog:Menu::langousta
2013-08-02 18:50:00,966 [8] CDTrade.Filters.StoreContextActionFilter - 000:StoreContextActionFilter:OnActionExecutedCDTrade.Controllers.CatalogController
2013-08-02 18:50:00,968 [8] CDTrade.Filters.ServicesFilter - 000:ServicesFilter:OnResultExecuting:CDTrade.Controllers.CatalogController:Menu
2013-08-02 18:50:01,200 [8] CDTrade.Filters.ServicesFilter - 000:ServicesFilter:OnResultExecuted:CDTrade.Controllers.CatalogController

With 20 tenants

2013-08-02 19:14:45,730 [23] CDTrade.Filters.StoreContextActionFilter - 000:StoreContextActionFilter:OnActionExecuting:CDTrade.Controllers.CatalogController
2013-08-02 19:14:45,732 [23] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 19:14:45,782 [23] CDTrade.Services.RemoteServices - 000:StoreServices
2013-08-02 19:14:45,897 [23] CDTrade.Controllers.CatalogController - 000:Catalog:RegisterCanonicalLink:
2013-08-02 19:14:45,900 [23] CDTrade.Controllers.CatalogController - 168:Catalog:Menu::langousta
2013-08-02 19:14:45,901 [23] CDTrade.Filters.StoreContextActionFilter - 000:StoreContextActionFilter:OnActionExecutedCDTrade.Controllers.CatalogController
2013-08-02 19:14:45,902 [23] CDTrade.Filters.ServicesFilter - 000:ServicesFilter:OnResultExecuting:CDTrade.Controllers.CatalogController:Menu
2013-08-02 19:14:50,220 [23] CDTrade.Filters.ServicesFilter - 000:ServicesFilter:OnResultExecuted:CDTrade.Controllers.CatalogController
Coordinator
Aug 4, 2013 at 5:02 AM
Edited Aug 4, 2013 at 5:03 AM
Do you have a simple repro that doesn't involve additional modules?
Aug 5, 2013 at 8:39 AM
No,
static pages are redered fast, even if we have 20 sites.
but we can provide you debug log. I didn't put it here because it's very large.
we also tried with empty views, the time reduce. Il seems really that's rendering is the problem.
Can you provide us some tests to perform so that we can locate the problem.
This issue ONLY HAPPENS when we have multinenancy active and is proportionnal to number of sites.
Thks

Patrick
Coordinator
Aug 5, 2013 at 8:44 AM
The only thing I can suggest is to profile and analyze the profile data.
Aug 5, 2013 at 9:43 AM
Thanks
We did a profiling
Result is :
Url.Action is consumming almost all time.
We also discoverd a linq .FirstOrDefault in a view but it's not the main issue.

Patrick
Aug 5, 2013 at 12:14 PM
Thanks a lot Bertrand !
We did rewrite a module to generate Urls by ourself and the performance is back again.
The original issue is still there. I don't understand how MVC parses routes to be so slow !!!
But for us, it's over.
Coordinator
Aug 6, 2013 at 12:03 AM
I'd like to know more. Can you share the part of the profile under Url.Action?
Aug 6, 2013 at 8:53 AM
Hi Bertrand,
Here you are.
If you want more, let me know a way to share files and wich files you need.
Thanks
Patrick

Image
Coordinator
Aug 6, 2013 at 9:16 AM
I'm afraid that's not going to be very helpful unfortunately. Can you dig under Url.Action? Do you have lots of routes in the system?