I am running Image Server 2.0 and have a few studies (about 100) that status is Online - Delete Scheduled but no items in the work queue. The studies are locked and cannot edit or delete study in the study details page. 

In the Application log I found a few errors associated with the delete function (below). I have restarted the shredhost service already to see if that would kick off any work queue entries or unlock the studies but that didn't work.  Any Ideas?  

 

 

2011-12-23 08:54:28,230 [WorkQueue Pool:23] ERROR - Exception thrown

 

Unexpected exception when processing WorkQueue item of type Delete Study.  Failing Queue item. (GUID: a6c2cd65-e5b7-4ec3-b3aa-e07b8e4b1f82)

ClearCanvas.Enterprise.Core.PersistenceException: Unexpected error with stored procedure: DeleteStudyStorage ---> System.Data.SqlClient.SqlException: Transaction (Process ID 108) was deadlocked on lock | communication buffer resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)

   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)

   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 ClearCanvas.ImageServer.Enterprise.SqlServer2005.ProcedureUpdateBroker`1.Execute(TInput criteria)

   --- End of inner exception stack trace ---

   at ClearCanvas.ImageServer.Enterprise.SqlServer2005.ProcedureUpdateBroker`1.Execute(TInput criteria)

   at ClearCanvas.ImageServer.Services.WorkQueue.DeleteStudy.DeleteStudyItemProcessor.RemoveDatabase(WorkQueue item)

   at ClearCanvas.ImageServer.Services.WorkQueue.DeleteStudy.DeleteStudyItemProcessor.ProcessItem(WorkQueue item)

   at ClearCanvas.ImageServer.Services.WorkQueue.BaseItemProcessor.Process(WorkQueue item)

   at ClearCanvas.ImageServer.Services.WorkQueue.WorkQueueProcessor.ExecuteProcessor(IWorkQueueItemProcessor processor, WorkQueue queueItem)

2011-12-23 08:54:28,230 [WorkQueue Pool:23] ERROR - Resetting Delete Study WorkQueue entry (a6c2cd65-e5b7-4ec3-b3aa-e07b8e4b1f82) to Pending, current retry count 1. Failure Reason: Transaction (Process ID 108) was deadlocked on lock | communication buffer resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

 

I thought that it may of been some issues with the DB Server and a momentarily network issue but we got the deadlocked errors again and the studies were not recovered. So now we have additional 20 or 30 studies that can not be deleted, opened or reprocessed. All logs on the two servers did not suggest anything unusual.

I'm a bit surprised by this and have a few questions. Are you doing anything to the studies when they're attempted to be deleted? Ie, are they being retrieved or something else? Also, do you think your database server is underpowered? Do you have a very heavy load on the ImageServer?

The actual deadlock would be caused by the delete transaction executing slowly (and the problem would be caused by transactions executing too slow), or if some other processing is being attempted on the study at the same time it is being deleted. The more likely cause is that the deadlock is caused by a slow database, or even a backup or reindex happening when the transaction is executing. Any other information on the status of the system would be helpful.

Steve

Nothing should be happening to the studies when they're attempted to be deleted. (A slim chance of it being retrieved / sending a duplicate exists). I don't think that our sql instance is under powered (20 GB of memory on this instance) and had our systems engineer double check the server to be sure it is not being over taxed.As far as load, we have just under 1/2 million studies currently in the system (US, DR, and InterOral) and recieve about 300 to 400 studies a day (The bulk being in an overnight process). We do have over 1600 devices that are able to communicate with imageserver (600+ CC Workstations configured to allow download (disabled streaming) and the rest a mix of US/DR/IO). The only other changes that may of happened in the first instance was adjusting the watermarks on the disc space. (currently have 11 file systems each 1TB each).

We have tried to run the purge during off times as well but the system comes back with a high percentage of the deadlock issues.

ImageServer deletes the study from the file system but seems to be stuck when deleting the row from the Database. The only button available on the study details screen is reprocess in which displays an error and reports that the study is in nearline status.

Similar issue here!

One day, for some reason, the NAS configured as Tier 2 FS could not be reached by IS (though was visible and very accessible in windows explorer).

I got Tier 1 FS full and about 4000 failed tier migration entries on the work queue. Some study were probably deleted.

As many might have experienced, it is quite a painful task deleting workqueue items 1 by one, so, in my wisdom, I deleted the entries 200 at a time using SQL management studio directly from the database table.

I then reapplied rules on Tier1 FS.

Now I have very many studies stuck in "Migration Scheduled" state. No workqueue entries!

Have restarted server severally, no change.

Log:


