Nservicebus stops processing messages of the sql worker queue

[Daniel Powell]

We have an issue where it appears that Nservicebus is not processing messages off of the worker queue anymore, we are using it within a Topshelf windows service and simply restarting the service will get NSB to process the messages that are sitting in the worker queue.

Using the following packages

  <package id="NHibernate" version="4.0.1.4000" targetFramework="net45" />
  <package id="NServiceBus" version="5.2.9" targetFramework="net45" />
  <package id="NServiceBus.Autofac" version="5.0.0" targetFramework="net45" />
  <package id="NServiceBus.NHibernate" version="6.2.5" targetFramework="net45" />
  <package id="NServiceBus.Serilog" version="2.0.1.1" targetFramework="net45" />
  <package id="NServiceBus.SqlServer" version="2.2.0" targetFramework="net45" />

The logs in serilog do not show any errors and it appears to be logging that is is checking the worker queue

24 Nov 2015 14:20:05.416

 Starting a new receive task for 'WorkerQueue'. Total count current/max 1/1

24 Nov 2015 14:20:05.416

 Stopping a receive task for 'WorkerQueue'. Total count current/max 0/1

24 Nov 2015 14:20:05.213

 Starting a new receive task for 'WorkerQueue.Timeouts'. Total count current/max 1/1

24 Nov 2015 14:20:05.213

 Starting a new receive task for 'WorkerQueue.TimeoutsDispatcher'. Total count current/max 1/1

24 Nov 2015 14:20:05.213

 Stopping a receive task for 'WorkerQueue.Timeouts'. Total count current/max 0/1

24 Nov 2015 14:20:05.213

 Stopping a receive task for 'WorkerQueue.TimeoutsDispatcher'. Total count current/max 0/1

24 Nov 2015 14:20:05.104

 Starting a new receive task for 'WorkerQueue.Retries'. Total count current/max 1/1

24 Nov 2015 14:20:05.104

 Stopping a receive task for 'WorkerQueue.Retries'. Total count current/max 0/1

24 Nov 2015 14:20:01.791

 Starting a new receive task for 'WorkerQueue'. Total count current/max 1/1

24 Nov 2015 14:20:01.791

 Stopping a receive task for 'WorkerQueue'. Total count current/max 0/1

24 Nov 2015 14:20:01.588

 Starting a new receive task for 'WorkerQueue.TimeoutsDispatcher'. Total count current/max 1/1

24 Nov 2015 14:20:01.588

 Starting a new receive task for 'WorkerQueue.Timeouts'. Total count current/max 1/1

24 Nov 2015 14:20:01.588

 Stopping a receive task for 'WorkerQueue.TimeoutsDispatcher'. Total count current/max 0/1

24 Nov 2015 14:20:01.588

 Stopping a receive task for 'WorkerQueue.Timeouts'. Total count current/max 0/1

24 Nov 2015 14:20:01.479

 Starting a new receive task for 'WorkerQueue.Retries'. Total count current/max 1/1

24 Nov 2015 14:20:01.479

 Stopping a receive task for 'WorkerQueue.Retries'. Total count current/max 0/1

When I do a sql profile on the database I can only see it hitting the following (all without error)

WITH message AS (SELECT TOP(1) * FROM [dbo].[WorkerQueue.TimeoutsDispatcher] WITH (UPDLOCK, READPAST, ROWLOCK) ORDER BY [RowVersion] ASC)
 DELETE FROM message
 OUTPUT deleted.Id, deleted.CorrelationId, deleted.ReplyToAddress,
 deleted.Recoverable, deleted.Expires, deleted.Headers, deleted.Body;

WITH message AS (SELECT TOP(1) * FROM [dbo].[WorkerQueue.Retries] WITH (UPDLOCK, READPAST, ROWLOCK) ORDER BY [RowVersion] ASC)
 DELETE FROM message
 OUTPUT deleted.Id, deleted.CorrelationId, deleted.ReplyToAddress,
 deleted.Recoverable, deleted.Expires, deleted.Headers, deleted.Body;

WITH message AS (SELECT TOP(1) * FROM [dbo].[WorkerQueue.Timeouts] WITH (UPDLOCK, READPAST, ROWLOCK) ORDER BY [RowVersion] ASC)
 DELETE FROM message
 OUTPUT deleted.Id, deleted.CorrelationId, deleted.ReplyToAddress,
 deleted.Recoverable, deleted.Expires, deleted.Headers, deleted.Body;

If I'm understanding those log messages correctly its saying it checked the database for anything on the worker queue, but the sql profiler suggests that it isn't actually hitting the database.

I can't reliably reproduce this and it seems to sporadically occur after running without issue for a number of days, the only thing I can maybe pinpoint is that it seems that it occurs roughly around the times we experience a sql cluster failover or connection issue, although not always.

We are using the following configuration

LogManager.Use<SerilogFactory>();

var configuration = new BusConfiguration();
configuration.CustomConfigurationSource(new ConfigurationProvider(_queueName));
configuration.EndpointName(_queueName);
configuration.UsePersistence<NHibernatePersistence>()
             .ConnectionString(connectionString);
configuration.UseTransport<SqlServerTransport>()
             .DisableCallbackReceiver()
             .ConnectionString(connectionString);
configuration.UseSerialization<JsonSerializer>();
configuration.Transactions().DisableDistributedTransactions();
configuration.UseContainer<AutofacBuilder>(c => c.ExistingLifetimeScope(container));

We are using sagas that look something like 

public class OrderSaga : Saga<OrderSagaData>,
        IAmStartedByMessages<ProcessOrder>,
        IHandleMessages<ProcessFailedOrder>,
        ....more handle messages...
    {
   
    public OrderSaga(....dependencies...) {}

    protected override void ConfigureHowToFindSaga(SagaPropertyMapper<OrderSagaData> mapper)
    {
        mapper.ConfigureMapping<ProcessOrder>(m => m.OrderId).ToSaga(s => s.OrderId);
        ..more similar mappings...
    }

    public void Handle(ProcessOrder message) {
       ...do work....
    }

    ... more handlers
}

