Sync agent becomes offline and needs a restart

Question

Hello.

In beginning of February, I set up Data Sync between an on-premise server and an Azure Database.
After some time I noticed that syncing was not performed on schedule and in Azure Management Portal I could see in the Sync group that the on-premise agent was offline.
When I logged onto the server, I could not ping the Azure service, so I restarted Azure service and everything started working.
6 days later, the same thing happened again, and was resolved the same way. This time it worked for only 4 days before I had to repeat the procedure again.

Any help is appreciated.

Answer 1

have you checked the logs? check Event Viewer->Applications and Services Logs->Sql Azure Data Sync Preview

Answer 2

Hello, here is a summary:

On February 27th at 8.58, the service was restarted, after that synchronization was successful until March 1st, however during this time there were several errors reported

On February 27th at 9.38, the following error was posted:

id:CommandAndControlClient_RequestProcessError, rId:, sId:00000000-0000-0000-0000-000000000000, agentId:c3e1c6bf-9325-4c83-9018-07390c5ed4a3, agentInstanceId:89b286d8-d72d-49dc-8583-9fe61cd49ef6, taskId:00000000-0000-0000-0000-000000000000, e:'Type=Microsoft.SqlAzureDataSync.ClientServerCommon.Exceptions.DssRetryException,Message=Retrying the Action after 1000ms. This was Attempt: 0 of 3. ,Source=,StackTrace=,'
'Type=System.ServiceModel.Security.MessageSecurityException,Message=An unsecured or incorrectly secured fault was received from the other party. See the inner FaultException for the fault code and detail.,Source=mscorlib,StackTrace=
Server stack trace: 
   at System.ServiceModel.Channels.SecurityChannelFactory`1.SecurityRequestChannel.ProcessReply(Message reply, SecurityProtocolCorrelationState correlationState, TimeSpan timeout)
   at System.ServiceModel.Channels.SecurityChannelFactory`1.SecurityRequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)


Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ICommandAndControlServiceApi.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.<>c__DisplayClass4.<GetRequest>b__3()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ClientProxyBase`1.ExecuteRequest(Action serviceCall)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass8.<Dispatcher>b__4(CommandAndControlProxy ccProxy)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass20.<ProxyActionWithRetry>b__1c()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.CommonHelperMethods.ExecuteWithRetry(Action method, ITransientErrorDetectionStrategy errorDetection, Int32 totalExecTimes, Int32 sleepTimeInMs, Action`1 logException),'
'Type=System.ServiceModel.FaultException,Message=Invalid agent Id or key. Access denied.,Source=,StackTrace=,', eType:'Type=Microsoft.SqlAzureDataSync.ClientServerCommon.Exceptions.DssRetryException', eMessage:'Message=Retrying the Action after 1000ms. This was Attempt: 0 of 3. ', eTypeInner:'Type=System.ServiceModel.Security.MessageSecurityException', eMessageInner:'Message=An unsecured or incorrectly secured fault was received from the other party. See the inner FaultException for the fault code and detail.'

The exactly same error occured two more times that day. Then on February 28th at 10.58, a new one came:

id:ClientRequestHandler_ExceptionProcessingRequest, rId:, sId:dcb77532-cb3d-445c-b62a-508109de6dd3, taskId:df01ae07-dc95-4207-8089-3d2fbd76d374, e:'Type=System.Data.SqlClient.SqlException,Message=Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.,Source=.Net SqlClient Data Provider,StackTrace=   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)

   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning()
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)
   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
   at Microsoft.Synchronization.Data.SqlServer.SqlSyncStoreMetadataCleanup.PerformCleanup(Int64& rowsCleaned)
   at Microsoft.SqlAzureDataSync.SyncControllerLib.SyncController.CleanupTombstones(CleanupTombstoneParameters cleanupTombstoneParams, Int64& rowsDeleted)
   at Microsoft.SqlAzureDataSync.AgentHostLib.ClientRequestHandler.CleanupTombstones(CleanupTombstoneRequest request),', eType:'Type=System.Data.SqlClient.SqlException', eMessage:'Message=Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.' Error Code: -2146232060 - SqlError Number:-2, Message: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.. , eTypeInner:, eMessageInner:

After that, "Problem 1" was reported 3 more times and "Problem 2 " one more time before a third issue took place on February 29th 17.36:

