SqlPackage Publish fails in some conditions with "ISqlModelElement: Identifier part cannot be null" #417
Description
- SqlPackage or DacFx Version: 162.2.111.2
- .NET Framework (Windows-only) or .NET Core:
- Environment (local platform and source/target platforms):
- Teamcity agent: Windows Server 2012 R2
- Microsoft SQL Server 2019 (RTM-CU25) - 15.0.4355.3 (X64)
- Compatibility Level: 150
Steps to Reproduce:
In PR build of TSQL projects we run tSQLt tests in DB clone. For that we create DB clone on the fly and deploy corresponding dacpac with tests into this clone. This scenario works like a charm in all projects except one. The project is one of our In-Memory DBs; for the rest of In-Memory DBs described scenario works like a charm. The problematic DB can be deployed on "normal" DB (not clone) with no issues; sqlpackage params are the same, dacpac is exactly the same.
The problem can be reproduced on this project at any time, it is stable. But I have no glue what could be the cause of the problem.
SqlPackage params:
& 'C:\Program Files\Microsoft SQL Server\160\dac\bin\sqlpackage.exe' /Action:Publish /SourceFile:'C:\BuildAgent\temp\buildTmp\output_build\post_trade_test.dacpac' /TargetConnectionString:"Data Source=our_server;Initial Catalog='_tsqlt_temp_clone__post_trade';Connect Timeout=60;Integrated Security=True;TrustServerCertificate=True;Persist Security Info=False;Pooling=False;MultipleActiveResultSets=False;Encrypt=False" /p:ExcludeObjectType=Logins /p:ExcludeObjectType=RoleMembership /p:ExcludeObjectType=Users /p:ExcludeObjectType=Permissions /p:ExcludeObjectType=PartitionFunctions /p:ExcludeObjectType=PartitionSchemes /p:IgnoreIndexOptions=True /p:IgnoreTableOptions=True /p:DatabaseLockTimeout=60 /p:CommandTimeout=150 /p:DropObjectsNotInSource=True /p:DropStatisticsNotInSource=False /p:IgnoreObjectPlacementOnPartitionScheme=true /p:IgnorePartitionSchemes=true /p:IgnoreTablePartitionOptions=true /p:ScriptDatabaseOptions=False /p:DropPermissionsNotInSource=False /p:DropRoleMembersNotInSource=False /p:AdditionalDeploymentContributors=AgileSqlClub.DeploymentFilterContributor /p:AdditionalDeploymentContributorArguments='SqlPackageFilter0=IgnoreType(Statistics);SqlPackageFilter1=IgnoreSchema(tmp)' /p:BlockOnPossibleDataLoss=False /p:IncludeCompositeObjects=True /Profile:'post_trade\post_trade_test\Publish\post_trade_test.publish.xml'
Tail of SqlPackage Publish log with /d switch:
Details
Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 25 : 2024-02-28T19:04:28 : Perf: Operation started (name, details): Top Level Populator,Sql150ExternalTablePopulator Microsoft.Data.Tools.Diagnostics.Tracer Information: 0 : 2024-02-28T19:04:28 : Populating child populator : Sql150ExternalTableColumnPopulator Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 1 : 2024-02-28T19:04:28 : Executing populator: Sql150ExternalTableColumnPopulatorMicrosoft.Data.Tools.Diagnostics.Tracer Verbose: 25 : 2024-02-28T19:04:28 : Perf: Operation started (name, details): Child Populator,Sql150ExternalTableColumnPopulator
Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 25 : 2024-02-28T19:04:28 : Perf: Operation ended (name, details, elapsed in ms): Child Populator,Sql150ExternalTableColumnPopulator,0
Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 25 : 2024-02-28T19:04:28 : Perf: Operation ended (name, details, elapsed in ms): Top Level Populator,Sql150ExternalTablePopulator,0
Microsoft.Data.Tools.Diagnostics.Tracer Information: 0 : 2024-02-28T19:04:28 : Populating populator : SqlSysCommentObjectDependencyPopulator
Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 1 : 2024-02-28T19:04:28 : Executing populator:
SqlSysCommentObjectDependencyPopulatorMicrosoft.Data.Tools.Diagnostics.Tracer Verbose: 25 : 2024-02-28T19:04:28 : Perf: Operation started (name, details): Top Level Populator,SqlSysCommentObjectDependencyPopulator
Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 25 : 2024-02-28T19:04:28 : Perf: Operation ended (name, details, elapsed in ms): Top Level Populator,SqlSysCommentObjectDependencyPopulator,21
Microsoft.Data.Tools.Diagnostics.Tracer Warning: 0 : 2024-02-28T19:04:28 : Reverse Engineering operation cancelled. Exception cannot be retried.
Exception: Microsoft.Data.Tools.Schema.SchemaModel.ModelException: Identifier part cannot be null.
at Microsoft.Data.Tools.Schema.SchemaModel.ModelStore.CheckIdentifierPartsLength(ICollection1 parts) at Microsoft.Data.Tools.Schema.SchemaModel.ModelStore.CreateIdentifierImpl(Int32 externalPartsId, ICollection1 parts)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.SqlSysCommentObjectDependencyPopulator.GetReferencedElement(Type& referencedElementType, ModelIdentifier& referencedModelId)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.SqlSysCommentObjectDependencyPopulator.CreateElement(ReverseEngineerOption option, EventArgs args)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.TopLevelElementPopulator1.Populate(SqlReverseEngineerRequest request, OrdinalSqlDataReader reader, ReverseEngineerOption option) at Microsoft.Data.Tools.Schema.Sql.SchemaModel.SqlReverseEngineerImpl.ExecutePopulators(Tuple2 connectionTuple, IList1 populators, Int32 totalPopulatorsCount, Int32 startIndex, Boolean progressAlreadyUpdated, ReverseEngineerOption option, SqlReverseEngineerRequest request) Microsoft.Data.Tools.Diagnostics.Tracer Error: 0 : 2024-02-28T19:04:28 : Unexpected exception in ExecutePopulators(). In a retail build this would go in the ErrorManager rather than being allowed to crash VS. This should never happen - known errors should be explicitly handled. Microsoft.Data.Tools.Schema.SchemaModel.ModelException: Identifier part cannot be null. at Microsoft.Data.Tools.Schema.SchemaModel.ModelStore.CheckIdentifierPartsLength(ICollection1 parts)
at Microsoft.Data.Tools.Schema.SchemaModel.ModelStore.CreateIdentifierImpl(Int32 externalPartsId, ICollection1 parts) at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.SqlSysCommentObjectDependencyPopulator.GetReferencedElement(Type& referencedElementType, ModelIdentifier& referencedModelId) at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.SqlSysCommentObjectDependencyPopulator.CreateElement(ReverseEngineerOption option, EventArgs args) at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.TopLevelElementPopulator1.Populate(SqlReverseEngineerRequest request, OrdinalSqlDataReader reader, ReverseEngineerOption option)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.SqlReverseEngineerImpl.ExecutePopulators(Tuple2 connectionTuple, IList1 populators, Int32 totalPopulatorsCount, Int32 startIndex, Boolean progressAlreadyUpdated, ReverseEngineerOption option, SqlReverseEngineerRequest request) Microsoft.Data.Tools.Schema.SchemaModel.ModelException: Identifier part cannot be null.
at Microsoft.Data.Tools.Schema.SchemaModel.ModelStore.CheckIdentifierPartsLength(ICollection1 parts) at Microsoft.Data.Tools.Schema.SchemaModel.ModelStore.CreateIdentifierImpl(Int32 externalPartsId, ICollection1 parts)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.SqlSysCommentObjectDependencyPopulator.GetReferencedElement(Type& referencedElementType, ModelIdentifier& referencedModelId)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.SqlSysCommentObjectDependencyPopulator.CreateElement(ReverseEngineerOption option, EventArgs args)
at Microsoft.Data.Tools.Schema.Sql.SchemaModel.ReverseEngineerPopulators.TopLevelElementPopulator1.Populate(SqlReverseEngineerRequest request, OrdinalSqlDataReader reader, ReverseEngineerOption option) at Microsoft.Data.Tools.Schema.Sql.SchemaModel.SqlReverseEngineerImpl.ExecutePopulators(Tuple2 connectionTuple, IList1 populators, Int32 totalPopulatorsCount, Int32 startIndex, Boolean progressAlreadyUpdated, ReverseEngineerOption option, SqlReverseEngineerRequest request) Microsoft.Data.Tools.Diagnostics.Tracer Information: 25 : 2024-02-28T19:04:28 : Perf: Operation ended (name, details, elapsed in ms): PopulateAll,,86995 Microsoft.Data.Tools.Diagnostics.Tracer Error: 1 : 2024-02-28T19:04:28 : Error detected when reverse engineering the database. Severity:'Error' Prefix:'' Error Code:'0' Message:An error occurred while attempting to reverse engineer elements of type Microsoft.Data.Tools.Schema.Sql.SchemaModel.ISqlModelElement: Identifier part cannot be null. Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2024-02-28T19:04:28 : Microsoft.SqlServer.Dac.DacServicesException: An error occurred during deployment plan generation. Deployment cannot continue. Error SQL72018: ISqlModelElement could not be imported but one or more of these objects exist in your source. ---> Microsoft.Data.Tools.Schema.Sql.Deployment.DeploymentFailedException: Errors occurred while modeling the target database. Deployment can not continue. at Microsoft.Data.Tools.Schema.Sql.Deployment.SqlDeployment.ThrowIfErrors(String message, ErrorManager errors, Object category) at Microsoft.Data.Tools.Schema.Sql.Deployment.SqlDeploymentEndpointServer.OnLoad(ErrorManager errors, DeploymentEngineContext context) at Microsoft.Data.Tools.Schema.Sql.Deployment.SqlDeployment.PrepareModels() at Microsoft.Data.Tools.Schema.Sql.Deployment.SqlDeployment.InitializePlanGeneratator() at Microsoft.Data.Tools.Schema.Sql.Deployment.SqlDeployment.CreateController(Action1 msgHandler)
at Microsoft.SqlServer.Dac.DacServices.CreateController(SqlDeployment deploymentEngine, ErrorManager errorManager)
--- End of inner exception stack trace ---
Microsoft.Data.Tools.Diagnostics.Tracer Information: 25 : 2024-02-28T19:04:28 : Perf: Operation ended (name, details, elapsed in ms): Initializing deployment,,91748
Initializing deployment (Failed)
*** An error occurred during deployment plan generation. Deployment cannot continue.
Error SQL72018: ISqlModelElement could not be imported but one or more of these objects exist in your source.Errors occurred while modeling the target database. Deployment can not continue.
Microsoft.Data.Tools.Diagnostics.Tracer Information: 18 : 2024-02-28T19:04:28 : Time elapsed: 0:01:32.16.
Time elapsed 0:01:32.16
Microsoft.Data.Tools.Diagnostics.Tracer Information: 0 : 2024-02-28T19:04:28 : SqlPackage completed
there is about 1.5 million lines of log above it.
Let me know if you need additional details.
Did this occur in prior versions? If not - which version(s) did it work in?
on 162.0.52.1 we had the same issue
(DacFx/SqlPackage/SSMS/Azure Data Studio)