SqlPackage Publish fails in some conditions with "ISqlModelElement: Identifier part cannot be null"

[IVNSTN]

• 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:
Sql150ExternalTableColumnPopulator
Microsoft.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:
SqlSysCommentObjectDependencyPopulator
Microsoft.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)

[namangupta211]

Hi @IVNSTN, Thanks for highlighting the issue. Can you please share more details or a sample dacpac to help us reproduce the issue?

[IVNSTN]

I'd be happy to give you a minimal repro but, as I already mentioned, I have no idea what to look for. The DB is a real thing used at prod. The error is reproduced only in certain circumstances so I'd have to share both full dacpac and DB dump which is impossible.

If you @namangupta211 can give me a hint what to look for in huge publish log I think I could give you some other details. I don't see even what object type it is trying to process.

[llali]

@IVNSTN sorry for the delay. Is it possible to run the same command with additional parameter to generate logs (/df:[path to logs] I'm hoping that in that generated logs we can get more details. At least we might give us the stack trace which helps us find the right place in the code to fix the issue. Thanks

[llali]

@IVNSTN this kind of error usually happens when using * instead of specifying column names in queries.