Hi There,
This post will include my investigation and proof of a dynamics 365 product code defect, and is intended to post for Dynamics 365 product team, I hope this will find them well.
I have several clients who are upgraded (or implemented earlier) to on-premise v9.1, and client users get used to the old classic UI which is based ASP.NET page, so they are still using the classic UI, we found there is a strange performance issue: when user opens the list view page of the system, if there are several lookup type columns within the view, and users' personal settings for list is set to display 250 lines, then the list becomes slow for no reason...sometimes takes more than 15 seconds and even more, while at the same time in new unified interface, for the same list view there is no such performance issue.
I've been sent for resolved this issue, at the first glance, I thought it could be easy shot, since people misuse Dynamics CRM plugin a lot, when I looked at all the suspicious custom code, and do the SQL database profiler trace, all is surprisedly not that bad...not bad enough for such level downgrade of performance, the SQL database query only takes few hundreds of milliseconds, and I have to turn my direction to Dynamics 365 CE itself, it could be either the Dynamics 365 App sever setup wrong way or Dynamics 365 product just does this wrong way, since there is no such issue at least for Dynamics CRM 2013.
After around one week deeply dived into the issue, it has been proved to be the issue of the Dynamics 365 product itself, there is a line code in the method
bool flag = writer.InnerWriter.ToString().Contains("otype=\"4567\"");
Otype with value "4567" is the "Audit" entity, and I believe this is a check for render Audit item, if the rendered text contains otype="4567", then it will render extra HTML element <UL> to wrapper the items, and I treat this as necessary check, however it introduced a performance issue, when system render 250 line records with 8 lookup columns, this LookupItem render method will at least execute 250*8=2000 times, and write.InnerWriter is StringWriter, in which it includes a StringBuilder, when render executes, the StringBuilder becomes bigger and bigger, at the end the length of StringBuilder will hold more than 3300000 characters in my debug case, it is huge, when writer.InnerWriter.ToString() executes, it shall allocate a new variable in memory and populate it with StringBuilder content, this is a kind of time consuming operation, and after that it evaluates a string compare operation: "Contains", this is another time consuming operation, all two operations is in a 2000 times loop, only these the string operations shall consume up to 15 seconds in my test case, I will prove this later, the below is complete version of the LookupItem render method:
private void RenderLookupItem(HtmlTextWriter writer)
{
if (HttpContext.Current.Request.Browser.Browser.ToLower().ToString() == "firefox")
{
writer.Write("<label for=\"" + CrmEncodeDecode.CrmHtmlEncode(AppResourceManager.Default.GetString("Web.Reports.Owner")) + "_label\" id=\"" + CrmEncodeDecode.CrmHtmlEncode(AppResourceManager.Default.GetString("Web.Reports.Owner")) + "_label\">");
writer.Write("<div class=\"ms-crm-div-NotVisible\">");
writer.Write(CrmEncodeDecode.CrmHtmlEncode(AppResourceManager.Default.GetString("Web.Reports.Owner")) + " ");
CrmEncodeDecode.CrmHtmlEncode(string.IsNullOrWhiteSpace(_name) ? AppResourceManager.Default.GetString("InlineEditControls.InlineLookup.NoName") : _name, writer);
writer.Write("</div></label>");
}
bool flag = writer.InnerWriter.ToString().Contains("otype=\"4567\"");
if (flag)
{
writer.Write("<ul><LI style=\"display:inline;white-space:nowrap\"><SPAN contentEditable=\"false\" title=\"");
}
else
{
writer.Write("<LI style=\"display:inline;white-space:nowrap\"><SPAN contentEditable=\"false\" title=\"");
}
CrmEncodeDecode.CrmHtmlAttributeEncode(_name, writer);
writer.Write("\"");
if (_style != null && _style.Length > 0)
{
CrmEncodeDecode.CrmWriteHtmlAttribute("class", _style, writer);
}
if (_category != null)
{
CrmEncodeDecode.CrmWriteHtmlAttribute("category", _category, writer);
}
if (_callback != null)
{
CrmEncodeDecode.CrmWriteHtmlAttribute("onclick", _callback, writer);
}
if (ShowPreviewOnRightClick)
{
writer.WriteAttribute("oncontextmenu", "handleGridRightClick(new Sys.UI.DomEvent(event))", fEncode: false);
}
if (Disabled && TabIndex >= 0)
{
writer.WriteAttribute("TabIndex", TabIndex.ToString(CultureInfo.InvariantCulture), fEncode: false);
writer.WriteAttribute("onkeydown", "openDisabledLui(new Sys.UI.DomEvent(event))", fEncode: false);
}
if (_data != null)
{
CrmEncodeDecode.CrmWriteHtmlAttribute("data", _data, writer);
}
if (_isProcessEnabled != null)
{
CrmEncodeDecode.CrmWriteHtmlAttribute("isprocessenabled", _isProcessEnabled, writer);
}
writer.Write(Expandos);
writer.Write('>');
if (IsMultiLookupItem)
{
writer.Write("<SPAN contentEditable=\"false\" unselectable=\"on\" wrapper=\"true\" oncontextmenu=\"handleGridRightClick(new Sys.UI.DomEvent(event))\">");
}
if (_icon != null)
{
using ImageStripImage imageStripImage = new ImageStripImage(_icon);
imageStripImage.AddExpando("alt", string.Empty);
imageStripImage.CssClass = "ms-crm-Lookup-Item";
imageStripImage.RenderControl(writer);
}
if (HttpContext.Current.Request != null)
{
if (HttpContext.Current.Request.Browser.Browser.ToLower().ToString() == "safari")
{
writer.Write("<SPAN wrapper='true' tabindex='0'>");
writer.Write("<span id='lblread' style='position: absolute;top:-999999em;left:auto;width:1px;height:1px;overflow:hidden;'></span>");
writer.Write("<SPAN class='ms-crm-LookupItem-Name' wrapper='true' title ='");
writer.Write(CrmEncodeDecode.CrmHtmlEncode(string.IsNullOrWhiteSpace(_name) ? AppResourceManager.Default.GetString("InlineEditControls.InlineLookup.NoName") : _name));
writer.Write("'>");
CrmEncodeDecode.CrmHtmlEncode(string.IsNullOrWhiteSpace(_name) ? AppResourceManager.Default.GetString("InlineEditControls.InlineLookup.NoName") : _name, writer);
writer.Write("</SPAN>");
writer.Write("</SPAN>");
writer.Write("</SPAN>");
}
else
{
writer.Write("<SPAN wrapper='true' tabindex='0'>");
writer.Write("<span class=\"ms-crm-Hidden-NoBehavior\" id=\"lblread\"></span>");
writer.Write("<SPAN class='ms-crm-LookupItem-Name' wrapper='true'>");
CrmEncodeDecode.CrmHtmlEncode(string.IsNullOrWhiteSpace(_name) ? AppResourceManager.Default.GetString("InlineEditControls.InlineLookup.NoName") : _name, writer);
writer.Write("</SPAN>");
writer.Write("</SPAN>");
writer.Write("</SPAN>");
}
}
if (IsMultiLookupItem)
{
writer.Write("</SPAN>");
}
if (flag)
{
writer.Write("</SPAN></LI></ul>");
}
else
{
writer.Write("</SPAN></LI>");
}
}
To test my theory, I wrote a console app and copy the render method to mockup this, please check the attachment for the screenshot of the code and result. basically for a 2000 times render loop, with a start string length 3.4m, it takes around 14 seconds, and if comment the line and populate the flag directly with false(it could be most of the time), it only take around 240 milliseconds!
I've tried the latest RU 1.41, it's not fixed, from my perspective, this issue is quite easy to repro, probably this may be a known issue for Microsoft product team, the line of code I believe is introduced in later version after Dynamics CRM 2013, since I've check the v6.0 assembly there is no such line of the code. they probably should come up a new way to do this check( whether is audit entity or not)and even think about to use a cache for that, just don't use string operation in this LookupItem render loop should be fine.
I hope this could be fixed soon, given the fact most of the people may use unified interface, but there still are a group of people they are still sticking with the classic UI :)
Any comments and suggestions is welcome.
Thanks,
Andy