Hi Team,

A customer has reported high CPU usage for the UnifyBroker service coming to me initial with the following report:

"In the past month we have been getting High CPU (90%) usage of the UnfyBroker service. We are using version v5.3.3. There has been no change in the environment other than the normal Microsoft patches once a month. It is occurring on both our prod and uat environments."

Confirm some further details with the customer I got the following spec information on the hosts and details about the behaviour:

"Specs on the servers.

Name Memory vCPU OS

PRD 16Gb 4 2016

UAT          14Gb 4 2016

Processor type - Intel(R) Xeon(R) Gold 5118 CPU @ 2.30GHz, 2295 Mhz, 1 Core(s), 1 Logical Processor(s)

The high cpu is more often on the uat server which processes the same data as prod for new accounts but the changes during the day are very minimal. The cpu usage does come down after

The utilization in some instances has cleared itself. Some have been by stopping the service. Timing is from 10 mins to an hour for uat. Interestingly on the prd server the time has been for several hours."

Some initial adjustments were made to the scheduler to ensure nothing is overlapping, though this wasn't really happening much anyway. These adjustments did not see any improvement to the situation.

Additionally the customer reported back the entity counts in the connectors to get a gauge for the size of the environment:

"Connector Prod Uat

Employee CSV 10792 10792

Position CSV 10792 10792

Teams 14805 1035

AD 45683 51356

Adapters

Person 10792 10792

Position 10792 10792"

Looking at the extensibility for the setup there are a number of powershell transform in the environment, which may explain some high cpu usage while connectors or running, though doesn't seem to explain why the high cpu usage continues afterwards.  

Finally the following resource monitor screenshots were provided to see what is consuming the resources for the service while no connectors are running:

I have confirmed no out of bounds scripts are contacting the service. And that there aren't a large number of WebUI sessions open that could be causing issues. So I am looking for the next steps in troubleshooting this one. Are you able to provide any guidance in figuring out what could be consuming the resources like this?

Let me know if there is any further information I can provide you.

Thanks in advance

An update from Azure via the SCIM gateway is being passed through to the adapter as a large XML document, as shown in this UNIFYBroker PowerShell log entry in a reverse adapter transform:

Before this SCIM update was received, the JobTitle field in the adapter for this user was NULL.  After the export update was received and processed the field in the adapter contained the XML document content.  Here is what the Azure POD showed:

According to Azure, it doesn't appear to be updating the title SCIM attribute (which ismapped to the JobTitle adapter field) at all, but nevertheless UNIFYBroker is populating it with XML document content by the time it gets to the adapter reverse transform.

Here's the adapter reverse transform (which doesn't do anything with JobTitle) showing the logging code:

Hello Team,

I understand editing the service extensibility config directly is not supported/recommend, and therefor this issue shouldn't be expected to impact any environments under normal circumstances. However I found some interesting behaviour that occurs when an AdapterConfiguration object in the Unify.Product.IdentityBroker.AdapterEnginePlugInKey.extensibility.config.xml file is given a duplicate "AdapterId".

When attempting to start the service with an incorrect configuration like this, the service fails to start which is expected, however the entire Unify.Product.IdentityBroker.AdapterEnginePlugInKey.extensibility.config.xml file is also cleared and saved in the process. Clearing any other configuration that may be there. I'm unsure if this is intended behaviour, but figured I would log this here anyway for your consideration so the service would simply fail and not save over the configuration.

UNIFYBroker version 5.3.1

Thanks

Hi Matt/Beau,

I am currently installing UNIFYBroker/Plus with a UNIFYConnect-style configuration for a customer. The OOTB connectors are Chris21 and AD, and there is also an existing PowerShell connector for “PeopleStreme” (a REST API-based recruitment system) that is being extended and a new “Mercury HR” CSV file import being added.

Could you please send me all the UNIFYBroker/Plus patches and files (both service and web) that I will need to run the latest version of UNIFYBroker/Plus successfully in this environment? There has been a lot of work done since the last official release on Voice. It would be great if I could patch this environment up to the same base level as the UNIFYConnect environments.

