|
dev
newsgroups
|
|||||||||||||||||||||||
|
|||||||||||||||||||||||
Profiler logging 'SP:Starting' hundreds of times for one SPENV: Windows 2003, SQL 2000 SP1, ADO.Net 1.1 We are invoking a stored procedure from .Net code (Windows service) once. However, when we trace it using SQL Profiler, it reports hundreds of identical SP:Starting and SP:Completed events. All of which have 0 duration and 0 reads. The final SP:Starting and SP:Completed are correct. But why all the mess? I hope that this is purely an artifact of SQL Profiler and that SQL really isn't doing extra work? Note that doing a simple 'exec sp_mysp' from SQL Query Analyser shows a lot of repeated SQL statements in a similar fashion. I realise that we can filter out the duplicates by only capturing RPC:Completed events, but this is curious. I've attached the traces. Thanks, Stuart [attached file: Traces.zip] Stu Carter wrote:
Show quote > Hi, It looks like you have a function on a column in the query. Functions > > ENV: Windows 2003, SQL 2000 SP1, ADO.Net 1.1 > > We are invoking a stored procedure from .Net code (Windows service) > once. However, when we trace it using SQL Profiler, it reports > hundreds of identical SP:Starting and SP:Completed events. All of > which have 0 duration and 0 reads. > > The final SP:Starting and SP:Completed are correct. But why all the > mess? I hope that this is purely an artifact of SQL Profiler and that > SQL really isn't doing extra work? > > Note that doing a simple 'exec sp_mysp' from SQL Query Analyser shows > a lot of repeated SQL statements in a similar fashion. > > I realise that we can filter out the duplicates by only capturing > RPC:Completed events, but this is curious. I've attached the traces. > > Thanks, > Stuart get called (like an SP) for each row in the query and they may get called on every row even before the rows are filtered. If you are returning a lot of rows, I would say stay away from functions as they have severe performance issue when used this way. If you can, put the code for the function right in the column, or do some post-processing on the client if you can. You can also add the ObjectID and NestLevel columns to the Profiler trace to see more information. Thanks David,
That explains it - the Stored Procedure is querying a view, some columns of which are generated 'dynamically' with user defined functions. We'll have to look at the peformance issues with this. Cheers, Stuart Show quote "David Gugick" <davidg-nospam@imceda.com> wrote in message news:#OX6cX#$EHA.612@TK2MSFTNGP09.phx.gbl... > Stu Carter wrote: > > Hi, > > > > ENV: Windows 2003, SQL 2000 SP1, ADO.Net 1.1 > > > > We are invoking a stored procedure from .Net code (Windows service) > > once. However, when we trace it using SQL Profiler, it reports > > hundreds of identical SP:Starting and SP:Completed events. All of > > which have 0 duration and 0 reads. > > > > The final SP:Starting and SP:Completed are correct. But why all the > > mess? I hope that this is purely an artifact of SQL Profiler and that > > SQL really isn't doing extra work? > > > > Note that doing a simple 'exec sp_mysp' from SQL Query Analyser shows > > a lot of repeated SQL statements in a similar fashion. > > > > I realise that we can filter out the duplicates by only capturing > > RPC:Completed events, but this is curious. I've attached the traces. > > > > Thanks, > > Stuart > > It looks like you have a function on a column in the query. Functions > get called (like an SP) for each row in the query and they may get > called on every row even before the rows are filtered. If you are > returning a lot of rows, I would say stay away from functions as they > have severe performance issue when used this way. If you can, put the > code for the function right in the column, or do some post-processing on > the client if you can. > > You can also add the ObjectID and NestLevel columns to the Profiler > trace to see more information. > > > -- > David Gugick > Imceda Software > www.imceda.com >  |
|||||||||||||||||||||||
Other interesting topics