M
Mike Carpenter
Guest
Hi! We are trying to detach a Team Foundation Server 2012 Update 3 project collection, and it is not detaching. Here is the error log that references jobs that are still running as the problem. Any suggestions? Thanks!
====================================================================
Collection name : AAACollection
Operation class : DetachCollection
Queue time : 03/26/2019 20:46:36
Start time : 03/26/2019 20:51:09
End time : 03/26/2019 20:53:14
Execution time : 0:00:02:04
Time Zone : Eastern Daylight Time
Job result : None
====================================================================
[20:51:09.860] Creating dictionary with 3 initial items:
[20:51:09.860] CollectionProperties => 22f9bd4e-0738-419c-97c6-f7a6a41413e4 (AAACollection)
[20:51:09.860] RequestingIdentity => IdentityDescriptor (IdentityType: System.Security.Principal.WindowsIdentity; Identifier: S-1-5-21-145362041-592939788-3377650921-1692)
[20:51:09.860] DatabaseMap => System.Collections.Generic.Dictionary`2[System.String,System.String]
[20:51:09.867] Acquiring servicing job lock 'Servicing-22f9bd4e-0738-419c-97c6-f7a6a41413e4'
[20:51:09.877] Setting token. Key: JobId. Value: 3a94a2ad-14f9-493b-abf7-eb22320a671a.
[20:51:09.880] OperationClass: DetachCollection
[20:53:10.150] Partition Id: 1, Host Id: 22f9bd4e-0738-419c-97c6-f7a6a41413e4, Sql Instance: servername, Database: Tfs_AAA
[20:53:10.153] onlineUpdate: False
[20:53:10.187] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.187] ++ Executing - Operation: Snapshot, Group: CleanUpSnapshot
[20:53:10.187] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.187] Executing step: Delete TFS_SNAPSHOT_COLLECTIONID stamp
[20:53:10.187] Executing step: 'Delete TFS_SNAPSHOT_COLLECTIONID stamp' DatabaseAttribute.DeleteDatabaseAttribute (1 of 28)
[20:53:10.187] Step Data: DatabaseCategory => Framework
[20:53:10.187] Step Data: DatabaseAttribute => TFS_SNAPSHOT_COLLECTIONID
[20:53:10.187] Step passed: Delete TFS_SNAPSHOT_COLLECTIONID stamp. Execution time: 1 millisecond.
[20:53:10.187] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.187] Executing step: Delete TFS_SNAPSHOT_STATE stamp
[20:53:10.187] Executing step: 'Delete TFS_SNAPSHOT_STATE stamp' DatabaseAttribute.DeleteDatabaseAttribute (2 of 28)
[20:53:10.187] Step Data: DatabaseCategory => Framework
[20:53:10.187] Step Data: DatabaseAttribute => TFS_SNAPSHOT_STATE
[20:53:10.190] Step passed: Delete TFS_SNAPSHOT_STATE stamp. Execution time: 3 milliseconds.
[20:53:10.190] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.190] Executing step: Drop existing framework snapshot schema if it exists
[20:53:10.190] Executing step: 'Drop existing framework snapshot schema if it exists' Sql.ExecuteSql (3 of 28)
[20:53:10.190] Step Data: DatabaseCategory => Framework
[20:53:10.190] Step Data: SqlResource => TfsSnapshotDropSchema.sql
[20:53:10.190] Step Data: BatchTimeout => 0
[20:53:10.190] Step Data: Parameters =>
[20:53:10.190] Step Data: Database =>
[20:53:10.190] Step Data: AcquireLock => False
[20:53:10.190] Step Data: Services[0] => Service: Catalog, Version: -1
[20:53:10.190] Step Data: Services[1] => Service: JobQueue, Version: -1
[20:53:10.190] Step Data: Services[2] => Service: JobReporting, Version: -1
[20:53:10.190] Step Data: Services[3] => Service: Group, Version: -1
[20:53:10.190] Step Data: Services[4] => Service: IdentityManagement, Version: -1
[20:53:10.220] It took 29 ms to retrieve script(s)
[20:53:10.220] Database: Tfs_AAA, Sql Instance: servername
[20:53:12.153] SQL Info: Begin set service version:Mar 27 2019 12:53:12:140AM
[20:53:12.153] End set service version:Mar 27 2019 12:53:12:150AM
[20:53:12.153] Step passed: Drop existing framework snapshot schema if it exists. Execution time: 1963 milliseconds.
[20:53:12.153] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.153] Executing step: Remove any service definitions that the catalog entries created
[20:53:12.153] Executing step: 'Remove any service definitions that the catalog entries created' Location.CleanUpSnapshottedServiceDefinitions (4 of 28)
[20:53:12.200] Step passed: Remove any service definitions that the catalog entries created. Execution time: 47 milliseconds.
[20:53:12.200] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.200] Executing step: Remove the Catalog Property Artifact Kind
[20:53:12.200] Executing step: 'Remove the Catalog Property Artifact Kind' Property.DeletePropertyArtifactKind (5 of 28)
[20:53:12.227] The property artifact kind with id 'ad359ef1-fde8-4c78-b19f-4ab30e74e53c' was deleted
[20:53:12.227] Step passed: Remove the Catalog Property Artifact Kind. Execution time: 27 milliseconds.
[20:53:12.227] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.227] Executing step: Remove the Identity Property Artifact Kind
[20:53:12.227] Executing step: 'Remove the Identity Property Artifact Kind' Property.DeletePropertyArtifactKind (6 of 28)
[20:53:12.230] The property artifact kind with id '2b258b5d-d41f-4657-8585-8bbbfec1052b' was deleted
[20:53:12.230] Step passed: Remove the Identity Property Artifact Kind. Execution time: 3 milliseconds.
[20:53:12.230] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.230] Executing step: Remove the snapshot registry entries
[20:53:12.230] Executing step: 'Remove the snapshot registry entries' Registry.CleanUpSnapshotRegistry (7 of 28)
[20:53:12.257] Step passed: Remove the snapshot registry entries. Execution time: 27 milliseconds.
[20:53:12.260] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.260] ++ Executing - Operation: Snapshot, Group: Snapshot.TfsFramework
[20:53:12.260] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.260] Executing step: Create framework snapshot schema (tables)
[20:53:12.260] Executing step: 'Create framework snapshot schema (tables)' Sql.ExecuteSql (8 of 28)
[20:53:12.260] Step Data: DatabaseCategory => Framework
[20:53:12.260] Step Data: SqlResource => TfsSnapshotCreateTables.sql
[20:53:12.260] Step Data: BatchTimeout => 0
[20:53:12.260] Step Data: Parameters =>
[20:53:12.260] Step Data: Database =>
[20:53:12.260] Step Data: AcquireLock => False
[20:53:12.260] Step Data: Services =>
[20:53:12.270] It took 11 ms to retrieve script(s)
[20:53:12.270] Database: Tfs_AAA, Sql Instance: corp-alt-04
[20:53:12.583] SQL Info: Warning! The maximum key length is 900 bytes. The index 'IX_tbl_Identity_DisplayName' has maximum length of 904 bytes. For some combination of large values, the insert/update operation will fail.
[20:53:12.583] Step passed: Create framework snapshot schema (tables). Execution time: 323 milliseconds.
[20:53:12.583] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.583] Executing step: Create framework snapshot schema (sprocs)
[20:53:12.583] Executing step: 'Create framework snapshot schema (sprocs)' Sql.ExecuteSql (9 of 28)
[20:53:12.583] Step Data: DatabaseCategory => Framework
[20:53:12.583] Step Data: SqlResource => TfsSnapshotCreateSProcs.sql
[20:53:12.583] Step Data: BatchTimeout => 0
[20:53:12.583] Step Data: Parameters =>
[20:53:12.583] Step Data: Database =>
[20:53:12.583] Step Data: AcquireLock => False
[20:53:12.583] Step Data: Services[0] => Service: JobQueue, Version: 10
[20:53:12.583] Step Data: Services[1] => Service: Catalog, Version: 3
[20:53:12.583] Step Data: Services[2] => Service: Group, Version: 2
[20:53:12.583] Step Data: Services[3] => Service: IdentityManagement, Version: 3
[20:53:12.663] It took 79 ms to retrieve script(s)
[20:53:12.663] Database: Tfs_AAA, Sql Instance: corp-alt-04
[20:53:13.783] SQL Info: The module 'prc_QueryCatalogDependents' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogNodes' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogParents' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogResources' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogResourcesByType' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_SaveCatalogChanges' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_ReleaseJobs' depends on the missing object 'prc_iiReleaseJob'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_RescheduleJobs' depends on the missing object 'prc_iiReleaseJob'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_SaveGroupSnapshot' depends on the missing object 'prc_UpdateGroupScopes'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] Begin set service version:Mar 27 2019 12:53:13:770AM
[20:53:13.783] End set service version:Mar 27 2019 12:53:13:777AM
[20:53:13.783] Step passed: Create framework snapshot schema (sprocs). Execution time: 1200 milliseconds.
[20:53:13.783] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.783] Executing step: Copy application instance identifier
[20:53:13.783] Executing step: 'Copy application instance identifier' Framework.SnapshotOriginalApplicationInstanceId (10 of 28)
[20:53:13.800] Step passed: Copy application instance identifier. Execution time: 17 milliseconds.
[20:53:13.800] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.800] Executing step: Copy collection host data to collection database
[20:53:13.800] Executing step: 'Copy collection host data to collection database' CollectionManagement.CopyCollectionHostDataForSnapshot (11 of 28)
[20:53:13.817] Step passed: Copy collection host data to collection database. Execution time: 17 milliseconds.
[20:53:13.817] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.817] Executing step: Create the Catalog Property Artifact Kind
[20:53:13.817] Executing step: 'Create the Catalog Property Artifact Kind' Property.CreatePropertyArtifactKind (12 of 28)
[20:53:13.817] Partition: 1, Host: 22f9bd4e-0738-419c-97c6-f7a6a41413e4
[20:53:13.820] Step passed: Create the Catalog Property Artifact Kind. Execution time: 3 milliseconds.
[20:53:13.820] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.820] Executing step: Copy catalog data to collection database
[20:53:13.820] Executing step: 'Copy catalog data to collection database' Catalog.SnapshotCollectionCatalogData (13 of 28)
[20:53:14.240] Found 80 nodes that need to be copied to the collection database.
[20:53:14.240] Found 6 service definitions that will to be copied to the collection database. They are...
[20:53:14.240] ServiceType: ReportManagerUrl; Identifier: e65f79ac-cbb9-402c-a40a-4396ccef8be6
[20:53:14.240] ServiceType: ReportWebServiceUrl; Identifier: e76d9256-a1db-41ea-9ac2-333d4cab5373
[20:53:14.240] ServiceType: LocationService; Identifier: 22f9bd4e-0738-419c-97c6-f7a6a41413e4
[20:53:14.240] ServiceType: LocationService; Identifier: 66b398ae-a757-465e-a8a0-e5ac3072c255
[20:53:14.240] ServiceType: WssAdminUrl; Identifier: dc38859b-7a6e-4c91-b0f8-5c8b2f876a59
[20:53:14.240] ServiceType: WssRootUrl; Identifier: 4e812e6b-9f9e-40dc-a697-3c76d0b0c7ae
[20:53:14.617] Step passed: Copy catalog data to collection database. Execution time: 797 milliseconds.
[20:53:14.617] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:14.617] Executing step: Copy job queue entries to collection database
[20:53:14.617] Executing step: 'Copy job queue entries to collection database' Job.SnapshotCollectionJobQueueEntries (14 of 28)
[20:53:14.637] [Error] TF252034: The team project collection cannot be detached at this time because one or more jobs are still in progress. You must stop all jobs before a collection can be detached.
[20:53:14.653] Microsoft.TeamFoundation.Framework.Server.TeamFoundationServicingException: TF252034: The team project collection cannot be detached at this time because one or more jobs are still in progress. You must stop all jobs before a collection can be detached.
[20:53:14.653] at Microsoft.VisualStudio.Services.Framework.JobStepPerformer.SnapshotCollectionJobQueueEntries(TeamFoundationRequestContext targetRequestContext, ServicingContext servicingContext)
[20:53:14.653] at Microsoft.TeamFoundation.Framework.Server.TeamFoundationStepPerformerBase.Microsoft.TeamFoundation.Framework.Server.IStepPerformer.PerformStep(String servicingOperation, String stepType, String stepData, ServicingContext servicingContext)
[20:53:14.653] at Microsoft.TeamFoundation.Framework.Server.ServicingStepDriver.PerformServicingStep(ServicingStep step, ServicingContext servicingContext, ServicingStepGroup group, ServicingOperation servicingOperation, Int32 stepNumber, Int32 totalSteps)
[20:53:14.653] Step failed: Copy job queue entries to collection database. Execution time: 36 milliseconds.
[20:53:14.667] Clearing dictionary, removing all items.
======================================================================================================
Step execution times in descending order
======================================================================================================
Drop existing framework snapshot schema if it exists (CleanUpSnapshot, Snapshot) - 1963 milliseconds
Create framework snapshot schema (sprocs) (Snapshot.TfsFramework, Snapshot) - 1200 milliseconds
Copy catalog data to collection database (Snapshot.TfsFramework, Snapshot) - 797 milliseconds
Create framework snapshot schema (tables) (Snapshot.TfsFramework, Snapshot) - 323 milliseconds
Remove any service definitions that the catalog entries c... (CleanUpSnapshot, Snapshot) - 47 milliseconds
Copy job queue entries to collection database (Snapshot.TfsFramework, Snapshot) - 36 milliseconds
Remove the Catalog Property Artifact Kind (CleanUpSnapshot, Snapshot) - 27 milliseconds
Remove the snapshot registry entries (CleanUpSnapshot, Snapshot) - 27 milliseconds
Copy application instance identifier (Snapshot.TfsFramework, Snapshot) - 17 milliseconds
Copy collection host data to collection database (Snapshot.TfsFramework, Snapshot) - 17 milliseconds
Delete TFS_SNAPSHOT_STATE stamp (CleanUpSnapshot, Snapshot) - 3 milliseconds
Remove the Identity Property Artifact Kind (CleanUpSnapshot, Snapshot) - 3 milliseconds
Create the Catalog Property Artifact Kind (Snapshot.TfsFramework, Snapshot) - 3 milliseconds
Delete TFS_SNAPSHOT_COLLECTIONID stamp (CleanUpSnapshot, Snapshot) - 1 millisecond
======================================================================================================
Execution times by group in descending order
======================================================================================================
Snapshot.TfsFramework (Snapshot) - 2 seconds
CleanUpSnapshot (Snapshot) - 2 seconds
Continue reading...
====================================================================
Collection name : AAACollection
Operation class : DetachCollection
Queue time : 03/26/2019 20:46:36
Start time : 03/26/2019 20:51:09
End time : 03/26/2019 20:53:14
Execution time : 0:00:02:04
Time Zone : Eastern Daylight Time
Job result : None
====================================================================
[20:51:09.860] Creating dictionary with 3 initial items:
[20:51:09.860] CollectionProperties => 22f9bd4e-0738-419c-97c6-f7a6a41413e4 (AAACollection)
[20:51:09.860] RequestingIdentity => IdentityDescriptor (IdentityType: System.Security.Principal.WindowsIdentity; Identifier: S-1-5-21-145362041-592939788-3377650921-1692)
[20:51:09.860] DatabaseMap => System.Collections.Generic.Dictionary`2[System.String,System.String]
[20:51:09.867] Acquiring servicing job lock 'Servicing-22f9bd4e-0738-419c-97c6-f7a6a41413e4'
[20:51:09.877] Setting token. Key: JobId. Value: 3a94a2ad-14f9-493b-abf7-eb22320a671a.
[20:51:09.880] OperationClass: DetachCollection
[20:53:10.150] Partition Id: 1, Host Id: 22f9bd4e-0738-419c-97c6-f7a6a41413e4, Sql Instance: servername, Database: Tfs_AAA
[20:53:10.153] onlineUpdate: False
[20:53:10.187] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.187] ++ Executing - Operation: Snapshot, Group: CleanUpSnapshot
[20:53:10.187] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.187] Executing step: Delete TFS_SNAPSHOT_COLLECTIONID stamp
[20:53:10.187] Executing step: 'Delete TFS_SNAPSHOT_COLLECTIONID stamp' DatabaseAttribute.DeleteDatabaseAttribute (1 of 28)
[20:53:10.187] Step Data: DatabaseCategory => Framework
[20:53:10.187] Step Data: DatabaseAttribute => TFS_SNAPSHOT_COLLECTIONID
[20:53:10.187] Step passed: Delete TFS_SNAPSHOT_COLLECTIONID stamp. Execution time: 1 millisecond.
[20:53:10.187] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.187] Executing step: Delete TFS_SNAPSHOT_STATE stamp
[20:53:10.187] Executing step: 'Delete TFS_SNAPSHOT_STATE stamp' DatabaseAttribute.DeleteDatabaseAttribute (2 of 28)
[20:53:10.187] Step Data: DatabaseCategory => Framework
[20:53:10.187] Step Data: DatabaseAttribute => TFS_SNAPSHOT_STATE
[20:53:10.190] Step passed: Delete TFS_SNAPSHOT_STATE stamp. Execution time: 3 milliseconds.
[20:53:10.190] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:10.190] Executing step: Drop existing framework snapshot schema if it exists
[20:53:10.190] Executing step: 'Drop existing framework snapshot schema if it exists' Sql.ExecuteSql (3 of 28)
[20:53:10.190] Step Data: DatabaseCategory => Framework
[20:53:10.190] Step Data: SqlResource => TfsSnapshotDropSchema.sql
[20:53:10.190] Step Data: BatchTimeout => 0
[20:53:10.190] Step Data: Parameters =>
[20:53:10.190] Step Data: Database =>
[20:53:10.190] Step Data: AcquireLock => False
[20:53:10.190] Step Data: Services[0] => Service: Catalog, Version: -1
[20:53:10.190] Step Data: Services[1] => Service: JobQueue, Version: -1
[20:53:10.190] Step Data: Services[2] => Service: JobReporting, Version: -1
[20:53:10.190] Step Data: Services[3] => Service: Group, Version: -1
[20:53:10.190] Step Data: Services[4] => Service: IdentityManagement, Version: -1
[20:53:10.220] It took 29 ms to retrieve script(s)
[20:53:10.220] Database: Tfs_AAA, Sql Instance: servername
[20:53:12.153] SQL Info: Begin set service version:Mar 27 2019 12:53:12:140AM
[20:53:12.153] End set service version:Mar 27 2019 12:53:12:150AM
[20:53:12.153] Step passed: Drop existing framework snapshot schema if it exists. Execution time: 1963 milliseconds.
[20:53:12.153] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.153] Executing step: Remove any service definitions that the catalog entries created
[20:53:12.153] Executing step: 'Remove any service definitions that the catalog entries created' Location.CleanUpSnapshottedServiceDefinitions (4 of 28)
[20:53:12.200] Step passed: Remove any service definitions that the catalog entries created. Execution time: 47 milliseconds.
[20:53:12.200] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.200] Executing step: Remove the Catalog Property Artifact Kind
[20:53:12.200] Executing step: 'Remove the Catalog Property Artifact Kind' Property.DeletePropertyArtifactKind (5 of 28)
[20:53:12.227] The property artifact kind with id 'ad359ef1-fde8-4c78-b19f-4ab30e74e53c' was deleted
[20:53:12.227] Step passed: Remove the Catalog Property Artifact Kind. Execution time: 27 milliseconds.
[20:53:12.227] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.227] Executing step: Remove the Identity Property Artifact Kind
[20:53:12.227] Executing step: 'Remove the Identity Property Artifact Kind' Property.DeletePropertyArtifactKind (6 of 28)
[20:53:12.230] The property artifact kind with id '2b258b5d-d41f-4657-8585-8bbbfec1052b' was deleted
[20:53:12.230] Step passed: Remove the Identity Property Artifact Kind. Execution time: 3 milliseconds.
[20:53:12.230] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.230] Executing step: Remove the snapshot registry entries
[20:53:12.230] Executing step: 'Remove the snapshot registry entries' Registry.CleanUpSnapshotRegistry (7 of 28)
[20:53:12.257] Step passed: Remove the snapshot registry entries. Execution time: 27 milliseconds.
[20:53:12.260] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.260] ++ Executing - Operation: Snapshot, Group: Snapshot.TfsFramework
[20:53:12.260] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.260] Executing step: Create framework snapshot schema (tables)
[20:53:12.260] Executing step: 'Create framework snapshot schema (tables)' Sql.ExecuteSql (8 of 28)
[20:53:12.260] Step Data: DatabaseCategory => Framework
[20:53:12.260] Step Data: SqlResource => TfsSnapshotCreateTables.sql
[20:53:12.260] Step Data: BatchTimeout => 0
[20:53:12.260] Step Data: Parameters =>
[20:53:12.260] Step Data: Database =>
[20:53:12.260] Step Data: AcquireLock => False
[20:53:12.260] Step Data: Services =>
[20:53:12.270] It took 11 ms to retrieve script(s)
[20:53:12.270] Database: Tfs_AAA, Sql Instance: corp-alt-04
[20:53:12.583] SQL Info: Warning! The maximum key length is 900 bytes. The index 'IX_tbl_Identity_DisplayName' has maximum length of 904 bytes. For some combination of large values, the insert/update operation will fail.
[20:53:12.583] Step passed: Create framework snapshot schema (tables). Execution time: 323 milliseconds.
[20:53:12.583] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:12.583] Executing step: Create framework snapshot schema (sprocs)
[20:53:12.583] Executing step: 'Create framework snapshot schema (sprocs)' Sql.ExecuteSql (9 of 28)
[20:53:12.583] Step Data: DatabaseCategory => Framework
[20:53:12.583] Step Data: SqlResource => TfsSnapshotCreateSProcs.sql
[20:53:12.583] Step Data: BatchTimeout => 0
[20:53:12.583] Step Data: Parameters =>
[20:53:12.583] Step Data: Database =>
[20:53:12.583] Step Data: AcquireLock => False
[20:53:12.583] Step Data: Services[0] => Service: JobQueue, Version: 10
[20:53:12.583] Step Data: Services[1] => Service: Catalog, Version: 3
[20:53:12.583] Step Data: Services[2] => Service: Group, Version: 2
[20:53:12.583] Step Data: Services[3] => Service: IdentityManagement, Version: 3
[20:53:12.663] It took 79 ms to retrieve script(s)
[20:53:12.663] Database: Tfs_AAA, Sql Instance: corp-alt-04
[20:53:13.783] SQL Info: The module 'prc_QueryCatalogDependents' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogNodes' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogParents' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogResources' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_QueryCatalogResourcesByType' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_SaveCatalogChanges' depends on the missing object 'prc_iQueryCatalogObjects'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_ReleaseJobs' depends on the missing object 'prc_iiReleaseJob'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_RescheduleJobs' depends on the missing object 'prc_iiReleaseJob'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] The module 'prc_SaveGroupSnapshot' depends on the missing object 'prc_UpdateGroupScopes'. The module will still be created; however, it cannot run successfully until the object exists.
[20:53:13.783] Begin set service version:Mar 27 2019 12:53:13:770AM
[20:53:13.783] End set service version:Mar 27 2019 12:53:13:777AM
[20:53:13.783] Step passed: Create framework snapshot schema (sprocs). Execution time: 1200 milliseconds.
[20:53:13.783] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.783] Executing step: Copy application instance identifier
[20:53:13.783] Executing step: 'Copy application instance identifier' Framework.SnapshotOriginalApplicationInstanceId (10 of 28)
[20:53:13.800] Step passed: Copy application instance identifier. Execution time: 17 milliseconds.
[20:53:13.800] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.800] Executing step: Copy collection host data to collection database
[20:53:13.800] Executing step: 'Copy collection host data to collection database' CollectionManagement.CopyCollectionHostDataForSnapshot (11 of 28)
[20:53:13.817] Step passed: Copy collection host data to collection database. Execution time: 17 milliseconds.
[20:53:13.817] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.817] Executing step: Create the Catalog Property Artifact Kind
[20:53:13.817] Executing step: 'Create the Catalog Property Artifact Kind' Property.CreatePropertyArtifactKind (12 of 28)
[20:53:13.817] Partition: 1, Host: 22f9bd4e-0738-419c-97c6-f7a6a41413e4
[20:53:13.820] Step passed: Create the Catalog Property Artifact Kind. Execution time: 3 milliseconds.
[20:53:13.820] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:13.820] Executing step: Copy catalog data to collection database
[20:53:13.820] Executing step: 'Copy catalog data to collection database' Catalog.SnapshotCollectionCatalogData (13 of 28)
[20:53:14.240] Found 80 nodes that need to be copied to the collection database.
[20:53:14.240] Found 6 service definitions that will to be copied to the collection database. They are...
[20:53:14.240] ServiceType: ReportManagerUrl; Identifier: e65f79ac-cbb9-402c-a40a-4396ccef8be6
[20:53:14.240] ServiceType: ReportWebServiceUrl; Identifier: e76d9256-a1db-41ea-9ac2-333d4cab5373
[20:53:14.240] ServiceType: LocationService; Identifier: 22f9bd4e-0738-419c-97c6-f7a6a41413e4
[20:53:14.240] ServiceType: LocationService; Identifier: 66b398ae-a757-465e-a8a0-e5ac3072c255
[20:53:14.240] ServiceType: WssAdminUrl; Identifier: dc38859b-7a6e-4c91-b0f8-5c8b2f876a59
[20:53:14.240] ServiceType: WssRootUrl; Identifier: 4e812e6b-9f9e-40dc-a697-3c76d0b0c7ae
[20:53:14.617] Step passed: Copy catalog data to collection database. Execution time: 797 milliseconds.
[20:53:14.617] +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[20:53:14.617] Executing step: Copy job queue entries to collection database
[20:53:14.617] Executing step: 'Copy job queue entries to collection database' Job.SnapshotCollectionJobQueueEntries (14 of 28)
[20:53:14.637] [Error] TF252034: The team project collection cannot be detached at this time because one or more jobs are still in progress. You must stop all jobs before a collection can be detached.
[20:53:14.653] Microsoft.TeamFoundation.Framework.Server.TeamFoundationServicingException: TF252034: The team project collection cannot be detached at this time because one or more jobs are still in progress. You must stop all jobs before a collection can be detached.
[20:53:14.653] at Microsoft.VisualStudio.Services.Framework.JobStepPerformer.SnapshotCollectionJobQueueEntries(TeamFoundationRequestContext targetRequestContext, ServicingContext servicingContext)
[20:53:14.653] at Microsoft.TeamFoundation.Framework.Server.TeamFoundationStepPerformerBase.Microsoft.TeamFoundation.Framework.Server.IStepPerformer.PerformStep(String servicingOperation, String stepType, String stepData, ServicingContext servicingContext)
[20:53:14.653] at Microsoft.TeamFoundation.Framework.Server.ServicingStepDriver.PerformServicingStep(ServicingStep step, ServicingContext servicingContext, ServicingStepGroup group, ServicingOperation servicingOperation, Int32 stepNumber, Int32 totalSteps)
[20:53:14.653] Step failed: Copy job queue entries to collection database. Execution time: 36 milliseconds.
[20:53:14.667] Clearing dictionary, removing all items.
======================================================================================================
Step execution times in descending order
======================================================================================================
Drop existing framework snapshot schema if it exists (CleanUpSnapshot, Snapshot) - 1963 milliseconds
Create framework snapshot schema (sprocs) (Snapshot.TfsFramework, Snapshot) - 1200 milliseconds
Copy catalog data to collection database (Snapshot.TfsFramework, Snapshot) - 797 milliseconds
Create framework snapshot schema (tables) (Snapshot.TfsFramework, Snapshot) - 323 milliseconds
Remove any service definitions that the catalog entries c... (CleanUpSnapshot, Snapshot) - 47 milliseconds
Copy job queue entries to collection database (Snapshot.TfsFramework, Snapshot) - 36 milliseconds
Remove the Catalog Property Artifact Kind (CleanUpSnapshot, Snapshot) - 27 milliseconds
Remove the snapshot registry entries (CleanUpSnapshot, Snapshot) - 27 milliseconds
Copy application instance identifier (Snapshot.TfsFramework, Snapshot) - 17 milliseconds
Copy collection host data to collection database (Snapshot.TfsFramework, Snapshot) - 17 milliseconds
Delete TFS_SNAPSHOT_STATE stamp (CleanUpSnapshot, Snapshot) - 3 milliseconds
Remove the Identity Property Artifact Kind (CleanUpSnapshot, Snapshot) - 3 milliseconds
Create the Catalog Property Artifact Kind (Snapshot.TfsFramework, Snapshot) - 3 milliseconds
Delete TFS_SNAPSHOT_COLLECTIONID stamp (CleanUpSnapshot, Snapshot) - 1 millisecond
======================================================================================================
Execution times by group in descending order
======================================================================================================
Snapshot.TfsFramework (Snapshot) - 2 seconds
CleanUpSnapshot (Snapshot) - 2 seconds
Continue reading...