2012-01-04 02:57:23,526 [ServiceLock Pool:20] INFO - Starting Tier Migration from Primary Filesystem
2012-01-04 02:57:23,542 [ServiceLock Pool:20] INFO - 29944.0 MBs needs to be removed from 'Primary Filesystem'. Found 0 studies that can be migrated in 0.0016371 seconds
2012-01-04 02:57:23,542 [ServiceLock Pool:20] INFO - 0 studies have been scheduled for migration from filesystem 'Primary Filesystem'
2012-01-04 02:57:23,557 [ServiceLock Pool:20] INFO - Starting query for Filesystem delete candidates on 'Primary Filesystem'.
2012-01-04 02:57:23,573 [ServiceLock Pool:20] INFO - 0 studies have been scheduled for removal from filesystem 'Primary Filesystem'
2012-01-04 02:57:23,573 [ServiceLock Pool:20] INFO - Starting query for Filesystem Purge candidates on 'Primary Filesystem'.
2012-01-04 02:57:23,573 [ServiceLock Pool:20] INFO - 0 studies have been scheduled for purging from filesystem 'Primary Filesystem'
2012-01-04 02:57:23,589 [ServiceLock Pool:20] WARN - Fileystem 'Primary Filesystem' is above high watermark but no studies can be deleted, migrated or purged at this point
2012-01-04 02:59:23,662 [ServiceLock Pool:21] INFO - Filesystem below watermarks: NAS (Current: 8.660921, High Watermark: 98.0000
2012-01-04 03:01:23,675 [ServiceLock Pool:20] INFO - Filesystem above high watermark: Primary Filesystem (Current: 75.69578, High Watermark: 75.0000
2012-01-04 03:01:23,675 [ServiceLock Pool:21] INFO - Filesystem below watermarks: NAS (Current: 8.660921, High Watermark: 98.0000
2012-01-04 03:01:23,675 [ServiceLock Pool:20] INFO - Starting Tier Migration from Primary Filesystem
2012-01-04 03:01:23,675 [ServiceLock Pool:20] INFO - 29944.0 MBs needs to be removed from 'Primary Filesystem'. Found 0 studies that can be migrated in 0.0016029 seconds
2012-01-04 03:01:23,691 [ServiceLock Pool:20] INFO - 0 studies have been scheduled for migration from filesystem 'Primary Filesystem'
2012-01-04 03:01:23,707 [ServiceLock Pool:20] INFO - Starting query for Filesystem delete candidates on 'Primary Filesystem'.
2012-01-04 03:01:23,722 [ServiceLock Pool:20] INFO - 0 studies have been scheduled for removal from filesystem 'Primary Filesystem'
2012-01-04 03:01:23,722 [ServiceLock Pool:20] INFO - Starting query for Filesystem Purge candidates on 'Primary Filesystem'.
2012-01-04 03:01:23,738 [ServiceLock Pool:20] INFO - 0 studies have been scheduled for purging from filesystem 'Primary Filesystem'
2012-01-04 03:01:23,753 [ServiceLock Pool:20] WARN - Fileystem 'Primary Filesystem' is above high watermark but no studies can be deleted, migrated or purged at this point
2012-01-04 03:03:23,810 [ServiceLock Pool:21] INFO - Filesystem below watermarks: NAS (Current: 8.660921, High Watermark: 98.0000

 jcschott,

Mukoya,

Manually deleting work queue entries is not advised. You basically screw up the status of the system. For instance, the FilesystemQueue table has entries that tell when studies are eligible for migration. When the WorkQueue entry is inserted to migrate a study, the row that triggered the migration is removed from the FilesystemQueue. When migration is completed, a new row is inserted into the FilesystemQueue for when the study is eligible to migrate again. Also, when we insert into the Workqueue, we also update the status of the studies in the StudyStorage table to prevent issues with more than one WorkQueue entry working on the study at the same time.

So, you basically have some inconsistencies in the database that are difficult to recover from. In the future, I'd suggest doing a DB update to reset all the entries back to pending and try and get them to reprocess, instead of just removing them. The actual delete process from the GUI does try and clean up the studies as appropriate when you delete the entries one by one.

Steve

Thanks Steve,

That bug you included does look almost identical to our symptoms. I will have our DBA's set up some monitoring on the ImageServer DB and see whats processes are causing this as well as still looking at our architecture with our system engineer to try to see if it is any environment issues and we will go from there.

Thank you steve.

I now get the picture! I tried resetting studies to pending from the Web GUI but was painful task as it needed selection and confirmation of reset one by one. Dint think of resetting to pending from DB.

With that info, I will try to see if this can be resolved or just live with it never to repeat it again!.

Regards.

One issue Steve:

What if I reprocess all the studies? Unfortunately, it is even more difficult to do that in the web UI that resetting failed items to pending.

If reprocess has potential to rectify the issue to an extend, is there an easier way to do mass reprocessing? I think they are about 3000 studies.

Thanks.

Mukoya again. . .!

For mass reprocessing, what if I do FS re-inventory (I am aware of the time/resources it might take) or copy all the affected files to partition incoming folder?

There isn't really a good solution for you.  You could try reapplying the rules through service scheduling.  This would I think cleanup the FilesystemQueue.  The second step would be to ensure the Studystatus and lock entries int he StudyStorage table are correct.  The two of these may help resolve the problem.

Steve

I ended up reprocessing all the studies:

Search for affected studies (were within a time frame of about a month),

Select all studies on page (Is there a way to increase number of studies displayed per page? In future a select all feature would be great),

Click view details (wish there was a reprocess functionality on this page).

Details of each study are opened in new tab,

Click reprocess study>yes>close and repeat for all studies.

Open new page and repeat.

Long process but it cleaned up the mess.

Thanks.

Just to add, reapply rules reported that these studies were locked and thus could not be processed.

Steve,

Just an update we were able to further optimize the DB where we were seeing the deadlock issues. We added an index to the table dbo.StudyHistory on column [DestStudyStorageGUID].

We were able to adjust our watermarks appropriately and it deleted over 9,000 studies over the course of the day with only one deadlock error.

Excellent, that is good news! You must have a fair amount of reconciles and edits on your system? The StudyHistory table is only used on studies that have edits or reconciles that happen on it. I'd assume that table would have to be fairly large to cause problems. In any case, we'll look into adding that index in a future release of the software.

Steve

 Hi Steve,

Do you have any response for Mukoya's question?

" Is there a way to increase number of studies displayed per page? "

Thanks,

Adrian

 

Yes, the number of results displayed per page can be changed, search for PageSize in the web.config file. You may have to restart IIS after the change or reboot to get the change to take effect.

Steve

 Hello Steve

Of course It works!

Really useful.

Thanks

Adrian

 Dear ImageServer community,

I am having a problem that is stucked in "Web delete scheduled" state.

I have just pressed the delete button and it has been in that state from that moment.

In the application log I see this:

-----------------------------------------------------------------------

Exception thrown

Unexpected exception when processing WorkQueue item of type Web Delete Study. Failing Queue item. (GUID: fdc91c45-3d9f-471c-8948-733d4a14f3d9)

ClearCanvas.Enterprise.Core.PersistenceException: Unexpected error with stored procedure: DeleteStudyStorage ---> System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)

at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)

at System.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)

at System.Data.SqlClient.TdsParserStateObject.ReadSni(DbAsyncResult asyncResult, TdsParserStateObject stateObj)

at System.Data.SqlClient.TdsParserStateObject.ReadNetworkPacket()

at System.Data.SqlClient.TdsParserStateObject.ReadBuffer()

at System.Data.SqlClient.TdsParserStateObject.ReadByte()

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 ClearCanvas.ImageServer.Enterprise.SqlServer2005.ProcedureUpdateBroker`1.Execute(TInput criteria)

--- End of inner exception stack trace ---

at ClearCanvas.ImageServer.Enterprise.SqlServer2005.ProcedureUpdateBroker`1.Execute(TInput criteria)

at ClearCanvas.ImageServer.Ser

--------------------------------------------------

 

If I press the Reprocess study button I get:

--------------------------------------------------

Message: Index was out of range. Must be non-negative and less than the size of the collection.
Parameter name: index

Extra Info: An unspecified error occurred.

Source:mscorlib

Stack Trace:   at System.ThrowHelper.ThrowArgumentOutOfRangeException()
   at System.Collections.Generic.List`1.get_Item(Int32 index)
   at ClearCanvas.ImageServer.Web.Common.Data.StudyController.ReprocessStudy(String reason, ServerEntityKey key)
   at ClearCanvas.ImageServer.Web.Application.Pages.Studies.StudyDetails.Default.ReprocessStudy()

   at ClearCanvas.ImageServer.Web.Application.Controls.MessageBox.OKButton_Click(Object sender, EventArgs e)

   at System.Web.UI.WebControls.ImageButton.OnClick(ImageClickEventArgs e)

   at System.Web.UI.WebControls.ImageButton.RaisePostBackEvent(String eventArgument)

   at System.Web.UI.Page.RaisePostBackEvent(IPostBackEventHandler sourceControl, String eventArgument)

   at System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)

-----------------------------------------

Please, help me with this issue. This is a production server.

Thank you very much in advanced,

Ignacio.