id:CommandAndControlClient_RequestProcessError, rId:, sId:00000000-0000-0000-0000-000000000000, agentId:c3e1c6bf-9325-4c83-9018-07390c5ed4a3, agentInstanceId:89b286d8-d72d-49dc-8583-9fe61cd49ef6, taskId:00000000-0000-0000-0000-000000000000, e:'Type=System.ServiceModel.FaultException`1[[Microsoft.SqlAzureDataSync.ClientServerCommon.DssFaultException, Microsoft.SqlAzureDataSync.ClientServerCommon, Version=2.0.0.0, Culture=neutral, PublicKeyToken=89845dcd8080cc91]],Message=An error occurred while executing the command definition. See the inner exception for details.

Inner exception: SqlException Error Code: -2146232060 - SqlError Number:50000, Message: Error 1205, Level 13, State 52, Procedure GetNextTask, Line 15, Message: Transaction (Process ID 433) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction. 
,Source=mscorlib,StackTrace=
Server stack trace: 
   at System.ServiceModel.Channels.ServiceChannel.HandleReply(ProxyOperationRuntime operation, ProxyRpc& rpc)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)


Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ICommandAndControlServiceApi.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.<>c__DisplayClass4.<GetRequest>b__3()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ClientProxyBase`1.ExecuteRequest(Action serviceCall)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass8.<Dispatcher>b__4(CommandAndControlProxy ccProxy)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass20.<ProxyActionWithRetry>b__1c()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.CommonHelperMethods.ExecuteWithRetry(Action method, ITransientErrorDetectionStrategy errorDetection, Int32 totalExecTimes, Int32 sleepTimeInMs, Action`1 logException)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.ProxyActionWithRetry(Action`1 proxyAction, CommandAndControlProxy proxy, Action`1 logger),', eType:'Type=System.ServiceModel.FaultException`1[[Microsoft.SqlAzureDataSync.ClientServerCommon.DssFaultException, Microsoft.SqlAzureDataSync.ClientServerCommon, Version=2.0.0.0, Culture=neutral, PublicKeyToken=89845dcd8080cc91]]', eMessage:'Message=An error occurred while executing the command definition. See the inner exception for details.
Inner exception: SqlException Error Code: -2146232060 - SqlError Number:50000, Message: Error 1205, Level 13, State 52, Procedure GetNextTask, Line 15, Message: Transaction (Process ID 433) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction. 
', eTypeInner:, eMessageInner:

After that there are 12 occurances of "Problem 3" the next 10 hours.

Then a fourth error occured:

id:CommandAndControlClient_RequestProcessError, rId:, sId:00000000-0000-0000-0000-000000000000, agentId:c3e1c6bf-9325-4c83-9018-07390c5ed4a3, agentInstanceId:89b286d8-d72d-49dc-8583-9fe61cd49ef6, taskId:00000000-0000-0000-0000-000000000000, e:'Type=System.ServiceModel.FaultException`1[[Microsoft.SqlAzureDataSync.ClientServerCommon.DssFaultException, Microsoft.SqlAzureDataSync.ClientServerCommon, Version=2.0.0.0, Culture=neutral, PublicKeyToken=89845dcd8080cc91]],Message=An error occurred while executing the command definition. See the inner exception for details.

