0
Not a bug

Unable to write data to the transport connection

Bob Bradley 3 years ago in UNIFYBroker/Microsoft Active Directory updated by anonymous 3 years ago 3

The above exception was logged earlier this morning in the IdB log.  I only noticed this because the adapter was RED on the IdB dashboard during an export operation, and I decided to search the logs.  Initially my search for "exception" found nothing, but a subsequent search for "error" returned this from 3:25 am this morning:

Handling of LDAP change log request.
Handling of LDAP change log request from user MIM_IDBMA on connection 127.0.0.1:65355 failed with error "Unable to write data to the transport connection: An established connection was aborted by the software in your host machine.". Duration: 00:08:13.5165781.

I was actually following up on another older error from November, and otherwise would not have noticed this problem.  Interestingly there was evidence an hour earlier of a data inconsistency in the CORP AD forest which since seems to have been resolved (AD enforces uniqueness of UPN, so I can't understand how the IdB adapter could be complaining of duplicate DNs when the DN is derived from an enforced unique attribute - unless there is a timing issue due to the processing of deltas such that there is a problem after a rename until the next connector full import removes a duplicate):

Handling of LDAP change log request.
Handling of LDAP change log request from user MIM_IDBMA on connection 127.0.0.1:60870 failed with error "Found multiple entities with the distinguished name 'CN=servicio@pr.qbe.com,OU=LicensedUsers,DC=IdentityBroker'.". Duration: 00:00:01.2500019.

I am only speculating that this export error had something to do with the adapter integrity issue which appears to be due to a shortcoming of the delta processing logic.

I am also now wondering if this exception may be leading to others as a result of compromised integrity.

Extract from log as follows:

20170612,17:25:02,UNIFY Identity Broker,Adapter,Information,"Request to reflect change entities of the adapter.
Request to reflect change entities of the AAD User Licensing (03228c30-2401-41a9-9977-57a75423829c) adapter completed with 0 adds, 31 updates and 0 deletes across 1 pages. Duration: 00:05:07.2662214",Normal
20170612,17:25:02,UNIFY Identity Broker,LDAP engine,Error,"Handling of LDAP change log request.
Handling of LDAP change log request from user MIM_IDBMA on connection 127.0.0.1:65355 failed with error ""Unable to write data to the transport connection: An established connection was aborted by the software in your host machine."". Duration: 00:08:13.5165781.",Normal
20170612,17:25:02,UNIFY Identity Broker,LDAP engine,Information,"Handling of LDAP change log request.
Handling of LDAP change log request from user MIM_IDBMA on connection 127.0.0.1:65534 completed successfully. Added: 0. Modified: 0. Renamed: 0. Deleted: 1. Total: 1. Duration: 00:03:01.7347333.",Normal
20170612,17:25:03,UNIFY Identity Broker,Change detection engine,Information,"Change detection engine import changes started.
Change detection engine import changes for connector CORP AD Group started.",Normal
20170612,17:25:03,UNIFY Identity Broker,Connector,Information,"Request to import changes from connector.
Request to import changes from connector CORP AD Group.",Normal
20170612,17:25:03,UNIFY Identity Broker,Connector,Information,"Import changes from connector completed.
Import changes from connector CORP AD Group reported 0 changes. Duration: 00:00:00",Normal
20170612,17:25:03,UNIFY Identity Broker,Change detection engine,Information,"Change detection engine import changes completed.
Change detection engine import changes for connector CORP AD Group returned 0 possible changes. Duration: 00:00:00.5000092",Normal
20170612,17:25:05,UNIFY Identity Broker,Adapter,Information,"Request to reflect change entities of the adapter.
Request to reflect change entities of the AAD User Licensing (03228c30-2401-41a9-9977-57a75423829c) adapter completed with 0 adds, 21 updates and 0 deletes across 1 pages. Duration: 00:00:00.2967598",Normal

Using: UNIFY Identity Broker Management Studio, v5.0.5 Revision #0

Using Plugin:

Microsoft Active Directory5.0.1.2
Affected Versions:
Fixed by Version:

Answer

Answer
Under review

Hi Bob,

The error

Handling of LDAP change log request from user MIM_IDBMA on connection 127.0.0.1:65355 failed with error "Unable to write data to the transport connection: An established connection was aborted by the software in your host machine.". Duration: 00:08:13.5165781.

indicates that upon completing the handling of a changelog request, Identity Broker found that the LDAP connection was dropped by the client. Given that the duration of the operation is over 8 minutes, I'm assuming that this is exceeding your timeout.

The long duration could be caused by high activity on the Identity Broker server. You could try increasing the timeout, but if the issue is resolving itself (activity dropping and subsequent imports succeeding) then perhaps leaving the connections to timeout is the best solution to prevent the client blocking downstream processing during these busy periods.

I don't believe this is related to the duplicate DNs. Have you checked the entity context, from the UI or from SQL, to check for the duplicate DNs?

Answer
Under review

Hi Bob,

The error

Handling of LDAP change log request from user MIM_IDBMA on connection 127.0.0.1:65355 failed with error "Unable to write data to the transport connection: An established connection was aborted by the software in your host machine.". Duration: 00:08:13.5165781.

indicates that upon completing the handling of a changelog request, Identity Broker found that the LDAP connection was dropped by the client. Given that the duration of the operation is over 8 minutes, I'm assuming that this is exceeding your timeout.

The long duration could be caused by high activity on the Identity Broker server. You could try increasing the timeout, but if the issue is resolving itself (activity dropping and subsequent imports succeeding) then perhaps leaving the connections to timeout is the best solution to prevent the client blocking downstream processing during these busy periods.

I don't believe this is related to the duplicate DNs. Have you checked the entity context, from the UI or from SQL, to check for the duplicate DNs?

Thanks Curtis. In answer to your last question, yes - there is no longer a duplicate.  I saw evidence of this problem during the development phase (various issues still open in JIRA for the QBE project), and from experience I can confidently say

  1. there was NEVER really a duplicate UPN in AD at ANY time - this is a physical impossibility (AD will reject the attempted constraint violation)
  2. during a rename scenario such as the following you will end up with duplicate DNs in the adapter (definition CN=UPN,DC=IdentityBroker) if both are imported by a polling operation before a full connector import can be run:
    1. fred => fred1
    2. fred2 => fred