Getting rid of : WCF-Custom" raised an error message. Details "System.Data.SqlClient.SqlException: Timeout expired

December 22, 2010 / Comments Off on Getting rid of : WCF-Custom" raised an error message. Details "System.Data.SqlClient.SqlException: Timeout expired

I had a nice setup in my BizTalk environment. I had 4 receive locations polling for data (in the same table) and it all boiled down to execute a stored procedure with different parameters. I used the WCF adapter with SQL bindings for that.
For some obscure reason, I would get timeouts in the eventlog. Below is a screenshot of the receive port setup I had. Only one is shown but I had four of them.

Some important things to notice:

  • PolledDataAvailablestatement, is not used cause Pollwhiledatatfound = false. But you still have to put stuff in there to make things work.
  • Execute a specific sproc, with the number of records you want to receive as a parameter.
  • UseAmbientTransaction, no, no,no, had too many problems in the past when using msdtc and receive locations (locks and stuff) so this is a NO.
  • ReceiveTimeout is set to 10 minutes. This is a bit long but i never touched that value, it’s the default.

To make things a little bit more clear, The stored procedure I used looks looked like this :

 CREATE PROCEDURE [dbo].[Get_TeVertalen_Berichten]
(
 @MaximumAantal INT = NULL
)
AS
BEGIN
 EXEC [dbo].[Get_Berichten_Internal]
  @MaximumAantalInternal = @MaximumAantal,
  @OudeBerichtStatus = ‘TeVertalen’,
  @NieuweBerichtStatus = ‘VertalenGestart’,
  @Richting  = ‘Ingaand’  
END

And here is the code of Get_Berichten_Internal:

CREATE PROCEDURE [dbo].[Get_Berichten_Internal]
(
 @MaximumAantalInternal INT = 15,
 @OudeBerichtStatus  VARCHAR(200),
 @NieuweBerichtStatus VARCHAR(200),
 @Richting    VARCHAR(20) 
)
AS
BEGIN
 BEGIN TRY
  — Declare variables
  DECLARE @AFFECTED_KEYS TABLE
  (
   BerichtID NUMERIC(18, 0)
  )
  DECLARE @AFFECTED_ROWS INT
   — Some sets needed
  SET NOCOUNT ON
  — Perform the update statement and capture all the keys
  UPDATE
   TOP (@MaximumAantalInternal) dbo.tb_Bericht
  SET  
   BerichtStatus = @NieuweBerichtStatus
  OUTPUT
   INSERTED.BerichtID
  INTO
   @AFFECTED_KEYS
  WHERE
   BerichtStatus = @OudeBerichtStatus
  AND
   ExternBerichtTypeID IS NOT NULL
  AND
   InternBerichtTypeID IS NOT NULL
  AND
   Richting = @Richting
  — DO STUFF WITH THE AFFECTED KEYS
  <– SNIP–>
 END TRY
END

Now everything looks good and in the query analyzer everything was working blazingly fast. But I started to see the following message in the eventlog every 10 minutes (hmm that’s the receive timeout).  And sometimes several (four to be exactly) of them within a very short period of time.

Event Type: Warning
Event Source: BizTalk Server 2006
Event Category: BizTalk Server 2006
Event ID: 5740
Date:  14-12-2010
Time:  10:47:07
User:  N/A
Computer: BA34T
Description:
The adapter “WCF-Custom” raised an error message. Details “System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
   at Microsoft.ServiceModel.Channels.Common.Design.AdapterAsyncResult.End()
   at Microsoft.ServiceModel.Channels.Common.Channels.AdapterInputChannel.EndTryReceive(IAsyncResult result, Message& message)
   at System.ServiceModel.Dispatcher.InputChannelBinder.EndTryReceive(IAsyncResult result, RequestContext& requestContext)
   at System.ServiceModel.Dispatcher.ErrorHandlingReceiver.EndTryReceive(IAsyncResult result, RequestContext& requestContext)”.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

And once this message started to appear, stuff went downhill from there on. I could see in the profiler that stored procedures were taking ages, and even simple updates of a single record would take thirty seconds or so. Lock-Time-outs and deadlocks were occuring on a very regular basis. Even though the receive locations werent receiving any data. So nothing was received and I still got may daily portion of errors/warnings/suspended stuff in BizTalk because of this.
So basically it looked like I was having some kind of locking problem even if no work was done by the second stored procedure. But the second procedure did an update (even when there was nothing to update) and maybe that triggered the nasty behaviour.

I started a discusiion on MSDN to see if anybody could help : <<See here>>

 But eventually i cghanged something to make this behaviour go away. The idea was only to perform the update when there was stuff to update. So i changed the first procedure to :

CREATE PROCEDURE [dbo].[Get_TeVertalen_Berichten]
(
   @MaximumAantal INT = NULL
)
AS
BEGIN
 SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
 DECLARE @Aantal int
 SELECT
  @Aantal=count(*)
 FROM
  dbo.tb_Bericht WITH (NOLOCK)
 WHERE
  BerichtStatus = ‘TeVertalen’
 AND
  ExternBerichtTypeID IS NOT NULL
 AND
  InternBerichtTypeID IS NOT NULL
 AND
  Richting = ‘Ingaand’
 IF @Aantal > 0
 BEGIN
  EXEC [dbo].[Get_Berichten_Internal]
    @MaximumAantalInternal = @MaximumAantal,
    @OudeBerichtStatus  = ‘TeVertalen’,
    @NieuweBerichtStatus = ‘VertalenGestart’,
    @Richting    = ‘Ingaand’  
 END 
END

 And by first checking if there was any work to do and only then do an update, I got rid of the deadlocks and the errors in the eventlog.
I really don’t know why this solved it, but my guess is there is some bug in the WCF adapters, that go wrong if you start a transaction but return no data.

Everything is running smooth now and I hope this post will help somebody experiencing the same problems.

  • Recent Posts
  • Recent Comments
  • Archives
  • Categories
  • Meta