Inner exception: SqlException Error Code: -2146232060 - SqlError Number:-2, Message: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. 
,Source=mscorlib,StackTrace=
Server stack trace: 
   at System.ServiceModel.Channels.ServiceChannel.HandleReply(ProxyOperationRuntime operation, ProxyRpc& rpc)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)


Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ICommandAndControlServiceApi.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.<>c__DisplayClass4.<GetRequest>b__3()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ClientProxyBase`1.ExecuteRequest(Action serviceCall)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass8.<Dispatcher>b__4(CommandAndControlProxy ccProxy)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass20.<ProxyActionWithRetry>b__1c()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.CommonHelperMethods.ExecuteWithRetry(Action method, ITransientErrorDetectionStrategy errorDetection, Int32 totalExecTimes, Int32 sleepTimeInMs, Action`1 logException)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.ProxyActionWithRetry(Action`1 proxyAction, CommandAndControlProxy proxy, Action`1 logger),', eType:'Type=System.ServiceModel.FaultException`1[[Microsoft.SqlAzureDataSync.ClientServerCommon.DssFaultException, Microsoft.SqlAzureDataSync.ClientServerCommon, Version=2.0.0.0, Culture=neutral, PublicKeyToken=89845dcd8080cc91]]', eMessage:'Message=An error occurred while executing the command definition. See the inner exception for details.
Inner exception: SqlException Error Code: -2146232060 - SqlError Number:-2, Message: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. 
', eTypeInner:, eMessageInner:

After that there is one "Problem 2" and two "Problem 3" and then no more messages at all. At the same time synchronization was stopped.

Answer 3

do you still get the error up until now?

Note that there were issues with Data Sync on Feb 29 but that should have been resolved already

what's your sync interval?

Answer 4

Hi, sync interval is 4 hours.

Today syncing once again stopped, but this time with an error message in the Azure Management-log:

Sync failed with the exception "GetStatus failed with exception:

Sync worker failed, checked by GetStatus method. Failure details:
An unexpected error occurred when applying batch file C:\Resources\directory\ceda43982be34e059edcb35ef8fad8df.NTierSyncServiceWorkerRole.LS1\DSS_syncjobu4sjpyvfoxwnl5f0udtjrov2\bcd11a17-e83c-482f-a507-a0b37aacc0c3.batch. See the inner exception for more details.
Inner exception: End of Stream encountered before parsing was completed."
For more information, provide tracing id ‘db91315a-e351-4e19-b743-f6b784600aed’ to customer support.

Answer 5

this new error you got is different from the previous ones. this actually shows that it is trying to sync and an error was encountered reading batch files.

Answer 6

Ok, so perhaps I should start a new thread with this other issue instead?

I have no idea on how to resolve problems with reading of batch files.

Best regards, 

Joel

Answer 7

afaik, there is not much you can do about the batching...

but since you posted the tracing id, the product team might have an idea what the error is all about.

Answer 8

hello, I have an update on this one.

After the error message on monday, the sync actually went back to normal again and was syncing correctly until wednesday when syncing stopped again.

I haven't gotten hold of the eventlog yet, but I will post it here as soon as I get it. Do you want me to post it her like last time or should I send it to someone?

 - Joel

Answer 9

you might want to post it here just in case a member of the product team goes thru the open forum questions.

Answer 10

Hello, below are the logs from the latest "sprint".

Note that I can also email the eventlog if that could help you.

Sync service was restarted on March 9th, and was working until March 14th.

I will use the same numbering of the problems as last time.

2012-03-09:
2x "Problem 2"

2012-03-10:
1x "Problem 2"

2012-03-11:
"Problem 2"
Then the following 8 errors occured within 1 minute:
"Problem 1" (0 of 3)
"Problem 1" (1 of 3)
"Problem 1" (0 of 3)
"Problem 1" (0 of 3)
"Problem 1" (1 of 3)
"Problem 1" (1 of 3)
"Problem 5" (description in the end)
"Problem 1" (0 of 3)
10 minutes break
"Problem 4"
"Problem 4"
Then 8 hours break, and the following 8 rows within 5 seconds:
"Problem 1" (0 of 3)
"Problem 1" (1 of 3)
"Problem 1" (0 of 3)
"Problem 1" (0 of 3)
"Problem 1" (1 of 3)
"Problem 1" (1 of 3)
"Problem 1" (0 of 3)
"Problem 1" (0 of 3)
Two hours break
"Problem 2"
6 hours break
"Problem 2"

2012-03-12:
"Problem 2"
"GetStatus failed" as described in earlier post (error occurred when applying batch file C:\Resources\directory\ceda43982be34e059edcb35ef8fad8df.NTierSyncServiceWorkerRole.LS1\DSS_syncjobu4sjpyvfoxwnl5f0udtjrov2\bcd11a17-e83c-482f-a507-a0b37aacc0c3.batch.)
3x "Problem 2"


2012-03-13:
3x "Problem 2"
2x "Problem 3"
1x "Problem 2"

2012-03-14:
"Problem 2"
"Problem 1" (0 of 3)

After this there were no more syncs.

Description of "Problem 5":

id:CommandAndControlClient_RequestProcessError, rId:, sId:00000000-0000-0000-0000-000000000000, agentId:c3e1c6bf-9325-4c83-9018-07390c5ed4a3, agentInstanceId:821a7a3b-0f9c-4a71-8464-e89a3d5a2c97, taskId:00000000-0000-0000-0000-000000000000, e:'Type=System.ServiceModel.Security.MessageSecurityException,Message=An unsecured or incorrectly secured fault was received from the other party. See the inner FaultException for the fault code and detail.,Source=mscorlib,StackTrace=
Server stack trace: 
   at System.ServiceModel.Channels.SecurityChannelFactory`1.SecurityRequestChannel.ProcessReply(Message reply, SecurityProtocolCorrelationState correlationState, TimeSpan timeout)
   at System.ServiceModel.Channels.SecurityChannelFactory`1.SecurityRequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)


Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ICommandAndControlServiceApi.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.<>c__DisplayClass4.<GetRequest>b__3()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.ClientProxyBase`1.ExecuteRequest(Action serviceCall)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlProxy.GetRequest(Guid instanceId, Guid& requestId, String& request)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass8.<Dispatcher>b__4(CommandAndControlProxy ccProxy)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.<>c__DisplayClass20.<ProxyActionWithRetry>b__1d()
   at Microsoft.SqlAzureDataSync.ClientServerCommon.CommonHelperMethods.ExecuteWithRetry(Action method, ITransientErrorDetectionStrategy errorDetection, Int32 totalExecTimes, Int32 sleepTimeInMs, Action`1 logException)
   at Microsoft.SqlAzureDataSync.AgentHostLib.CommandAndControlClient.ProxyActionWithRetry(Action`1 proxyAction, CommandAndControlProxy proxy, Action`1 logger),'
'Type=System.ServiceModel.FaultException,Message=An error occurred when verifying security for the message.,Source=,StackTrace=,', eType:'Type=System.ServiceModel.Security.MessageSecurityException', eMessage:'Message=An unsecured or incorrectly secured fault was received from the other party. See the inner FaultException for the fault code and detail.', eTypeInner:'Type=System.ServiceModel.FaultException', eMessageInner:'Message=An error occurred when verifying security for the message.'

Answer 11

Hello, are there any updates on this issue?

This time syncing was working from March 19 to March 27th, but then we needed a restart to make it sync again.

Should I post the eventlog-entries once again, or is there something else I can do to help you find the root cause of this problem?

Best regards, 

Joel

Answer 12

Hey Joel,

Does your sync group have the errors still? Can you enable the verbose log for DSS local agent? you can open file "LocalAgentHost.exe.config" from folder "Program Files (x86)\Microsoft SQL Azure Data Sync\bin" to enable the verbose logging. are you meaning every time the sync will work after you restart the DSS local agent service?

---

Oliver Yao - MSFT

Answer 13

Hello Oliver. Yes the problem still remains.

On April 3rd, we upgraded the Sync Agent to the latest one and restarted the sync service again, and syncing was working until April 6th.

Today (April 18th), we turned on verbose logging and restarted the service again, so most likely sync will fail by the start of next week, and then I can send the log-files somewhere?

Answer 14

Hey Joel, If the file is ready when the error is shown up again, you can put somewhere and i can download for taking a look.

---

Oliver Yao - MSFT

Answer 15

Hello, ok I finally got hold of the log file and you can download it from here.

This time, syncing was working successfully from April 18th to April 22nd.

Thanks for your help, 

Joel

Answer 16

Hey Joel,

I got the file already. you can remove it from the place. I will look at it to see whether any findings there.

thanks,

-oliver

---

Oliver Yao - MSFT

Answer 17

The errorlog file shows the error message that "https://api-su2am1.sync.azure.com/CommandAndControl.svc" cannot be resolved.

In that machine which the problem still exists, if you open the browser and input above link, is it successful?

From the error message, it looks mostly related to your network side.

---

Oliver Yao - MSFT

Answer 18

Thank you for your response, I will make sure our technicians check this first thing on Monday.

 - Joel

Answer 19

Hi, sorry this took longer time than expected. I just got reply from technicians that they can reach the URL from IE.

Answer 20

Hi, any news on this issue? We still have to manually restart the agent service every week...

If there may be internal network issues, it would be great to get some more details abut that so I can inform our network technicians.

Br, 

Joel

Answer 21

Hi Joel,

have you updated your agents to the latest release ?

cheers,

junet

Answer 22

Hi, 

Yes on June 13th we upgraded to the latest version and restarted the service. 

After that it continued working until June 20th before we had to restart the service again.

Br, 

Joel

Answer 23

I have once again turned on the logging feature, since I thought it could be interesting to look through it now that we have upgraded to the latest version. The new log file can be found here.

It would be great if we can resolve this issue so we don't have to restart the service every week...

 - Joel