I have the sql trace and an application dump if that helps in debugging this at all.

[Szymon Pobiega]

Hi Daniel

So if I understood you correctly, you say that after some time the endpoints stops to query the main queue ([dbo].[WorkerQueue]) but it still queries the other queues. Are there any error messages in the logs before the endpoint stops to query the input queue?

Szymon

--
You received this message because you are subscribed to the Google Groups "Particular Software" group.
To unsubscribe from this group and stop receiving emails from it, send an email to particularsoftw...@googlegroups.com.
To post to this group, send email to particula...@googlegroups.com.
Visit this group at http://groups.google.com/group/particularsoftware.
To view this discussion on the web visit https://groups.google.com/d/msgid/particularsoftware/3d3defac-a854-4d53-b33e-6bf89171259c%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Daniel Powell]

Correct,

There is nothing out of the ordinary in the logs.

Earlier in the day there was issues with our SQL server going down and not being accessible for a while and this logged the transport circuit breaker was disarmed and rearmed, however I believe the entire windows server was restarted since then (although I have seen it happen along the same times as sql connectivity issues when the service hasn't been restarted).

So far it only happens sproadically in our QA environment which makes it difficult to actually debug anything other than providing log messages / application dumps.

To unsubscribe from this group and stop receiving emails from it, send an email to particularsoftware+unsub...@googlegroups.com.

[Daniel Powell]

I've been able to somewhat reproduce it by starting up the windows service, letting it configure and poll the database, ensuring theres at least one message to process in there, take the sql server down and leave it down for a while, then start the sql server.

The logs look as following

 

Startup:

2015-11-25 14:31:43.918 +10:00 [Information] Starting "WorkerQueue" queue.
2015-11-25 14:31:44.429 +10:00 [Information] Activating persistence '"NHibernatePersistence"' to provide storage for 'NServiceBus.Persistence.StorageType+GatewayDeduplication' storage.
2015-11-25 14:31:44.431 +10:00 [Information] Activating persistence '"NHibernatePersistence"' to provide storage for 'NServiceBus.Persistence.StorageType+Timeouts' storage.
2015-11-25 14:31:44.437 +10:00 [Information] Activating persistence '"NHibernatePersistence"' to provide storage for 'NServiceBus.Persistence.StorageType+Sagas' storage.
2015-11-25 14:31:44.440 +10:00 [Information] Activating persistence '"NHibernatePersistence"' to provide storage for 'NServiceBus.Persistence.StorageType+Subscriptions' storage.
2015-11-25 14:31:44.442 +10:00 [Information] Activating persistence '"NHibernatePersistence"' to provide storage for 'NServiceBus.Persistence.StorageType+Outbox' storage.
2015-11-25 14:31:44.753 +10:00 [Debug] Error queue retrieved from <MessageForwardingInCaseOfFaultConfig> element in config file.
2015-11-25 14:31:44.773 +10:00 [Debug] Associated 'NServiceBus.Scheduling.Messages.ScheduledTask' message with 'NServiceBus.Scheduling.ScheduledTaskMessageHandler' handler
2015-11-25 14:31:44.780 +10:00 [Debug] Associated 'Worker.Messages.ProcessOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.781 +10:00 [Debug] Associated 'Core.OrderProcessing.ProcessFailedOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.783 +10:00 [Debug] Associated 'Worker.Messages.NotifyCustomerAboutFailedOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.784 +10:00 [Debug] Associated 'Worker.Messages.FinishFailedOrderProcessing' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.786 +10:00 [Debug] Associated 'Core.OrderProcessing.ProcessRejectedOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.788 +10:00 [Debug] Associated 'Core.OrderProcessing.ProcessExpiredOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.789 +10:00 [Debug] Associated 'Core.OrderProcessing.ProcessAcceptedOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.791 +10:00 [Debug] Associated 'Worker.Messages.NotifyCustomerAboutSuccessfulOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.792 +10:00 [Debug] Associated 'Worker.Messages.FinishSuccesfulOrderProcessing' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.797 +10:00 [Debug] Associated 'Worker.Messages.ProcessStalledOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.798 +10:00 [Debug] Associated 'Worker.Messages.ProcessGiftCardForAcceptedOrder' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.800 +10:00 [Debug] Associated 'Worker.Messages.UpdateStoreStock' message with 'Worker.Sagas.OrderSaga' handler
2015-11-25 14:31:44.804 +10:00 [Information] Using license in current folder ("C:\dev\Worker\bin\Debug\NServiceBus\License.xml").
2015-11-25 14:31:44.819 +10:00 [Information] Expires on 11/16/2016 00:00:00
2015-11-25 14:31:44.908 +10:00 [Debug] Routing for message: Worker.Messages.FinishFailedOrderProcessing set to "WorkerQueue@devpc"
2015-11-25 14:31:44.909 +10:00 [Debug] Routing for message: Worker.Messages.FinishSuccesfulOrderProcessing set to "WorkerQueue@devpc"
2015-11-25 14:31:44.910 +10:00 [Debug] Routing for message: Worker.Messages.NotifyCustomerAboutFailedOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.911 +10:00 [Debug] Routing for message: Worker.Messages.NotifyCustomerAboutSuccessfulOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.912 +10:00 [Debug] Routing for message: Worker.Messages.ProcessGiftCardForAcceptedOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.913 +10:00 [Debug] Routing for message: Worker.Messages.ProcessStalledOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.914 +10:00 [Debug] Routing for message: Worker.Messages.UpdateStoreStock set to "WorkerQueue@devpc"
2015-11-25 14:31:44.915 +10:00 [Debug] Routing for message: Worker.Messages.ProcessOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.916 +10:00 [Debug] Routing for message: Core.OrderProcessing.ProcessAcceptedOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.917 +10:00 [Debug] Routing for message: Core.OrderProcessing.ProcessExpiredOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.918 +10:00 [Debug] Routing for message: Core.OrderProcessing.ProcessFailedOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.918 +10:00 [Debug] Routing for message: Core.OrderProcessing.ProcessRejectedOrder set to "WorkerQueue@devpc"
2015-11-25 14:31:44.924 +10:00 [Information] Number of messages found: 13
2015-11-25 14:31:44.925 +10:00 [Debug] Message definitions:
 "MessageType: Core.OrderProcessing.ProcessAcceptedOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Core.OrderProcessing.ProcessAcceptedOrder
MessageType: Core.OrderProcessing.ProcessExpiredOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Core.OrderProcessing.ProcessExpiredOrder
MessageType: Core.OrderProcessing.ProcessFailedOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Core.OrderProcessing.ProcessFailedOrder
MessageType: Core.OrderProcessing.ProcessRejectedOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Core.OrderProcessing.ProcessRejectedOrder
MessageType: NServiceBus.Scheduling.Messages.ScheduledTask, Recoverable: True, TimeToBeReceived: Not set , Parent types: NServiceBus.Scheduling.Messages.ScheduledTask
MessageType: Worker.Messages.FinishFailedOrderProcessing, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.FinishFailedOrderProcessing
MessageType: Worker.Messages.FinishSuccesfulOrderProcessing, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.FinishSuccesfulOrderProcessing
MessageType: Worker.Messages.NotifyCustomerAboutFailedOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.NotifyCustomerAboutFailedOrder
MessageType: Worker.Messages.NotifyCustomerAboutSuccessfulOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.NotifyCustomerAboutSuccessfulOrder
MessageType: Worker.Messages.ProcessGiftCardForAcceptedOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.ProcessGiftCardForAcceptedOrder
MessageType: Worker.Messages.ProcessStalledOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.ProcessStalledOrder
MessageType: Worker.Messages.UpdateStoreStock, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.UpdateStoreStock
MessageType: Worker.Messages.ProcessOrder, Recoverable: True, TimeToBeReceived: Not set , Parent types: Worker.Messages.ProcessOrder
"
2015-11-25 14:31:45.456 +10:00 [Debug] Error queue retrieved from <MessageForwardingInCaseOfFaultConfig> element in config file.
2015-11-25 14:31:45.659 +10:00 [Information] ------------- FEATURES ----------------
Name: CriticalErrorHandling
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: CustomIDataBus
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [DataBus]


Name: DataBus
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -No databus properties was found in available messages


Name: Encryptor
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -No encryption properties was found in available messages


Name: ErrorSubscribers
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: ForwarderFaultManager
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: InMemoryFaultManager
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: InstallationSupport
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: CriticalTimeMonitoring
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: Audit
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: AutoSubscribe
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: ApplySubscriptions


Name: MsmqSubscriptionPersistence
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: Scheduler
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: CustomSerialization
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -CustomSerialization not enable since serialization definition not detected.


Name: ForwardReceivedMessages
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -No forwarding address was defined in the unicastbus config


Name: RegisterHandlersInOrder
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: SLAMonitoring
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: LicenseReminder
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: Outbox
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: InMemoryGatewayPersistence
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [Gateway]


Name: InMemoryOutboxPersistence
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [Outbox]


Name: InMemorySagaPersistence
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [Sagas]


Name: InMemorySubscriptionPersistence
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [MessageDrivenSubscriptions]


Name: InMemoryTimeoutPersistence
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [TimeoutManager]


Name: TimeoutManagerBasedDeferral
Version: 5.2.10
Enabled by Default: No
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: UnicastBus
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: BinarySerialization
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -BinarySerialization not enable since serialization definition not detected.


Name: BsonSerialization
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -BsonSerialization not enable since serialization definition not detected.


Name: JsonSerialization
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: XmlSerialization
Version: 5.2.10
Enabled by Default: Yes
Status: Disabled
Deactivation reason: Did not fulfill its Prerequisites:
   -XmlSerialization not enable since serialization definition not detected.


Name: MsmqTransportConfigurator
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies:


Name: TimeoutManager
Version: 5.2.10
Enabled by Default: No
Status: Enabled
Dependencies: [TimeoutManagerBasedDeferral]
Startup Tasks: None


Name: Sagas
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: SecondLevelRetries
Version: 5.2.10
Enabled by Default: Yes
Status: Enabled
Dependencies: [ForwarderFaultManager]
Startup Tasks: None


Name: DataBusFileBased
Version: 5.2.10
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [DataBus]


Name: StorageDrivenPublishing
Version: 5.2.10
Enabled by Default: No
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: MessageDrivenSubscriptions
Version: 5.2.10
Enabled by Default: No
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: NHibernateGatewayDeduplication
Version: 6.2.5
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [Gateway]


Name: NHibernateDBConnectionProvider
Version: 6.2.5
Enabled by Default: No
Status: Enabled
Dependencies: None
Startup Tasks: None


Name: NHibernateOutboxStorage
Version: 6.2.5
Enabled by Default: No
Status: Disabled
Deactivation reason: Did not meet one of the dependencies: [Outbox]


Name: NHibernateSagaStorage
Version: 6.2.5
Enabled by Default: No
Status: Enabled
Dependencies: [Sagas]
Startup Tasks: None


Name: NHibernateStorageSession
Version: 6.2.5
Enabled by Default: No
Status: Enabled
Dependencies: [NHibernateDBConnectionProvider]
Startup Tasks: None


Name: NHibernateSubscriptionStorage
Version: 6.2.5
Enabled by Default: No
Status: Enabled
Dependencies: [StorageDrivenPublishing]
Startup Tasks: None


Name: NHibernateTimeoutStorage
Version: 6.2.5
Enabled by Default: No
Status: Enabled
Dependencies: [TimeoutManager],[NHibernateDBConnectionProvider]
Startup Tasks: None


Name: ValidateOutboxOrAmbientTransactionsEnabled
Version: 2.2.0
Enabled by Default: Yes
Status: Enabled
Dependencies: None
Startup Tasks: ValiateTask


Name: SqlServerTransport
Version: 2.2.0
Enabled by Default: No
Status: Enabled
Dependencies: None
Startup Tasks: None




2015-11-25 14:31:45.796 +10:00 [Information] Registration 'OutboxDeduplication' specified in the insertbefore of the 'OpenSqlConnection' step does not exist!
2015-11-25 14:31:45.797 +10:00 [Information] Registration 'OutboxRecorder' specified in the insertbefore of the 'OpenNHibernateSession' step does not exist!
2015-11-25 14:31:45.802 +10:00 [Information] Registration 'OutboxDeduplication' specified in the insertafter of the 'OpenNHibernateSession' step does not exist!
2015-11-25 14:31:45.824 +10:00 [Debug] '"# of msgs successfully processed / sec"' counter initialized for '"WorkerQueue"'
2015-11-25 14:31:45.826 +10:00 [Debug] '"# of msgs pulled from the input queue /sec"' counter initialized for '"WorkerQueue"'
2015-11-25 14:31:45.830 +10:00 [Debug] '"# of msgs failures / sec"' counter initialized for '"WorkerQueue"'
2015-11-25 14:31:45.835 +10:00 [Information] Receiver for queue '"WorkerQueue"' started with maximum concurrency '1'
2015-11-25 14:31:45.839 +10:00 [Debug] Starting a new receive task for '"WorkerQueue"'. Total count current/max 1/1
2015-11-25 14:31:45.847 +10:00 [Debug] Starting 3/3 "NServiceBus.SecondLevelRetries.SecondLevelRetriesProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite
2015-11-25 14:31:45.847 +10:00 [Debug] Starting 1/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutMessageProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite
2015-11-25 14:31:45.847 +10:00 [Debug] Starting 2/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutDispatcherProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite
2015-11-25 14:31:45.850 +10:00 [Debug] Starting satellite "NServiceBus.SecondLevelRetries.SecondLevelRetriesProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" for "WorkerQueue.Retries".
2015-11-25 14:31:45.852 +10:00 [Debug] Starting satellite "NServiceBus.Timeout.Hosting.Windows.TimeoutDispatcherProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" for "WorkerQueue.TimeoutsDispatcher".
2015-11-25 14:31:45.855 +10:00 [Debug] '"# of msgs successfully processed / sec"' counter initialized for '"WorkerQueue.TimeoutsDispatcher"'
2015-11-25 14:31:45.853 +10:00 [Debug] '"# of msgs successfully processed / sec"' counter initialized for '"WorkerQueue.Retries"'
2015-11-25 14:31:45.851 +10:00 [Debug] Starting satellite "NServiceBus.Timeout.Hosting.Windows.TimeoutMessageProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" for "WorkerQueue.Timeouts".
2015-11-25 14:31:45.856 +10:00 [Debug] '"# of msgs pulled from the input queue /sec"' counter initialized for '"WorkerQueue.TimeoutsDispatcher"'
2015-11-25 14:31:45.859 +10:00 [Debug] '"# of msgs successfully processed / sec"' counter initialized for '"WorkerQueue.Timeouts"'
2015-11-25 14:31:45.862 +10:00 [Debug] '"# of msgs pulled from the input queue /sec"' counter initialized for '"WorkerQueue.Timeouts"'
2015-11-25 14:31:45.861 +10:00 [Debug] '"# of msgs failures / sec"' counter initialized for '"WorkerQueue.TimeoutsDispatcher"'
2015-11-25 14:31:45.865 +10:00 [Information] Receiver for queue '"WorkerQueue.TimeoutsDispatcher"' started with maximum concurrency '1'
2015-11-25 14:31:45.864 +10:00 [Debug] '"# of msgs failures / sec"' counter initialized for '"WorkerQueue.Timeouts"'
2015-11-25 14:31:45.857 +10:00 [Debug] '"# of msgs pulled from the input queue /sec"' counter initialized for '"WorkerQueue.Retries"'
2015-11-25 14:31:45.872 +10:00 [Information] Receiver for queue '"WorkerQueue.Timeouts"' started with maximum concurrency '1'
2015-11-25 14:31:45.867 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:31:45.880 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:31:45.883 +10:00 [Information] Started 1/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutMessageProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite
2015-11-25 14:31:45.874 +10:00 [Debug] '"# of msgs failures / sec"' counter initialized for '"WorkerQueue.Retries"'
2015-11-25 14:31:45.886 +10:00 [Information] Receiver for queue '"WorkerQueue.Retries"' started with maximum concurrency '1'
2015-11-25 14:31:45.884 +10:00 [Debug] Polling for timeouts at 11/25/2015 14:31:45.
2015-11-25 14:31:45.888 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:31:45.882 +10:00 [Information] Started 2/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutDispatcherProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite
2015-11-25 14:31:45.890 +10:00 [Information] Started 3/3 "NServiceBus.SecondLevelRetries.SecondLevelRetriesProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite
2015-11-25 14:31:45.900 +10:00 [Information] "WorkerQueue" queue started.
2015-11-25 14:31:45.909 +10:00 [Debug] Started "NServiceBus.Features.FeatureActivator+Runner, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c".
2015-11-25 14:31:46.051 +10:00 [Debug] Started "NServiceBus.Unicast.Subscriptions.MessageDrivenSubscriptions.StorageInitializer, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c".
2015-11-25 14:31:46.064 +10:00 [Debug] Polling next retrieval is at 11/25/2015 14:32:46.

Begins to process an already existing mesasge (note it throws an exception as the message needs to contact an external service I didnt have running at the time)

2015-11-25 14:31:48.614 +10:00 [Information] Failed to process message
2015-11-25 14:31:49.453 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:31:49.454 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:31:49.455 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:31:49.456 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:31:49.456 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:31:49.456 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:31:49.682 +10:00 [Information] Failed to process message
2015-11-25 14:31:51.864 +10:00 [Warning] "Message with 'af96f2d8-0823-440d-88d3-a55b00dd5d3c' id has failed FLR and" will be handed over to SLR for retry attempt 2.
2015-11-25 14:31:51.867 +10:00 [Debug] Ignoring start task request for '"WorkerQueue"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:31:52.013 +10:00 [Debug] Defer message and send it to "WorkerQueue"
2015-11-25 14:31:53.012 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:31:53.013 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:31:53.015 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:31:53.017 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:31:55.428 +10:00 [Debug] Stopping a receive task for '"WorkerQueue"'. Total count current/max 0/1
2015-11-25 14:31:55.430 +10:00 [Debug] Starting a new receive task for '"WorkerQueue"'. Total count current/max 1/1
2015-11-25 14:31:55.575 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:31:55.576 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:31:56.573 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:31:56.575 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:31:56.630 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:31:56.631 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:31:58.989 +10:00 [Debug] Stopping a receive task for '"WorkerQueue"'. Total count current/max 0/1
2015-11-25 14:31:58.990 +10:00 [Debug] Starting a new receive task for '"WorkerQueue"'. Total count current/max 1/1
2015-11-25 14:31:59.135 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:31:59.137 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:32:00.133 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:32:00.134 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:32:00.189 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:32:00.190 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1

I then stopped the sql server 

2015-11-25 14:32:06.106 +10:00 [Debug] Stopping a receive task for '"WorkerQueue"'. Total count current/max 0/1
2015-11-25 14:32:06.109 +10:00 [Debug] Starting a new receive task for '"WorkerQueue"'. Total count current/max 1/1
2015-11-25 14:32:06.254 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:32:06.257 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:32:06.413 +10:00 [Warning] An exception occurred when connecting to the configured SQLServer instance
System.Data.SqlClient.SqlException (0x80131904): A connection was successfully established with the server, but then an error occurred during the pre-login handshake. (provider: Shared Memory Provider, error: 0 - No process is on the other end of the pipe.) ---> System.ComponentModel.Win32Exception (0x80004005): No process is on the other end of the pipe
   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at System.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)
   at System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
   at System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
   at System.Data.SqlClient.TdsParser.ConsumePreLoginHandshake(SqlAuthenticationMethod authType, Boolean encrypt, Boolean trustServerCert, Boolean integratedSecurity, Boolean& marsCapable, Boolean& fedAuthRequired)
   at System.Data.SqlClient.TdsParser.Connect(ServerInfo serverInfo, SqlInternalConnectionTds connHandler, Boolean ignoreSniOpenTimeout, Int64 timerExpire, Boolean encrypt, Boolean trustServerCert, Boolean integratedSecurity, Boolean withFailover, SqlAuthenticationMethod authType)
   at System.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(ServerInfo serverInfo, String newPassword, SecureString newSecurePassword, Boolean ignoreSniOpenTimeout, TimeoutTimer timeout, Boolean withFailover)
   at System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(ServerInfo serverInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString connectionOptions, SqlCredential credential, TimeoutTimer timeout)
   at System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(TimeoutTimer timeout, SqlConnectionString connectionOptions, SqlCredential credential, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance)
   at System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString userConnectionOptions, SessionData reconnectSessionData, DbConnectionPool pool, String accessToken)
   at System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NServiceBus.Transports.SQLServer.ConnectionFactory.<>c.<Default>b__3_0(String cs)
   at NServiceBus.Transports.SQLServer.ConnectionFactory.OpenNewConnection(String connectionString)
   at NServiceBus.Transports.SQLServer.NativeTransactionReceiveStrategy.TryReceiveFrom(TableBasedQueue queue)
   at NServiceBus.Transports.SQLServer.AdaptivePollingReceiver.Try(Boolean& success)
   at NServiceBus.Transports.SQLServer.AdaptiveExecutor`1.ReceiveLoop(Object obj)
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:c22b0fdc-aa12-4d42-b0ea-7d3b51ea7343
Error Number:233,State:0,Class:20
2015-11-25 14:32:06.424 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now in the armed state
2015-11-25 14:32:06.463 +10:00 [Warning] An exception occurred when connecting to the configured SQLServer instance
System.Data.SqlClient.SqlException (0x80131904): A connection was successfully established with the server, but then an error occurred during the pre-login handshake. (provider: Shared Memory Provider, error: 0 - No process is on the other end of the pipe.) ---> System.ComponentModel.Win32Exception (0x80004005): No process is on the other end of the pipe
   at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NServiceBus.Transports.SQLServer.ConnectionFactory.<>c.<Default>b__3_0(String cs)
   at NServiceBus.Transports.SQLServer.ConnectionFactory.OpenNewConnection(String connectionString)
   at NServiceBus.Transports.SQLServer.NativeTransactionReceiveStrategy.TryReceiveFrom(TableBasedQueue queue)
   at NServiceBus.Transports.SQLServer.AdaptivePollingReceiver.Try(Boolean& success)
   at NServiceBus.Transports.SQLServer.AdaptiveExecutor`1.ReceiveLoop(Object obj)
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:c22b0fdc-aa12-4d42-b0ea-7d3b51ea7343
Error Number:233,State:0,Class:20
2015-11-25 14:32:06.466 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now in the armed state
2015-11-25 14:32:07.253 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:32:07.254 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:32:07.254 +10:00 [Warning] An exception occurred when connecting to the configured SQLServer instance
System.Data.SqlClient.SqlException (0x80131904): A connection was successfully established with the server, but then an error occurred during the pre-login handshake. (provider: Shared Memory Provider, error: 0 - No process is on the other end of the pipe.) ---> System.ComponentModel.Win32Exception (0x80004005): No process is on the other end of the pipe
   at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NServiceBus.Transports.SQLServer.ConnectionFactory.<>c.<Default>b__3_0(String cs)
   at NServiceBus.Transports.SQLServer.ConnectionFactory.OpenNewConnection(String connectionString)
   at NServiceBus.Transports.SQLServer.NativeTransactionReceiveStrategy.TryReceiveFrom(TableBasedQueue queue)
   at NServiceBus.Transports.SQLServer.AdaptivePollingReceiver.Try(Boolean& success)
   at NServiceBus.Transports.SQLServer.AdaptiveExecutor`1.ReceiveLoop(Object obj)
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:c22b0fdc-aa12-4d42-b0ea-7d3b51ea7343
Error Number:233,State:0,Class:20
2015-11-25 14:32:07.258 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now in the armed state
2015-11-25 14:32:07.307 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:32:07.308 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:32:07.309 +10:00 [Warning] An exception occurred when connecting to the configured SQLServer instance
System.Data.SqlClient.SqlException (0x80131904): A connection was successfully established with the server, but then an error occurred during the pre-login handshake. (provider: Shared Memory Provider, error: 0 - No process is on the other end of the pipe.) ---> System.ComponentModel.Win32Exception (0x80004005): No process is on the other end of the pipe
   at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NServiceBus.Transports.SQLServer.ConnectionFactory.<>c.<Default>b__3_0(String cs)
   at NServiceBus.Transports.SQLServer.ConnectionFactory.OpenNewConnection(String connectionString)
   at NServiceBus.Transports.SQLServer.NativeTransactionReceiveStrategy.TryReceiveFrom(TableBasedQueue queue)
   at NServiceBus.Transports.SQLServer.AdaptivePollingReceiver.Try(Boolean& success)
   at NServiceBus.Transports.SQLServer.AdaptiveExecutor`1.ReceiveLoop(Object obj)
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:c22b0fdc-aa12-4d42-b0ea-7d3b51ea7343
Error Number:233,State:0,Class:20
2015-11-25 14:32:07.313 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now in the armed state
2015-11-25 14:32:15.866 +10:00 [Debug] Ignoring start task request for '"WorkerQueue"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:15.925 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.TimeoutsDispatcher"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:15.925 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.Timeouts"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:15.925 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.Retries"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:15.943 +10:00 [Debug] Resolving job
2015-11-25 14:32:16.427 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:32:16.429 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:32:16.468 +10:00 [Debug] Stopping a receive task for '"WorkerQueue"'. Total count current/max 0/1
2015-11-25 14:32:16.469 +10:00 [Debug] Starting a new receive task for '"WorkerQueue"'. Total count current/max 1/1
2015-11-25 14:32:17.259 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:32:17.261 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:32:17.314 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:32:17.316 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:32:25.879 +10:00 [Debug] Ignoring start task request for '"WorkerQueue"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:25.926 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.TimeoutsDispatcher"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:25.926 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.Timeouts"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:25.926 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.Retries"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:32:30.482 +10:00 [Warning] An exception occurred when connecting to the configured SQLServer instance
System.Data.SqlClient.SqlException (0x80131904): A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server) ---> System.ComponentModel.Win32Exception (0x80004005): The system cannot find the file specified
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NServiceBus.Transports.SQLServer.ConnectionFactory.<>c.<Default>b__3_0(String cs)
   at NServiceBus.Transports.SQLServer.ConnectionFactory.OpenNewConnection(String connectionString)
   at NServiceBus.Transports.SQLServer.NativeTransactionReceiveStrategy.TryReceiveFrom(TableBasedQueue queue)
   at NServiceBus.Transports.SQLServer.AdaptivePollingReceiver.Try(Boolean& success)
   at NServiceBus.Transports.SQLServer.AdaptiveExecutor`1.ReceiveLoop(Object obj)
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:2,State:0,Class:20
2015-11-25 14:32:32.099 +10:00 [Information] The circuit breaker for "TimeoutStorageConnectivity" is now in the armed state
2015-11-25 14:32:33.101 +10:00 [Debug] Polling for timeouts at 11/25/2015 14:32:33.
2015-11-25 14:32:33.104 +10:00 [Warning] Failed to fetch timeouts from the timeout storage
System.Data.SqlClient.SqlException (0x80131904): A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server) ---> System.ComponentModel.Win32Exception (0x80004005): The system cannot find the file specified
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NHibernate.Connection.DriverConnectionProvider.GetConnection()
   at NServiceBus.Persistence.NHibernate.ISessionFactoryExtensions.GetConnection(ISessionFactory sessionFactory) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\Internal\ISessionFactoryExtensions.cs:line 13
   at NServiceBus.TimeoutPersisters.NHibernate.TimeoutPersister.GetNextChunk(DateTime startSlice, DateTime& nextTimeToRunQuery) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\TimeoutPersisters\TimeoutPersister.cs:line 30
   at NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver.Poll(Object obj) in C:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Timeout\Hosting\Windows\TimeoutPersisterReceiver.cs:line 90
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:2,State:0,Class:20
2015-11-25 14:32:34.111 +10:00 [Debug] Polling for timeouts at 11/25/2015 14:32:34.
2015-11-25 14:32:34.112 +10:00 [Warning] Failed to fetch timeouts from the timeout storage
System.Data.SqlClient.SqlException (0x80131904): A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server) ---> System.ComponentModel.Win32Exception (0x80004005): The system cannot find the file specified
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NHibernate.Connection.DriverConnectionProvider.GetConnection()
   at NServiceBus.Persistence.NHibernate.ISessionFactoryExtensions.GetConnection(ISessionFactory sessionFactory) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\Internal\ISessionFactoryExtensions.cs:line 13
   at NServiceBus.TimeoutPersisters.NHibernate.TimeoutPersister.GetNextChunk(DateTime startSlice, DateTime& nextTimeToRunQuery) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\TimeoutPersisters\TimeoutPersister.cs:line 30
   at NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver.Poll(Object obj) in C:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Timeout\Hosting\Windows\TimeoutPersisterReceiver.cs:line 90
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:2,State:0,Class:20
2015-11-25 14:33:05.038 +10:00 [Debug] Stopping a receive task for '"WorkerQueue"'. Total count current/max 0/1
2015-11-25 14:33:05.039 +10:00 [Debug] Starting a new receive task for '"WorkerQueue"'. Total count current/max 1/1
2015-11-25 14:33:05.040 +10:00 [Warning] An exception occurred when connecting to the configured SQLServer instance
System.Data.SqlClient.SqlException (0x80131904): A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server) ---> System.ComponentModel.Win32Exception (0x80004005): The system cannot find the file specified
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at NServiceBus.Transports.SQLServer.ConnectionFactory.<>c.<Default>b__3_0(String cs)
   at NServiceBus.Transports.SQLServer.ConnectionFactory.OpenNewConnection(String connectionString)
   at NServiceBus.Transports.SQLServer.NativeTransactionReceiveStrategy.TryReceiveFrom(TableBasedQueue queue)
   at NServiceBus.Transports.SQLServer.AdaptivePollingReceiver.Try(Boolean& success)
   at NServiceBus.Transports.SQLServer.AdaptiveExecutor`1.ReceiveLoop(Object obj)
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:2,State:0,Class:20