Thanks.

I have a SCIM gateway configured in UNIFYConnect and the following error appears every time a SCIM request is received:

There is a mapping for the employeeNumber field, as evidenced here:

I tried recycling, and then deleting and recreating the gateway from scratch but it continues to give me the same outcome.

The UNIFYConnect external address for the gateway is "https://unifyconnect-scim-dev.unifysolutions.net/CUSTOMERNAME-dev-B2BAD/"

How can I stop this error from appearing and get my config to work correctly?

I removed a user's application assignment in Azure and it initated a disable (i.e. delete user profile) SCIM operation and reported a successful outcome:

However, the user profile object remained present in UNIFYBroker:

According to the UNIFYBroker logs the request came through as an entity update (I know this from the PowerShell debugging tracewrites shown):

20220428,13:07:42,UNIFYBroker,Logging,Information,Reverse Transform extracted ROLE=[NONE],Normal
20220428,13:07:42,UNIFYBroker,Logging,Information,"[EmployeeGuid, 14de44ec-2322-4c75-b745-cb873341f8e4] [Application, XXXXXXXXX] [Active, False] [UserPrincipalName, admin@unifyXXXXXXXX.onmicrosoft.com] [TicketingID, XXXXXXXXX.14de44ec-2322-4c75-b745-cb873341f8e4] [Role, NONE] [EmployeeName, David Parsonson] [0799C19A00044B368A7D06D9AE23CC07, c36f2c4a-4eb6-46ac-a69c-9565ec327e9e]",Normal
20220428,13:07:42,UNIFYBroker,Connector,Information,"Request to update entity to connector.
Request to update entities [Count:1] to connector Ticketed Application Provisioning.",Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,GIEBP(Application),Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,"PV=(XXXXXXXX) for [EmployeeGuid, 14de44ec-2322-4c75-b745-cb873341f8e4] [Application, XXXXXXX] [Active, False] [UserPrincipalName, admin@unifyXXXXXXXXX.onmicrosoft.com] [TicketingID, Marketo.14de44ec-2322-4c75-b745-cb873341f8e4] [Role, NONE] [EmployeeName, David Parsonson] [0799C19A00044B368A7D06D9AE23CC07, c36f2c4a-4eb6-46ac-a69c-9565ec327e9e]",Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,"Saving [XXXXXXX.14de44ec-2322-4c75-b745-cb873341f8e4] [EmployeeGuid, 14de44ec-2322-4c75-b745-cb873341f8e4] [Application, XXXXXXX] [Active, False] [UserPrincipalName, admin@unifyXXXXXX.onmicrosoft.com] [TicketingID, XXXXXX.14de44ec-2322-4c75-b745-cb873341f8e4] [Role, NONE] [EmployeeName, David Parsonson] [0799C19A00044B368A7D06D9AE23CC07, c36f2c4a-4eb6-46ac-a69c-9565ec327e9e]",Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,update: init Lines=@{Application=XXXXXXX; Active=True; EmployeeId=; EmployeeName=David Parsonson; Role=Admin; UserPrincipalName=admin@unifyXXXXXXXX.onmicrosoft.com; TicketingID=XXXXXXX.14de44ec-2322-4c75-b745-cb873341f8e4; EmployeeGuid=14de44ec-2322-4c75-b745-cb873341f8e4} @ 1,Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,update: after Lines=@{Application=XXXXXXXX; Active=False; EmployeeId=; EmployeeName=David Parsonson; Role=NONE; UserPrincipalName=admin@unifyXXXXXXX.onmicrosoft.com; TicketingID=Marketo.14de44ec-2322-4c75-b745-cb873341f8e4; EmployeeGuid=14de44ec-2322-4c75-b745-cb873341f8e4} @ 1,Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,update done,Normal
20220428,13:07:45,UNIFYBroker,Logging,Information,Updated 1 entities in C:\CSV\XXXXXXXX-Users.csv,Normal
20220428,13:07:45,UNIFYBroker,Connector,Information,"Update entities to connector completed.
Update entities 1 to connector Ticketed Application Provisioning reported 1 entities saved, 0 failed. Duration: 00:00:02.9484342",Normal

