Help get this topic noticed by sharing it on Twitter, Facebook, or email.

SF_Refresh and never ending / locking the sql server instance

We are having problems with DBAMP SF_Refresh, When we run this sometimes it appears to deadlock / not finish running or report an error, this in turn means that we require resetting sql server a few times everyday to clear the error down and allow other databases to run queries again, have you ever seen this behaviour before, and has anyone got any advice as to running this trouble free? Thanks
1 person has
this question
+1
Reply
  • 1. What version of DBAmp are you running ?
    2. How are you determining the locking behavior ? Are you using the Actvity Monitor or some other means? When you "View locks by process" for the sf_refresh process, are you seeing other locks besides those on the salesforce backup database ?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Hi Bill, thanks for the very quick reply

    What version of DBAmp are you running ? 2.13.4

    We have been using Activity Monitor and and some dba type scripts to check the locking behaviour, there have been other locks however the majority of the backlog seems to be DBA AMP related, and we havent encountered them on this production server until we started bring the SF data in on a regular basis,

    Thanks Again
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • 1. How often are you running the sf_refresh ? Do you also run sf_replicate on a schedule ?

    2. The only locks DBAmp uses are the following:
    - a table lock is used when sf_replicate runs
    - A BEGIN TRANSACTION / COMMIT is used when sf_refresh adds the changes to the local table.

    Neither of these should cause the level of disruption that you are seeing.

    Can you send me a screenshot of the locks held by the sf_refresh process that you are seeing ? Or perhaps a screenshot showing the "DBAmp backlog" of locks ?

    Thanks.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • HI Bill.

    Yes we run the sf_refresh on a 30 minute schedule and we run the replicate on a schedule that is invoked if we detect that there is a mismatch between local and cloud copies of the data, this happens approx 1 time a day.

    The next time that Sql Server comes to a halt (which may be sooner rather than later ;¬) ) i will send you a screenshot, out of interest are there any settings on sql server that are thought be best practice for running DBAMP on? Are there extra error reporting or trapping we can be doing in the meantime?

    Again appreciate your help here

    Regards

    Craig
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • 1. The database you are using for salesforce.com local data should have a Recovery Model of Simple ( not Full).
    2. If you like, you can send me screenshots of the DBAMp.DBAmp provider options (Server Objects, Linked Servers, Providers, right click DBAmp.DBAmp) and the linked server Server Options (right click on the SALESFORCE link server) to support att forceamp.com for review.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Thanks Bill,

    I will send these in 1 minute, thanks for this Craig
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • I’m confused
    Did you resolve this? I have the same problem. If I login to the local database with my account that is a SQL system administrator and interactively run SF_Replicate against any SF table the command completes successfully.
    If I run the same command from an SSIS package the command never completes, and it appears that there is a deadlock that never resolves between the RUNNABLE process that is running the SF_Refresh (command it is running is "Exec dbo.SF_Replicate 'SALESFORCE' , 'Account'", found using >DBCC INPUTBUFFER spid) and the SUSPENDED process that is being run by the SQL Server's service account (command it is running is "exec [sys].sp_bcp_dbcmptlevel [SalesForce_DEV] set fmtonly on select * from [Account_Previous] set fmtonly off")

    If I kill the suspended process then the SSIS package job fails with error "Executing the query "Exec dbo.SF_Replicate 'SALESFORCE' , 'Account'" failed with the following error: "--- Ending SF_Replicate. Operation FAILED. --- Starting SF_Replicate for Account 17:30:46: Drop Account_Previous if it exists. 17:30:46: Create Account_Previous with new structure. 17:30:49: Run the DBAmp.exe program. 17:30:49: DBAmp Bulk Operations. V2.13.6 (c) Copyright 2006-2011 forceAmp.com LLC 17:30:49: Replicating into Account_Previous , SESQL01 / SalesForce_DEV . 17:30:49: DBAmp is using the SQL Native Client. 17:30:49: Opening SQL Server rowset 17:31:02: Error: Failed to open SQL Rowset. Source: Microsoft SQL Server Native Client 10.0 Description: Unspecified error 17:31:02: Error: DBAmp.exe was unsuccessful. 17:31:02: Error: Command string is C:\"Program Files"\DBAmp\DBAmp.exe Export Account_Previous "SESQL01" "SalesForce_DEV" "SALESFORCE" --- Ending SF_Replicate. Operation FAILED.". Possible failure reasons: Problems with the query, "ResultSet" property not set correctly, parameters not set correctly, or connection not established correctly. "

    If I kill the RUNNABLE process then it hangs attempting a rollback until I kill the other process.

    FYI my database is running using Simple recovery model (i.e. no logging)
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Hi Steve,

    Let's setup a goto meeting so I can have a look.
    Can you email support at forceamp.com with some times today (including timezone) that would work ?

    Bill
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Are you sure that the id used to run the SSIS package can execute xp_cmdshell ?

    Trying logging into SQL Mngt Studio as that user and see if you can run a sf_replicate.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • This looks very close to the issue we are having, this was 3 years ago, but wondering if you ever came up with a cause?

    We have been having a problem where DBAmp just hangs, both SF_BulkOPS and SELECT FROM Linked Server. We have multiple jobs running at the same time, and once one hangs, the rest also fail until it gets cleared up.

    The WIERD thing is we have found a process that "seems" to fix the problem "sometimes"; after figuring out the processes running we will do a DBCC INPUTBUFFER(spid) against the ones hung and they will eventually finish processing and everything will clear up. It does appear they do complete the process they were running.

    We are running v2.18.4, and DB's are in Simple Mode
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Additional Info, the lastwaittype that we normally see when this is happening is "PREEMPTIVE_OS_LOGONUSER" for the SP's and "OLEDB" for the Linked Server
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Is sf_bulkops always one of the hung parties ?

    Also, are you sure about the wait type ? I cannot find that wait type in the SQL docs.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Had this happen again today, ended up killing SPID's and then had to actually kill the DBAmp.EXE process.

    Any other ideas to try?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Send me an email to support at forceamp.com with some tines today that would work for a call..
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • We would also like to set a configuration value in the registry to see if it impacts the issue. Please reach out via email with some times for a meeting.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Some improvements, we don't seem to be completely locked out and have to kill the processes most of the time now. But still having issues that when a large process (SF_BulkOps or SF_Replicate) is running, things will seem to hang until one of the jobs finish.
    A lot of the times we can be running multiple without issue, but occasionally we see the symptom of a hang, but if we wait long enough the process will finish, and everything else that is running will also continue once that one is done.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • "but if we wait long enough the process will finish,"

    Could you quantify the length of time the long running process takes to finish ?

    Also, what windows OS is the SQL Server running on ?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • I’m frustrated
    Windows 2013 Server, 2008R2

    So based on previous experience, we may have a process that normally takes 25 seconds to run, and will sometime be hung for several hours.

    We still continue to have the issue, it does appear that when this occurs, a LARGE SalesForce Table is involved (e.g. Lead), so in today's example, via SF_RefreshAll, it is currently processing Lead (BULK INSERT to Lead_Previous is running), all other SF_Refresh or Query using Linked Server (e.g. SELECT * FROM SALESFORCE...RecordType) is now waiting for that process to complete before it will move on.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • SF_RefreshAll is just a loop over all tables running sf_refresh for each table. Therefore it will always exhibit "serial' behavior.

    Are you saying that while that sf_refreshall is downloading the Lead table, ALL other linked server queries are stalled ?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • yes, that appears to be the problem, it holds all other transactions while it is running.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • FYI, our issues seemed to start when we FINALLY moved from a SQL2000 Server to SQL2008 R2 a few months ago, we virtually never had any issues when we were on SQL2000.

    Our installation is running a dedicated instance for DBAmp, but we are planning on using the replicated copy of the SalesForce data for new reporting and other processes beyond what we are currently doing in the next few weeks, so we are really concerned about what is happeing with existing processes hanging.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • As we have seen in the past, if we kill the DBAmp.exe process running, all queued one start processing.

    Is there any chance something is causing this on the SalesForce side?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • I just got off a call with another customer with the same issue.

    We have begun an extensive code review to try to identify this bug.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Hello Bill - just curious if this particular question was resolved, with v2.18.4?
    It sounds similar to the SF_Refresh issue we are currently working with you to resolve.

    I'm also curious to know the answer to the above question: "Is there any chance something is causing this on the SalesForce side?" I'm assuming the answer to this question is No, and that it's not possible for Salesforce to be delayed for hours responding to any type of request.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • The code that was added for this issue is what I described on the phone.

    We think there is a bug in that code that is contributing to your issue. Hence, we have a new version for you to test.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Hi Bill, we are having a similar issue. We have different jobs running every hour that call sf_refresh. We have the hanging on sf_refresh and not completing. This happened today and lasted several hours, and the refresh usually takes seconds to complete. Thanks for your help getting this resolved.

    Date,Source,Severity,Step ID,Server,Job Name,Step Name,Notifications,Message,Duration,Sql Severity,Sql Message ID,Operator Emailed,Operator Net sent,Operator Paged,Retries Attempted
    05/23/2016 18:15:00,DbAmp_Sf_Contact_SetMemberType,Cancelled,0,IP-0ABB2C53,DbAmp_Sf_Contact_SetMemberType,(Job outcome),,The job was stopped prior to completion by Shutdown Sequence 0. The Job was invoked by Schedule 125 (Every Hour). The last step to run was step 1 (Set SF Contact MemberType).,00:04:10,0,0,,,,0
    05/23/2016 18:15:00,DbAmp_Sf_Contact_SetMemberType,Cancelled,1,IP-0ABB2C53,DbAmp_Sf_Contact_SetMemberType,Set SF Contact MemberType,,Executed as user: IP-0ABB2C53\Administrator. The step was cancelled (stopped) as the result of a stop job request.,00:04:10,0,0,,,,0
    05/23/2016 18:15:00,DbAmp_Sf_Sync_ContactsContractsLookup,Cancelled,0,IP-0ABB2C53,DbAmp_Sf_Sync_ContactsContractsLookup,(Job outcome),,The job was stopped prior to completion by Shutdown Sequence 0. The Job was invoked by Schedule 122 (Every hour). The last step to run was step 1 (DbAmp_Sf_Sync_ContactsContractsLookup).,00:04:10,0,0,,,,0
    05/23/2016 18:15:00,DbAmp_Sf_Sync_ContactsContractsLookup,Cancelled,1,IP-0ABB2C53,DbAmp_Sf_Sync_ContactsContractsLookup,DbAmp_Sf_Sync_ContactsContractsLookup,,Executed as user: IP-0ABB2C53\Administrator. The step was cancelled (stopped) as the result of a stop job request.,00:04:10,0,0,,,,0
    05/23/2016 12:15:01,DbAmp_Sf_Contact_SetMemberType,Cancelled,0,IP-0ABB2C53,DbAmp_Sf_Contact_SetMemberType,(Job outcome),,The job was stopped prior to completion by User IP-0ABB2C53\Administrator. The Job was invoked by Schedule 125 (Every Hour). The last step to run was step 1 (Set SF Contact MemberType).,05:35:44,0,0,,,,0
    05/23/2016 12:15:01,DbAmp_Sf_Contact_SetMemberType,Cancelled,1,IP-0ABB2C53,DbAmp_Sf_Contact_SetMemberType,Set SF Contact MemberType,,Executed as user: IP-0ABB2C53\Administrator. The step was cancelled (stopped) as the result of a stop job request.,05:35:44,16,16389,,,,0
    05/23/2016 12:15:01,DbAmp_Sf_Sync_ContactsContractsLookup,Error,0,IP-0ABB2C53,DbAmp_Sf_Sync_ContactsContractsLookup,(Job outcome),,The job failed. The Job was invoked by Schedule 122 (Every hour). The last step to run was step 1 (DbAmp_Sf_Sync_ContactsContractsLookup).,05:34:43,0,0,,,,0
    05/23/2016 12:15:01,DbAmp_Sf_Sync_ContactsContractsLookup,Error,1,IP-0ABB2C53,DbAmp_Sf_Sync_ContactsContractsLookup,DbAmp_Sf_Sync_ContactsContractsLookup,,Executed as user: IP-0ABB2C53\Administrator. --- Starting SF_Refresh for ContactsContractsLookup__c V3.1.0 [SQLSTATE 01000] (Message 0) 12:15:01: Using Schema Error Action of yes [SQLSTATE 01000] (Message 0) 12:15:03: Using last run time of 2016-05-23 10:45:00 [SQLSTATE 01000] (Message 0) 12:15:09: Identified 19 updated/inserted rows. [SQLSTATE 01000] (Message 0) 12:15:10: Identified 0 deleted rows. [SQLSTATE 01000] (Message 0) 12:15:10: Adding updated/inserted rows into ContactsContractsLookup__c [SQLSTATE 01000] (Message 0) --- Ending SF_Refresh. Operation successful. [SQLSTATE 01000] (Message 0) Unspecified error occurred on SQL Server. Connection may have been terminated by the server. [SQLSTATE HY000] (Error 0) --- Starting SF_Refresh for Contact V3.1.0 [SQLSTATE 01000] (Message 0) 12:15:10: Using Schema Error Action of yes [SQLSTATE 01000] (Message 0) 12:15:11: Using last run time of 2016-05-23 11:40:00 [SQLSTATE 01000] (Message 0) 12:15:22: Identified 2 updated/inserted rows. [SQLSTATE 01000] (Message 0) 12:15:24: Identified 0 deleted rows. [SQLSTATE 01000] (Message 0) 12:15:24: Adding updated/inserted rows into Contact [SQLSTATE 01000] (Message 0) The statement has been terminated. [SQLSTATE 01000] (Message 3621). The step failed.,05:34:43,0,3621,,,,0
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Can you upgrade to the latest version of DBAmp? There are some fixes in that version that impact this issue. You can find the latest version on the ForceAmp website.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • We upgraded to version 3.2.9.0 and didn't see the issue for some time, however, it has now occurred again. 4 jobs are all showing as Executing for several hours and do not complete. When I try to view the db tables, I'm getting the error "Lock request timeout period exceeded". How can I identify the process that's causing the issue, and then the issue itself? Thanks.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • If you login to server itself and run the Task Manager, do you see any processes that have DBAmp.exe as a name ? If so, are those consuming CPU?

    Also, is it possible that there has been a schema change in the object and the refresh as turned into a long running replicate ?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • DbAmp.exe isn't showing any CPU being used. It's possible there was a schema change to an object, but the replication usually takes less than 1 hour and this has been in this state for more than six hours. I will need to restart the sql server and then I can check the DBAmp log table and can provide any information that might help us identify the source of this issue. Would copy of this log table data help to identify the issue?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Rather than restarting SQL, just kill that process. That will cancel the sf_replicate and fail the job. Then we can take a look at the job output and log output to determine what is going on.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Sorry, but the server got restarted before I could do this. Is there log data I can try to use now to determine the source of the issue?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Can you provide the job step log for the failed step ?
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • There were several jobs that were in the queue all showing as Executing. The only log I can find at this point is the Job Activity History log, and all I see in it for all the hanging jobs is:

    07/05/2016 13:30:00,DbAmp_Sf_Sync_ContactsContractsLookup,Cancelled,0,IP-0A93D046\BETA,DbAmp_Sf_Sync_ContactsContractsLookup,(Job outcome),,The job was stopped prior to completion by User IP-0A93D046. The Job was invoked by Schedule 4 (CollectorSchedule_Every_15min). The last step to run was step 1 (DbAmp_Sf_Sync_ContactsContractsLookup).,1.00:19:40,0,0,,,,0
    07/05/2016

    For the job step logging you mention, is advanced logging mentioned in the article below what you need? If so, I will have to enable this on all our DbAmp jobs.

    http://sqlmag.com/blog/semi-advanced-...
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Is this what we need to do to identify and resolve the issue? This issue is occurring on our production database and we need to resolve it as quickly as possible. If you could help us see this through to a final resolution, it would be much appreciated.
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated

  • Are you available for a goto meeting this morning ?

    Please send an email to support at forceamp.com with your availability,
  • (some HTML allowed)
    How does this make you feel?
    Add Image
    I'm

    e.g. indifferent, undecided, unconcerned happy, confident, thankful, excited kidding, amused, unsure, silly sad, anxious, confused, frustrated