And then later I started it again 

2015-11-25 14:43:45.323 +10:00 [Debug] Polling for timeouts at 11/25/2015 14:43:45.
2015-11-25 14:43:50.294 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:43:50.295 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:43:50.304 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:43:50.306 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:43:50.309 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:43:50.310 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:43:56.479 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.Timeouts"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:43:56.479 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.Retries"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:43:56.479 +10:00 [Debug] Ignoring start task request for '"WorkerQueue.TimeoutsDispatcher"' because of maximum concurrency limit of 1 has been reached.
2015-11-25 14:43:59.870 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now disarmed
2015-11-25 14:43:59.871 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now disarmed
2015-11-25 14:43:59.873 +10:00 [Information] The circuit breaker for "SqlTransportConnectivity" is now disarmed
2015-11-25 14:43:59.878 +10:00 [Debug] Polling next retrieval is at 11/25/2015 14:32:32.
2015-11-25 14:43:59.878 +10:00 [Information] The circuit breaker for "TimeoutStorageConnectivity" is now disarmed
2015-11-25 14:43:59.879 +10:00 [Debug] Polling for timeouts at 11/25/2015 14:43:59.
2015-11-25 14:43:59.883 +10:00 [Debug] Polling next retrieval is at 11/25/2015 14:44:59.
2015-11-25 14:44:03.428 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:44:03.429 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:44:03.431 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:44:03.431 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:44:03.682 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:44:03.683 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:44:06.989 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:44:06.990 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:44:06.989 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:44:06.992 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:44:07.242 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:44:07.243 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1
2015-11-25 14:44:10.549 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Timeouts"'. Total count current/max 0/1
2015-11-25 14:44:10.549 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.Retries"'. Total count current/max 0/1
2015-11-25 14:44:10.550 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Timeouts"'. Total count current/max 1/1
2015-11-25 14:44:10.551 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.Retries"'. Total count current/max 1/1
2015-11-25 14:44:10.802 +10:00 [Debug] Stopping a receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 0/1
2015-11-25 14:44:10.803 +10:00 [Debug] Starting a new receive task for '"WorkerQueue.TimeoutsDispatcher"'. Total count current/max 1/1

