- UNIFYNow Forum
-
Bugs
AD Listen operations faulting after upgrade to 4.0.0.0
An old problem now appears to be showing up whereby incoming AD operations show the listener momentarily as Running and then Faulted.
I have the AD agent service account configured as svcFIM_MA@client.local instead of client\svcFIM_MA, since this format was previously discovered as necessary to ensure that the listener works properly (as it is in PROD with v3.2.1.3).
Listen Operation - Live Active Directory Listen
However with 4.0.0.0 and the same account configuration, I am now seeing this in both UAT and DEV (for both AD listeners and one of the ADLDS listeners):
Listen Operation - Faulted Active Directory Listen
I have been able to get the UAT ADLDS listener working (no idea why), but not the others.
I have tried changing the agent settings to various combinations of server settings, but to no avail, e.g.
D-OCCCP-DC201:389
D-OCCCP-DC202:389
D-OCCCP-DC201.client.local:389
D-OCCCP-DC202.client.local:389
I am using the SECURE authentication setting with the username svcFIM_MA@client.local (as was configured and working previously under v3.2.1.3)
Answer
Error reported in logs as follows:
OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local:389 [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]) System.DirectoryServices.Protocols:
System.DirectoryServices.Protocols.DirectoryOperationException: The server cannot handle directory requests.
at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult)
at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result)
I am unable to reproduce - it works for me with both the domain format and FQDN. Thankfully you have been able to reproduce so we should be able to come up with the solution.
What is strange is that the logic should be the same for the @ formatted username across both versions. So I'm not sure why it would stop working in v4.0.
I've updated Unify.EventBroker.PlugIn.AD.dll to split on the @ symbol, however, so that it actually places the domain in the correct place for the connection. The thing that I'm not sure about is whether I should strip away the local part of the domain, but that can be the next version if this one fails. You could also attempt the operation using FQDN.
Thanks.
Patch deployed in both DEV and UAT as specified - but continues to fail:
OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local:389 [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]) System.DirectoryServices.Protocols:
System.DirectoryServices.Protocols.DirectoryOperationException: The server cannot handle directory requests.
at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult)
at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result)
Config:
D-OCCCP-DC201.client.local:389
D-OCCCP-DC202.client.local:389
Any luck with FQDN? Also, are you in a position to trace the bind to make sure the right thing is being done?
The traces look fine in all three cases and the search request was issued immediately after - indicating that the bind was successful. Could you please confirm that the listen operation works on the same server using v3.2?
Hi Bob
The Faulted status is a new addition to v4.0, and was implemented as a fix to an issue where an operation was throwing an exception but reporting Live on the UI. Can you confirm for me that the listen operation is actually working in v3.2 and not just saying it is incorrectly? The exception should still be logged the same in both version, so checking the v3.2 logs for the System.DirectoryServices.Protocols.DirectoryOperationException: The server cannot handle directory requests error would be the quickest test.
Another thing I've found is a hotfix for an unrelated Microsoft AD library which fixes an issue caused by fast bind mode that also resulted in the above exception. Would the AD agent have FastBind set as a custom authentication option? Try unselecting it if it is selected.
Beau - I don't know where you got that info about FAULTED status before - have you checked out the JIRA ticket I cross referenced above? I was only able to close this ticket for a v3.2.1 implementation after I managed to get the LIVE status showing, and this 100% corresponded to the ceasing of the continuous DirectoryOperationException events.
https://unifysolutions.jira.com/browse/CSODBB-474
So ... I was getting a FAULTED status prior to resolving 474. A fix??? :)
Now in PROD (where we still have 3.2.1 I do have instances of the "The server cannot handle directory requests" error, but only once per day (not once every 30 seconds!). The related ticket for this is http://voice.unifysolutions.net/topics/3239-the-ldap-server-is-unavailable-ldapexception-cannot-be-identified/
Incidentally, the very reason I am upgrading to version 4 is to eliminate separate corresponding daily events at this time: http://voice.unifysolutions.net/topics/2447-the-trigger-for-operation-list-with-id-xxx-has-failed-to-attached-with-the-message-the-supplied/
I tried the FASTBIND suggestion, but this too shows a status of FAULTED - same results in logs:
OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]) System.DirectoryServices.Protocols: System.DirectoryServices.Protocols.DirectoryOperationException: An operation error occurred. at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult) at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result)
Product Group no longer have access to Jira issues. Any relevant information will have to be included in the Voice ticket.
The exception with FastBind off is actually slightly different, although of the same type and raised at the same location. Can you provided a new network trace? I'd like to see what's different compared to when fastbind was on.
On the topic of your traces, the ones you've provided so far have been strange in that the LDAP requests are captured yet the responses are not. This makes it difficult for us as it's literally only half the information. Would there be any environmental reason you could think of that would be interfering? Also, if you're not capturing with either Wireshark or rawcap could try using one of them, instead?
No chance to run a trace as yet, but the log entries produced by the DLL appear here:
20170817,03:21:14,UNIFY MIM Event Broker,Logging Engine,Information,Log file started.,Minimal
20170817,03:21:14,UNIFY MIM Event Broker,OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]),Error,":
System.Exception: ID: NULL | ResponseErrorMessage: 000004DC: LdapErr: DSID-0C0907C2, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v2580 | ResultCode: OperationsError | Controls: | MatchedDN: | ReferalUrls: ---> System.DirectoryServices.Protocols.DirectoryOperationException: An operation error occurred.
at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult)
at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result)
--- End of inner exception stack trace ---",Normal
20170817,03:21:34,UNIFY MIM Event Broker,Operations,Information,The operation list of name FIM Agent PHRIS Outgoing with id 62f66e30-0f54-4557-ab72-ff9b09484715 cannot be run due a conflict with the group.,Normal
20170817,03:21:58,UNIFY MIM Event Broker,OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]),Error,":
System.Exception: ID: NULL | ResponseErrorMessage: 000004DC: LdapErr: DSID-0C0907C2, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v2580 | ResultCode: OperationsError | Controls: | MatchedDN: | ReferalUrls: ---> System.DirectoryServices.Protocols.DirectoryOperationException: An operation error occurred.
at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult)
at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result)
--- End of inner exception stack trace ---",Normal
Log entry when I changed from FastBind to the SECURE option I was using successfully in v3.2.1.3:
20170817,03:25:33,UNIFY MIM Event Broker,OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]),Error,": System.Exception: ID: NULL | ResponseErrorMessage: 000020B9: SvcErr: DSID-0311052E, problem 5003 (WILL_NOT_PERFORM), data 0 | ResultCode: UnwillingToPerform | Controls: | MatchedDN: | ReferalUrls: ---> System.DirectoryServices.Protocols.DirectoryOperationException: The server cannot handle directory requests. at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult) at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result) --- End of inner exception stack trace ---",Normal
And finally BASIC:
20170817,03:27:42,UNIFY MIM Event Broker,OpenLDAPTriggerPlugIn.ResultsCallback.Error (D-OCCCP-DC201.dbb.local [51a5cde2-681b-4329-8da8-d9a0e2b4fceb]),Error,": System.Exception: ID: NULL | ResponseErrorMessage: 000020B9: SvcErr: DSID-0311052E, problem 5003 (WILL_NOT_PERFORM), data 0 | ResultCode: UnwillingToPerform | Controls: | MatchedDN: | ReferalUrls: ---> System.DirectoryServices.Protocols.DirectoryOperationException: The server cannot handle directory requests. at System.DirectoryServices.Protocols.LdapPartialResultsProcessor.GetPartialResults(LdapPartialAsyncResult asyncResult) at Unify.Product.EventBroker.OpenLDAPListenPlugIn.ResultsCallback(IAsyncResult result) --- End of inner exception stack trace ---",Normal
Now using SECURE with the DBB\svcFIM_MA credential format (instead of the correct svcFIM_MA@dbb.local UPN style format):
20170817,03:29:26,UNIFY MIM Event Broker,Operation List Executor Sink,Error,"The trigger for operation list with id 51a5cde2-681b-4329-8da8-d9a0e2b4fceb has failed to attached with the message The supplied credential is invalid.. System.DirectoryServices.Protocols.LdapException: The supplied credential is invalid. at System.DirectoryServices.Protocols.LdapConnection.BindHelper(NetworkCredential newCredential, Boolean needSetCredential) at System.DirectoryServices.Protocols.LdapConnection.SendRequestHelper(DirectoryRequest request, Int32& messageID) at System.DirectoryServices.Protocols.LdapConnection.BeginSendRequest(DirectoryRequest request, TimeSpan requestTimeout, PartialResultProcessing partialMode, AsyncCallback callback, Object state) at Unify.Product.EventBroker.OpenLDAPListenPlugIn.AttachTrigger(IListenOperationInformation listenOperationInformation) at Unify.EventBroker.PlugIn.Audit.ListenOperationAuditingDecorator.AttachTrigger(IListenOperationInformation listenOperationInformation) at Unify.Product.EventBroker.OperationListExecutorSink.RecycleListenOperation(IListenOperationFactoryInformation operationInformation)",Normal
Note that if the credential really WAS invalid then the agents page would show an error (as it does when I deliberately put in the wrong password) - but there is no error:
20170817,03:29:26,UNIFY MIM Event Broker,Operation List Executor Sink,Error,"The trigger for operation list with id 51a5cde2-681b-4329-8da8-d9a0e2b4fceb has failed to attached with the message The supplied credential is invalid.. System.DirectoryServices.Protocols.LdapException: The supplied credential is invalid. at System.DirectoryServices.Protocols.LdapConnection.BindHelper(NetworkCredential newCredential, Boolean needSetCredential) at System.DirectoryServices.Protocols.LdapConnection.SendRequestHelper(DirectoryRequest request, Int32& messageID) at System.DirectoryServices.Protocols.LdapConnection.BeginSendRequest(DirectoryRequest request, TimeSpan requestTimeout, PartialResultProcessing partialMode, AsyncCallback callback, Object state) at Unify.Product.EventBroker.OpenLDAPListenPlugIn.AttachTrigger(IListenOperationInformation listenOperationInformation) at Unify.EventBroker.PlugIn.Audit.ListenOperationAuditingDecorator.AttachTrigger(IListenOperationInformation listenOperationInformation) at Unify.Product.EventBroker.OperationListExecutorSink.RecycleListenOperation(IListenOperationFactoryInformation operationInformation)",Normal
Hi Bob,
We've finally figured out what going on and I even managed to reproduce it locally. Turns out the LDAP persistent search feature the listener uses has a hard restriction on the filter that can be used. Only (objectClass=*) is valid. When you get back to this issue, try changing the filter to the default value.
https://msdn.microsoft.com/en-us/library/aa366983(v=vs.85).aspx
Authentication method and username format appear to be unrelated.
Thanks Beau - I can confirm that this indeed fixed the issue in both DEV and UAT - shows LIVE now in both cases. I suggest the guidance needs to be updated - the hint on the field says "e.g. (objectClass=*)" but we need something more forceful now I think - i.e. don't give people the option to put in an invalid query.
Agreed. There doesn't seem to be any other valid filter so there is no reason for that configuration to exist. I've created a work item to remove it.
Customer support service by UserEcho
Hi Bob,
We've finally figured out what going on and I even managed to reproduce it locally. Turns out the LDAP persistent search feature the listener uses has a hard restriction on the filter that can be used. Only
(objectClass=*)is valid. When you get back to this issue, try changing the filter to the default value.https://msdn.microsoft.com/en-us/library/aa366983(v=vs.85).aspx
Authentication method and username format appear to be unrelated.