Performance Problem in HasExpression

Topics: Resolved
Nov 29, 2007 at 7:41 PM
To reproduce: Run VS.NET, open package, open data flow task. open Error List tab, get the profile below (from JetBrains' dotTrace 3.0). A similar trace is seen upon opening the data flow task, but that eventually terminates. In the trace below, the program never terminates. Disabling the expression hilighting feature solves the problem.

This is version 1.2:

80.57 % WindowActivated - 11016* ms - 28 calls - EnvDTE.dispWindowEventsSinkHelper.WindowActivated(Window, Window)
80.57 % windowEventsWindowActivated - 11016* ms - 10 calls - BIDSHelper.BIDSHelperWindowActivatedPluginBase.windowEventsWindowActivated(Window, Window)
80.57 % OnWindowActivated - 11016* ms - 2 calls - BIDSHelper.ExpressionHighlighterPlugin.OnWindowActivated(Window, Window)
79.20 % HasExpression - 10828* ms - 53 calls - BIDSHelper.ExpressionHighlighterPlugin.HasExpression(TaskHost, String, List<String>, Boolean &)
36.34 % Microsoft.SqlServer.Dts.Runtime.PropertyEnumerator.get_Current... - 4969 ms - 16720 calls
21.49 % Microsoft.SqlServer.Dts.Runtime.DtsEnumerator.MoveNext... - 2938 ms - 16822 calls
8.11 % Microsoft.SqlServer.Dts.Runtime.DtsProperty.get_Name... - 1109* ms - 16749 calls
5.60 % Microsoft.SqlServer.Dts.Runtime.DtsProperties.GetEnumerator... - 766 ms - 105 calls
3.43 % Microsoft.SqlServer.Dts.Runtime.TaskHost.get_Properties... - 469 ms - 105 calls
2.51 % Microsoft.SqlServer.Dts.Runtime.TaskHost.GetExpression... - 344 ms - 29 calls
0.91 % StartsWith - 125 ms - 16719 calls - System.String.StartsWith(String)
0.34 % System.Type.InvokeMember... - 47 ms - 105 calls
0.34 % GetObjectByID* - 47 ms - 53 calls - Microsoft.SqlServer.Dts.Pipeline.Wrapper.IDTSComponentMetaDataCollection90.GetObjectByID*(Int32)
0.23 % GetPackageConfigurationSettings - 31 ms - 2 calls - BIDSHelper.PackageConfigurationLoader.GetPackageConfigurationSettings(Configuration, Package, String, Boolean)
0.11 % MoveNext - 16 ms - 139 calls - System.Runtime.InteropServices.CustomMarshalers.EnumeratorViewOfEnumVariant.MoveNext()
0.11 % GetPrivateType - 16 ms - 1 call - BIDSHelper.ExpressionHighlighterPlugin.GetPrivateType(Type, String)
Coordinator
Nov 30, 2007 at 9:11 PM
First of all, did you download the 1.2 release from the Releases tab and use the installer? (Just checking this is the release version, and not a prior version of the source code you compiled yourself.)

I can't reproduce the problem of it getting into an infinite loop. Can you describe more exactly what you were doing with the Error List tab? Was it docked? Floating? Hidden so you had to slide your mouse over it to make it appear? Did you click the tab, or just mouse over it? Once the Error List opens up, what were the errors you were getting? Did you click on any of them or anything like that?

Can you go to the Help... About Microsoft Visual Studio menu option and click Copy Info and paste all the version info here? And what OS and service pack are you on?

Regarding performance, do note the performance warning at the bottom of this page: Expression and Configuration Highlighter. Please do vote for those suggestions on Connect as that could help tremendously. Just as a benchmark, if you have a dataflow with 20 derived column transforms, each with 5 derived columns, my screen takes 20-30 seconds to paint that. It all depends on how many expressionable properties you've got in that tab of the package designer.

Hope we can get to the bottom of this. Thanks for reporting it.
Dec 18, 2007 at 6:42 PM
Edited Dec 18, 2007 at 6:45 PM
Hi. I just tried it again with the new 1.2.0.1. Opening the package (to the Control Flow tab) seemed faster, but it's still unusable on my huge Data Flow task:

73.59 % HasExpression - 63297 ms - 138 calls - BIDSHelper.ExpressionHighlighterPlugin.HasExpression(TaskHost, String, List<String>, Boolean &)
26.72 % MoveNext - 22984 ms - 44278 calls - Microsoft.SqlServer.Dts.Runtime.DtsEnumerator.MoveNext()
20.76 % getCurrent - 17859 ms - 44013 calls - Microsoft.SqlServer.Dts.Runtime.PropertyEnumerator.getCurrent()
9.83 % getName - 8453 ms - 44129 calls - Microsoft.SqlServer.Dts.Runtime.DtsProperty.getName()
7.08 % GetEnumerator - 6094 ms - 276 calls - Microsoft.SqlServer.Dts.Runtime.DtsProperties.GetEnumerator()
4.74 % GetExpression - 4078 ms - 116 calls - Microsoft.SqlServer.Dts.Runtime.TaskHost.GetExpression(String)
3.67 % getProperties - 3156 ms - 276 calls - Microsoft.SqlServer.Dts.Runtime.TaskHost.getProperties()
0.56 % StartsWith - 484 ms - 44013 calls - System.String.StartsWith(String, Boolean, CultureInfo)
0.02 % Contains - 16 ms - 121 calls - System.Collections.Generic.List<T>.Contains(T)
0.02 % GetPackagePath - 16 ms - 121 calls - Microsoft.SqlServer.Dts.Runtime.DtsProperty.GetPackagePath(Object)

Note the amount of time taken by enumerating: 26.72% in Microsoft.SqlServer.Dts.Runtime.DtsEnumerator.MoveNext, 20.76% in PropertyEnumerator.get_Current(). That's a huge performance win if Microsoft can fix that.
Coordinator
Dec 18, 2007 at 8:14 PM
1.2.0.1 doesn't significantly improve performance of the expression highlighter. However, we are working on a complete restructuring of the expression highlighter. Here's the plan. Basically it will only lock up the UI for 2 seconds max, and then it will continue highlighting in the background if you exceed that 2 seconds. You'll be able to continue editing your package.

The other significant change is that we're making the highlighting track incremental changes to the package so that it doesn't do a full scan every time you focus on a window like it does now.

It should be significantly better. Thanks for your feedback... your feedback among others was instrumental in pushing us over the edge to rework this code.

Stay tuned for the next release with these improvements... hopefully early January 2008, I would guess.
Coordinator
Dec 18, 2007 at 8:16 PM
Yes, this was just a minor tweak that removed some redundant calls to getCurrent. We are currently looking at other possible strategies to make this component more useable with very large packages, including maybe incorporating some processing on a background thread so that the UI is still responsive.