Using sql profile shows its only querying Retries, Timeouts and TimeoutsDispatcher

[Szymon Pobiega]

Hi Daniel

I tried to reproduce it but failed. After restarting the SQL server the receiver started working fine. I might have missed something important though. What happened between 2015-11-25 14:33:05.040 +10:00 and 2015-11-25 14:43:45.323 +10:00. Can you attach the full logs? It seems like the main receiver has been stopped/disposed but satellites were not.

Szymon

--

You received this message because you are subscribed to the Google Groups "Particular Software" group.

To unsubscribe from this group and stop receiving emails from it, send an email to particularsoftw...@googlegroups.com.

To post to this group, send email to particula...@googlegroups.com.
Visit this group at http://groups.google.com/group/particularsoftware.

To view this discussion on the web visit https://groups.google.com/d/msgid/particularsoftware/018b5604-9585-4157-97f5-b989bb26408c%40googlegroups.com.

[ramon...@particular.net]

Hi,

You mentioned that it can be due to a fail-over. Depending on the kind of fail-over it can result in your connection pool to contain 'dirty' connections. This results in that .net gets a dirty connection to a database that is already dropped by the server.

During a fail-over is it normal that an application tries to use a connection from the connection pool, fail and then need to retry.

You can solve this by:

* Not using connection pooling