The UNIFYBroker entity for the user should have been deleted rather than updated.  It looks like UNIFYBroker has missed the "Action: disable" part of the SCIM request from Azure, which is the only indication I can see that the request was to disable/delete the user, rather than update it.

Can you please check that UNIFYBroker work with SCIM disable requests from Azure correctly?

This is high priority for me as I have been asked to deliver SCIM app provisioning functionality (including disable) for the customer to UAT by early next week.

Thanks

I am seeing the above error *sometimes* when attempting to update a user via SCIM.

In every case of the error that I've seen SCIM has been trying to update a single field (Role) which is mapped from Azure's large "appRoleAssignments" XML field value, but I don't actually know if that's relevant or coincidental.

The full stack trace is:

20220428,11:53:00,UNIFYBroker,Logging,Information,Healthcheck,Normal
20220428,11:54:00,UNIFYBroker,Logging,Information,Healthcheck,Normal
20220428,11:54:05,UNIFYBroker,SCIMGateway,Error,"Error during SCIM operation: System.InvalidOperationException: Sequence contains more than one element
at System.Linq.Enumerable.Single[TSource](IEnumerable`1 source)
at Unify.Product.IdentityBroker.SCIMProvider.Patch(IAdapterEntity adapterEntity, PatchRequest2 patch, ISCIMGatewayMapping mappings, IValueAdapter`2 valueAdapter, IEntitySchema schema)
at Unify.Product.IdentityBroker.SCIMProvider.d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.SystemForCrossDomainIdentityManagement.ProviderBase.d__45.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.SystemForCrossDomainIdentityManagement.ProviderAdapterTemplate`1.d__15.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.SystemForCrossDomainIdentityManagement.ControllerTemplate`1.d__5.MoveNext()",Normal
20220428,11:55:00,UNIFYBroker,Logging,Information,Healthcheck,Normal

Here's the Azure provision on demand output that corresponds to the error:

I can't work out why this happens for some user updates, but others go through just fine.  Since I can't packet trace the SCIM protocol in UNIFYConnect environment my ability to debug this is limited, and unfortunately right now I don't really have time to set up a non-UNIFYConnect test environment to debug what's going on.

The backing connector for the SCIM gateway is a PowerShell one, but the error appears to be occurring before it's even called.

I saw https://voice.unifysolutions.net/en/communities/6/topics/3913-sequence-contains-more-than-one-element for the same error, but I am running the latest of everything so the advice on that ticket (upgrade) didn't help.

Do you have any hints what might be going on to result in that error message?

I put through an update from Azure via SCIM which had two attributes changing at the same time, and the following error appeared in the UNIFYBroker log:

20220422,05:36:27,UNIFYBroker,SCIMGateway,Error,"Error during SCIM operation: System.InvalidOperationException: Sequence contains more than one element
at System.Linq.Enumerable.Single[TSource](IEnumerable`1 source)
at Unify.Product.IdentityBroker.SCIMProvider.Patch(IAdapterEntity adapterEntity, PatchRequest2 patch, ISCIMGatewayMapping mappings, IValueAdapter`2 valueAdapter, IEntitySchema schema)
at Unify.Product.IdentityBroker.SCIMProvider.d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.SystemForCrossDomainIdentityManagement.ProviderBase.d__45.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.SystemForCrossDomainIdentityManagement.ProviderAdapterTemplate`1.d__15.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.SystemForCrossDomainIdentityManagement.ControllerTemplate`1.d__5.MoveNext()",Normal

Here is the corresponding update from the Azure side:

As a possible complication for this ticket, the user involved previously didn't have a value for their employeeNumber field (which is a required/key field of the underlying connector) and that caused this error:

