SQL Prompt Refreshing very slowly, different query when connecting to DB

BiestMode

Hello, we've got quite a few complaints about slowness in a recent update of prompt. I've got some notes below on what I've found so far trying to troubleshoot this issue.

We have some workstations still on Prompt 10.14.21.9884 that are not affected by the issue and others on 10.14.23.11448 that are reporting the slowness. We're on the same network connected to the same databases. When you refresh suggestions on the system running 10.14.23.11448 prompt is querying the object definition for all stored procedures which takes quite a long time to complete. Doing the same thing on the older copy of prompt does not do this and instead is running a more lightweight set of queries to gather a list of objects in the DB.

This is the query in question we see running on the newer version that is taking over 6 minutes to complete that kicks off as soon as you connect a tab to a database. When I was profiling the older version of prompt this I never saw an instance of this query being used.

SELECT

obj.id AS object_id,

OBJECT_DEFINITION(obj.id) AS object_definition
FROM (VALUES ... **huge list of stored procedures here**

SQL Server Management Studio 20.2.30.0

ShaneG

I wish it only took 6 minutes... It is taking more like 15-20 minutes on some of our Databases.  Please fix this!!!!

cperez

Hi Biestmode,

Thanks for reaching out to Redgate Software and sorry to hear you are seeing some slowness on SQL Prompt's latest release. Would it be possible for you to place SQL Prompt in Verbose (SQL Prompt > Help > Enable Verbose Logging) and repeat the same test where you are seeing the extended slowness and then attach those logs here? 

BiestMode

I will do that today; it is getting stuck on the loading parameters step. Like I said we ran SQL profiler on the different version of SQL prompt. The query I referenced in my first post is selecting the entire object text of every procedure in the database and is taking 5+ minutes to complete and does not appear at all in the older version.

cperez

Hi @BiestMode,

Thanks for the follow up,

I was able to find out that the behavior for Stored Procedures in the latest version of Prompt did indeed change.

• Default values of Stored Procedure Parameters are now being displayed in suggestions.

Which was in 10.14.22.11347, so if you install the Prompt version prior to this one, I imagine your loading speeds will speed up for the time being. I currently have this escalated as a Performance Issue with SQL Prompt, so if you do end up finding time to test this in your end, I would kindly ask that the test be performed as such:

• Place Prompt into Verbose Mode  (SQL Prompt > Help > Enable Verbose Logging) while on the latest version and then let the slow load occur.
• Afterwards gather the verbose logs
• Then uninstall Prompt and downgrade to version 10.14.21.9884 and Place Prompt into Verbose Mode  (SQL Prompt > Help > Enable Verbose Logging) and repeat the test for loading suggestions.
• Attach both sets of logs to this post.

I can then make a comparison on the loading times and provide that to Development for remediation.
 

MFrenzel

I'm currently having the same problems.

I just installed SQL Prompt 10.15.3.12768 just so I can experience this penomenon too. Being the DBA I saw more and more of those Select-Queries @BiestMode described in the first post. I wondered why I didn't experience those behaviour. So I installed said version manually (because the auto updater said SQL Prompt was already up to date).

The little UI-Window just keeps displaying 

Loading {database_name}
Processing parameters…
{Loading bar approx. 25% filled}

The end of the verbose log reads like this (cleaned sensitive data)

<p>2024-11-27 15:03:11.673 +01:00 [Debug] [the-sql-server].[the-database] progress: Connecting...</p><p>2024-11-27 15:03:14.031 +01:00 [Information] Populating [the-sql-server].[the-database] as "Sql2016"</p><p>2024-11-27 15:03:14.031 +01:00 [Debug] Loading schema [the-database]</p><p>2024-11-27 15:03:14.031 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing schemas...</p><p>2024-11-27 15:03:14.046 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for schemas [the-database] = "00:00:00.0253054" [89 rows]</p>
<p>2024-11-27 15:03:14.046 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing objects...</p><p>2024-11-27 15:03:21.239 +01:00 [Warning] Couldn't find table owner 1441719338 for DF__xxxx.</p><p>2024-11-27 15:03:21.239 +01:00 [Warning] Couldn't find table owner 2074802799 for DF__xxxxx.</p><p>2024-11-27 15:03:21.239 +01:00 [Warning] Couldn't find table owner 2074802799 for DF__xxxxxx.</p><p>2024-11-27 15:03:21.239 +01:00 [Warning] Couldn't find table owner 2074802799 for DF__xxxxxxx.</p><p>2024-11-27 15:03:21.239 +01:00 [Warning] Couldn't find table owner 1765194240 for DF__xxxxxxxx.</p><p>2024-11-27 15:03:21.239 +01:00 [Warning] Couldn't find table owner 1765194240 for DF__xxxxxxxxx.</p><p>2024-11-27 15:03:21.255 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for objects [the-database] = "00:00:07.1952561" [43322 rows]</p><p>2024-11-27 15:03:21.255 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing master objects...</p><p>2024-11-27 15:03:21.255 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for master objects [the-database] = "00:00:00.0021998" [0 rows]</p><p>2024-11-27 15:03:21.255 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing triggers...</p><p>2024-11-27 15:03:21.355 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for triggers [the-database] = "00:00:00.1083274" [1093 rows]</p><p>2024-11-27 15:03:21.355 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing data types...</p><p>2024-11-27 15:03:21.371 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for data types [the-database] = "00:00:00.0165587" [47 rows]</p><p>2024-11-27 15:03:21.371 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing ansi data types...</p><p>2024-11-27 15:03:21.371 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for ansi data types [the-database] = "00:00:00.0000197" [0 rows]</p><p>2024-11-27 15:03:21.371 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing columns...</p><p>2024-11-27 15:03:29.375 +01:00 [Debug]&nbsp; &nbsp; &nbsp;Time taken for columns [the-database] = "00:00:07.9992848" [117396 rows]</p><p>2024-11-27 15:03:29.375 +01:00 [Debug] [the-sql-server].[the-database] progress: Processing parameters...</p><div></div>

And it will stay there for a very long time. Having currently 27225 stored procedures in [the-database]. It feels like the progress bar is filling up ever so slightly.

MFrenzel

I looked in the logs since the Loading bar in the little tool window was suddenly full after beeing only 25% full and found a System.OutOfMemoryException. Currently there are slightly over 27000 stored procedures in the-database… 

<div>2024-11-27 15:03:29.375 +01:00 [Debug] [the-server].[the-databse] progress: Processing parameters...
[~500 lines omitted for readability]
2024-11-27 15:44:30.746 +01:00 [Warning] Database population step failed for database the-database - step parameters</div><div>System.OutOfMemoryException: Exception of type 'System.OutOfMemoryException' was thrown.</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.TdsParser.TryReadPlpUnicodeChars(Char[]& buff, Int32 offst, Int32 len, TdsParserStateObject stateObj, Int32& totalCharsRead)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.TdsParser.TryReadSqlStringValue(SqlBuffer value, Byte type, Int32 length, Encoding encoding, Boolean isPlp, TdsParserStateObject stateObj)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.TdsParser.TryReadSqlValue(SqlBuffer value, SqlMetaDataPriv md, Int32 length, TdsParserStateObject stateObj, SqlCommandColumnEncryptionSetting columnEncryptionOverride, String columnName, SqlCommand command)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.SqlDataReader.TryReadColumnData()</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.SqlDataReader.TryReadColumnInternal(Int32 i, Boolean readHeaderOnly, Boolean forStreaming)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.SqlDataReader.TryReadColumn(Int32 i, Boolean setTimeout, Boolean allowPartiallyReadColumn, Boolean forStreaming)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.SqlDataReader.GetValueInternal(Int32 i)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.SqlDataReader.GetValue(Int32 i)</div><div>&nbsp; &nbsp;at Microsoft.Data.SqlClient.SqlDataReader.get_Item(Int32 i)</div><div>&nbsp; &nbsp;at RedGate.SqlPrompt.Cache.Population.Steps.Queries.ObjectDefinitionQuery.Execute(IDbCommand command, ICollection`1 objectIds)</div><div>&nbsp; &nbsp;at RedGate.SqlPrompt.Cache.Population.Steps.Queries.Unfiltered.ParameterQuery.Execute(IDbCommand command)</div><div>&nbsp; &nbsp;at RedGate.SqlPrompt.Cache.Population.Steps.ParameterPopulationStep.Populate(IDbCommand command)</div><div>&nbsp; &nbsp;at RedGate.SqlPrompt.Cache.Population.DatabasePopulator.PopulateStep(DebugLogger logger, DbCommand command, IDatabasePopulationStep populationStep, String databaseName, Single overallPercentageComplete)
</div>

cperez

Hi @MFrenzel

Thanks for chiming in, thankfully this issue has now since been replicated by development and they are currently testing the fix we are planning to implement. Once that has cleared smoke testing and is released in a new version of SQL Prompt, I will circle back here and let you guys know. Looking at the solution, it seems to be significantly faster after the fix is applied.

Cheers,

Christian Perez
Product Support