* Specifying a lifetime by adding `Connection Lifetime` to your connection string

The second option basically ensures that connection lifetime is shorter than the fail-over duration window so that the connection pool will contain connections to the new server.

Let us know if this cut down on roll-over errors or that we might have to consider other issues.

Regards,

Ramon

...

[Daniel Powell]

@Syzmon Attached, The windows service also hosts a quartz.net job so you'll see that in the logs also

@Ramon I"ll take a look at that, although I can somewhat reproduce it on a local machine that is just a single instance without clustering, and it appears its able to query the other queues (retry, timeout) correctly.

[Daniel Powell]

I tried with connection pooling disabled and saw this

2015-11-26 09:12:57.969 +10:00 [Information] Initiating shutdown.

2015-11-26 09:12:57.989 +10:00 [Debug] Stopping all tasks.

2015-11-26 09:12:57.993 +10:00 [Debug] Ensuring IWantToRunWhenBusStartsAndStops.Start has been called.

2015-11-26 09:12:57.995 +10:00 [Debug] All IWantToRunWhenBusStartsAndStops.Start have completed now.

2015-11-26 09:12:57.997 +10:00 [Debug] Stopped "NServiceBus.Unicast.Subscriptions.MessageDrivenSubscriptions.StorageInitializer, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c".

