I may have a slight feeling as to what is going on, but I thought I'd ask to get confirmation, and potentially look at an alternative.
As a slight background, I've written a C# application that is providing a small front end to a stored procedure. The procedure contains a number of temporary table inserts from other stored procedures (and one table valued udf), and some xml processing.
In order to get a sense of how far along I am in the stored procedure, I'm subscribing to the InfoMessage (using an SqlInfoMessageEventHandler) from an SqlConnection. I've put some informative print statements in various places throughout the SP, so I can get a sense of the processing which has completed and update a status bar accordingly).
The rough structure of the SP is along these lines:
Print 'Beginning processing'
Create Temp Table
Insert into Temp Table from Table Valued UDF
Print 'Creating working Tables'
Create more Temp Tables
Insert into Temp Tables from SPs (each SP contains a print statement e.g 'Starting SP1').
All the messages are received and processed successfully, but there is a delay of a few seconds before any messages are returned from the server, then the first few arrive all at once (as though they were all processed but the output was held back for a while).
I had naively assumed (I still have a lot to learn about DB mechanics) that my initial print statement would be returned before any of the other processing instructions within the SP took place.
I assume that the server is doing something regarding fetching execution plans an/or potentially recalculating plans, or is it the case that query optimiser is doing some preprocessing before any results at all are returned?
Hopefully my question is reasonably understandable from that mess of text. Essentially, would the query optimiser make the server perform some of the selects/inserts before the procedure actually begins sequentially encountering my print statements?
I also tried doing some small temp table manipulation before my initial print statement, so some rows would be returned before the slow operations began but the result was much the same.
Thanks for any responses.
I can judge by MSSM, when you use PRINT statements they are late because of output happens once buffer is full. If you would like to output message straight away use:
RAISERROR('Message',0,0) WITH NOWAIT
It will work as Print but will be outputted straight away.
Hope this helps.