20220422,05:34:08,UNIFYBroker,An exception has occured in the AdapterEntityChangeDetectorCollator. Please see the exception for details,Error,"Npgsql:
System.InvalidOperationException: Parameter 'key1value0' must have its value set
at Npgsql.NpgsqlParameter.ResolveHandler(ConnectorTypeMapper typeMapper)
at Npgsql.NpgsqlParameter.Bind(ConnectorTypeMapper typeMapper)
at Npgsql.NpgsqlCommand.ValidateParameters()
at Npgsql.NpgsqlCommand.d__100.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Npgsql.NpgsqlCommand.d__92.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Npgsql.NpgsqlCommand.ExecuteNonQuery()
at Unify.Product.IdentityBroker.MultiKeyValueQueryExecutor`2.PopulateTempTable(NpgsqlConnection connection, NpgsqlTransaction transaction, IDictionary`2 tempKeyLookup, ValueToObjectAdapter adapter, IEnumerable`1 multiKeyValues, String tempTableName)
at Unify.Product.IdentityBroker.MultiKeyValueQueryExecutor`2.Execute(NpgsqlConnection connection, ValueToObjectAdapter adapter, Guid partitionId, IEnumerable`1 multiKeyValues, String tempTableName, String entityValueFieldName, String entityTableName, String partitionIdName, Func`2 readData)
at Unify.Product.IdentityBroker.KnownEntityPartitionPostgreSqlUpdatableContextBase`3.GetEntities(Guid partitionId, IEnumerable`1 keys)
at Unify.Product.IdentityBroker.EntityRepositoryExtensions.<>c__DisplayClass1_0.b__0(MultiKeyValue`1[] multiKeyValues)
at Unify.Product.IdentityBroker.EntityRepositoryExtensions.ConvertConnectorEntities(IEnumerable`1 connectorEntities, IMultiKey`1 schemaKey, Func`2 retrieveEntities, Guid connectorId, IEnumerable`1 wellKnownEntities)
at Unify.Product.IdentityBroker.EntityRepositoryExtensions.ConvertConnectorEntities(IEnumerable`1 connectorEntities, IMultiKey`1 schemaKey, IKnownEntityContextBase`3 context, Guid connectorId, IEnumerable`1 wellKnownEntities)
at Unify.Product.IdentityBroker.EntityChangeDetector.ProcessConnectorChangedEntities(Guid connectorId, IEnumerable`1 connectorEntities, IEnumerable`1 wellKnownItems)
at Unify.Product.IdentityBroker.AdapterEntityChangeDetectorCollator.DetectChanges(KeyValuePair`2 connectorEntities)
at Unify.Framework.Visitor.<>c__DisplayClass0_0`1.b__0(T item, Int32 index)
at Unify.Framework.Visitor.Visit[T](IEnumerable`1 visitCollection, Action`2 visitor)
at Unify.Product.IdentityBroker.AdapterEntityChangeDetectorCollator.Run()
at Unify.Framework.AsynchronousJobExecutor.PerformJobCallback(Object state)",Normal

Could you please investigate and fix the update error, and also consider improving the behaviour when a connector's required field is missing in a SCIM update?

For the purposes of my demo next week I can make sure this 'bad data' doesn't occur, and so the only dependency for this is SIT/UAT meaning that it's a medium priority.

I have a SCIM gateway configured in UNIFYConnect and Azure is able to use it to Add users just fine, but when it attempts an update this error is shown:

There's nothing written into the UNIFYBroker log when this happens.

Could you please investigate and advise how to make updates work?

The strangest thing ever... For this adapter:

When I generate changes to update the DNs (used to be DN=@IdBID), I see DNs assigned with different segment orders like this:

The two digit CN is DepartmentID.  The date CN is StartDate.  The four digit CN is PositionID.  The three letter CN is LocationID.  The six digit CN is EmployeeID.

I tried clearing precalculated entities and re-running Generate Changes, but the same thing happens with the newly generated entities - the segments are always in the same (wrong) order for each entity.

This is happening in a non-Production environment, and the DN segment order for each entity appears to be persistent, so this is a very minor (but very strange) issue.