2015-11-26 09:12:57.998 +10:00 [Debug] Stopped "NServiceBus.Features.FeatureActivator+Runner, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c".

2015-11-26 09:12:58.000 +10:00 [Debug] Stopping 1/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutMessageProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite

2015-11-26 09:12:58.001 +10:00 [Debug] Stopping all tasks.

2015-11-26 09:12:58.002 +10:00 [Information] Stopped 1/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutMessageProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite

2015-11-26 09:12:58.000 +10:00 [Debug] Stopping 2/3 "NServiceBus.Timeout.Hosting.Windows.TimeoutDispatcherProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite

2015-11-26 09:12:58.004 +10:00 [Debug] Stopping all tasks.

2015-11-26 09:12:58.000 +10:00 [Debug] Stopping 3/3 "NServiceBus.SecondLevelRetries.SecondLevelRetriesProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite

2015-11-26 09:12:58.006 +10:00 [Debug] Stopping all tasks.

2015-11-26 09:12:58.006 +10:00 [Information] Stopped 3/3 "NServiceBus.SecondLevelRetries.SecondLevelRetriesProcessor, NServiceBus.Core, Version=5.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c" satellite

2015-11-26 09:12:58.058 +10:00 [Warning] The circuit breaker for "SqlTransportConnectivity" will now be triggered

