WAITFOR RECEIVE results offset/delayed by 1 result

Question

I'm using SQL Service Broker. One connection SENDS a message on a queue with an XML message. I have an independent connection that is WAITFOR (RECEIVE TOP (1) ...), TIMEOUT 5000. This goes in a WHILE (1=1) loop in a single Management Studio query or a single ADO.NET SQL command execution with looped reader.NextResult().

All that seems to be correctly configured as I eventually get every result I expect.

But the problem is that the most recent result is always held back!

Let's say it's been running and there have been no SENDs, so it just keeps timing out with "None" printed to the console every 5 seconds.

Well now I SEND from SQL Management Studio query. The SEND command completes successfully and immediately. I immediately get a "None" in the console before the normal timeout interval. Then at the next timeout interval, my "Update" event appears!

And if I SEND two messages after a run of "None"s, then I'll immediately get "None" and then one "Update". Again, at the next timeout interval, the second "Update" will appear.

I can SEND ten messages and immediately get a "None" and nine "Update"s. Then I wait the five seconds timeout and get the final "Update".

All SENDs are on the same conversation and I never end the conversation. I do not RETAIN.

If I do a dirty read of the queue while the RECEIVE loop is running, the queue is always empty. If I stop the RECEIVE loop, it fills up. If I RECEIVE from another Management Studio query window, an additional clue is that when I stop the query, the final output always appears. These two facts make me think that the queue is being dequeued right away, but that something is latching on the reader side (but what??).

At first I figured it was just a weird behavior of Management Studio that I've seen before where PRINT(?) is sometimes delayed. But I would not expect that same behavior to show up in ADO.NET

Perhaps it has nothing to do with SSB, just the WAITFOR or just the streaming of multiple ResultSets. I will investigate those options, but I'm hoping someone might recognize this in the meantime.

Are these symptoms familiar to you?

Thanks!

• Is there some way to allow results to be flushed to the connection before the next blocking action? Is result/resultset delivery deferred?
• I don't see any extra locking in sp_lock results immediately following the SEND (nor otherwise)

---

For @Rikalous, here is the ADO.NET

using (var cmd = connection.CreateCommand())
{
    cmd.CommandTimeout = 0;
    cmd.CommandType = System.Data.CommandType.StoredProcedure;
    cmd.CommandText = "upWaitForReceive";

    using (var reader = cmd.ExecuteReader())
    {
        do
        {
            while (reader.Read()) // Individual messages received
            {
                string eventType = reader["EventType"] as string;

                // do something with the message
            }
        } while (reader.NextResult()); // next batch
    }
}

The sql loop is:

SELECT 'Initialized' AS EventType

WHILE (1=1) BEGIN
    ;DECLARE 
        @ConversationHandle UNIQUEIDENTIFIER, 
        @MessageTypeName SYSNAME, 
        @MessageBody XML

    ;WAITFOR(
        RECEIVE TOP (1) @ConversationHandle = conversation_handle, @MessageTypeName = message_type_name, @MessageBody = message_body
        FROM [dbo].[{0}_EventsQueue]
    ), TIMEOUT 5000

    IF (@@ROWCOUNT = 0) BEGIN
        SELECT 'None' AS EventType; -- Allow the blocking call to spin anyway
        CONTINUE;
    END

    IF (@MessageTypeName = ...) BEGIN
        SELECT ...
    END ELSE IF (@MessageTypeName = 'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog') BEGIN
        END CONVERSATION @ConversationHandle
        SELECT @Message = 'Conversation Terminated' -- Not Expected
        RAISERROR (@Message, 11, 1)
        RETURN
    END
END

;END CONVERSATION @ConversationHandle -- This will never be reached.  But if it were, this is what should be done

Answer 1

I believe RAISERROR (...) WITH NOWAIT should flush the buffer but I didn't play with it for quite some time.

Answer 2

Print-messages are not immediately sent. I regularly see arbitrarily high delays of printed debug messages. I think SQL Server waits for a network packet to be full, or some other kind of buffering.

If you just run an infinite loop that prints a small message every seconds you might get the first N messages after N seconds all at once. This might only be the case over TCP. Maybe shared memory is quicker, I don't know.

I have never seen result sets to be delayed, though. So try "printing" by performing a SELECT 'msg'.

The issue of delayed writes to the client is well known as it seems:

1. http://connect.microsoft.com/SQLServer/feedback/details/124994/print-output-lags-in-stored-procedure-it-is-always-delay-during-execution-of-a-batch-or-a-stored-procedure
2. https://stackoverflow.com/a/13047982/122718
3. http://msdn.microsoft.com/en-us/library/ms178592.aspx

On the other hand, all side-effects in your code (writing to a table or other DML) take place immediately anyway. Only the client app receives the PRINT messages delayed. This delay should not affect your production application at all because all the useful side-effects happen immediately.

In short, either ignore the problem or use RAISERROR('Message', 0, 0) WITH NOWAIT. An exception will only be thrown if the severity is greater than 10.