2015-11-26 09:12:58.061 +10:00 [Fatal] Repeated failures when communicating with SQL

Not sure if this is what was happening before, pretty sure I didnt see it in the logs, is there anyway I can get nservicebus to keep retrying instead of failling when the server is down

[simon.cropp]

The Sql transport already has some build in logic around connection failures

http://docs.particular.net/nservicebus/sqlserver/#circuit-breaker

So if the endpoint is shutting down it means these levels have already been exceeded.

Have you looked into why the sql connectivity is failing? 

[Daniel Powell]

Yeah we have, we had some environmental issues, although even with those solved, I wouldn't expect nservicebus to just give up given that the servers could come back online

[Andreas Ohlund]

We can't keep on retrying for ever since that would hide potential misconfigurations. 

I recommend that you set the timeout to some higher value that is more resonable for your environment:

http://docs.particular.net/nservicebus/sqlserver/#circuit-breaker-wait-time

Hope this makes sense!

Cheers,

Andreas

--

You received this message because you are subscribed to the Google Groups "Particular Software" group.
To unsubscribe from this group and stop receiving emails from it, send an email to particularsoftw...@googlegroups.com.
To post to this group, send email to particula...@googlegroups.com.
Visit this group at http://groups.google.com/group/particularsoftware.

To view this discussion on the web visit https://groups.google.com/d/msgid/particularsoftware/6b0aa5be-e8fe-4862-8158-3ddb97ca6ffb%40googlegroups.com.

[Szymon Pobiega]

Hi Daniel

I agree with Andreas' advice. That said, there is a bug in SQL Server transport that you uncovered. The bug causes the endpoint to go into a zombie mode after the endpoint shutdown procedure is initiated by a circuit breaker. The shutdown procedure deadlocks after stopping the main queue receiver. Here's the issue for that defect: https://github.com/Particular/NServiceBus.SqlServer/issues/104.

Thank you for a very detailed problem report!

Szymon

To view this discussion on the web visit https://groups.google.com/d/msgid/particularsoftware/CA%2BFW%2BejN9R_aD6X1Km1R39KcsUSVUjdvA3rRRqzUOUQ1Ga1-Eg%40mail.gmail.com.

[Szymon Pobiega]

Hi Daniel

One other thing I didn't mention is that the shutdown procedure will dispose the bus (unless you override the critical action) when you are self hosting the NServiceBus. Currently there is no feature that would allow NServiceBus to go into some kind of paused mode when it cannot connect to the transport. You could try building it yourself by tapping into that critical action (http://docs.particular.net/nservicebus/hosting/critical-errors). When a critical problem happens you can do the default thing (dispose off the bus instance) and start monitoring the SQL Server. When you detect that it is up again, you can start a new bus instance.

Hope it makes sense,

Szymon

[Szymon Pobiega]

Hi Daniel

We've just released SQL Server transport patch 2.1.5 which fixes the shutdown deadlock problem.

Cheers,

Szymon

[Daniel Powell]

I don't see it in the github repo?

You received this message because you are subscribed to a topic in the Google Groups "Particular Software" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/particularsoftware/cj8PjSoUJyY/unsubscribe.
To unsubscribe from this group and all its topics, send an email to particularsoftw...@googlegroups.com.

To post to this group, send email to particula...@googlegroups.com.
Visit this group at http://groups.google.com/group/particularsoftware.

To view this discussion on the web visit https://groups.google.com/d/msgid/particularsoftware/CAE87Yxpj5OxOW93czpLDGNYFqSjbT08fd94%2BmCM8-9P_PbrFxA%40mail.gmail.com.

[Szymon Pobiega]

Hi Daniel

It turns out I've put a wrong version number on that release. The correct one is 2.2.1. It is on github and nuget.

Szymon

To view this discussion on the web visit https://groups.google.com/d/msgid/particularsoftware/CAHA1e3apkHSvpj81rYFq48-WhRJUtKB_-Kgd38XK0XgvAhv-9Q%40mail.gmail.com.

[Daniel Powell]

Excellent, everything makes more sense now !!