Skip to main content

NetApp_Insight_2020.png 

NetApp Knowledgebase

How to troubleshoot LDAP issues in Windows Active Directory

Views:
605
Visibility:
Public
Votes:
0
Category:
data-ontap-8
Specialty:
core
Last Updated:

Applies to

  • ONTAP 9
  • Clustered Data ONTAP 8

Description

For more detailed and up-to-date information about Active Directory LDAP and clustered Data ONTAP, please see TR-4073: Secure Unified Authentication.

When using LDAP in Cluster-Mode, the mhost process 'secd' is leveraged. This process is responsible for user authentication (name mapping). Issues occuring in name mapping get logged to the secd logs, located in the /mroot/etc/mlog file.

By default, name mapping failures do not get logged in the secd logs unless specified:

::*> diag secd trace set -node node-01 -module-names name-mapping -trace-all YES
Trace spec set successfully.

::*> diag secd trace show -node node-01
Trace Spec
---------------------------------------
TraceAll:                     Tracing all RPCs
Modules:                      NameMapping


This behavior was the same in Data ONTAP 7-Mode, where options cifs.trace_login has to be enabled to view trace match failures in the logs.

When a name mapping failure occurs, the following is seen:

Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |------------------------------------------------------------------------------
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |                                 TRACE MATCH                                  |
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |   RPC secd_rpc_map_name succeeded and is being dumped because of a tracing   |
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |                                  match on:                                   |
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |                                     All                                      |
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |                   RPC recevied at Thu Sep 15 16:55:38 2011                   |
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] |------------------------------------------------------------------------------'
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.032]  debug:  SecD RPC Server received RPC from MGMT.  RPC 351: secd_rpc_map_name  { in secd_prog_1() at server/secd_rpc_server.cpp:806 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.103]  debug:  Setting thread context. VServerId = 6, Protocol = NONE, lifId = 0  { in setThreadContext() at utils/secd_thread_data_manager.cpp:172 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.121]  debug:  secd_rpc_map_name_1_svc called with vserverid = 6  { in secd_rpc_map_name_1_svc() at name_mapping/secd_rpc_map_name.cpp:50 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.168]  debug:  Attempting to map name ldap using the cluster mapping store  { in getAppropriateWindowsToUnixMapping() at name_mapping/secd_name_mapping.cpp:385 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.207]  debug:  IDS_FROM_USER_NAME ldapInfoType requested.
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402]   { in getLdapInfoFromName() at authorization/secd_ldap_unix_authorization.cpp:552 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.239]  debug:  Looking for LDAP (NIS & Name Mapping) cache (key: "") in vserver 6  { in getConnectionCache() at connection_manager/secd_connection_cache.cpp:450 } 000000ad.0000150a 001db95a Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.255]  debug:  Looking for a connection to LDAP (NIS & Name Mapping)  { in getConnection() at connection_manager/secd_connection_manager.cpp:547 } 000000ad.0000150b 001db95a Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.268]  debug:  Acquiring a new LDAP (NIS & Name Mapping) connection; favoring cache  { in getBestConnection() at connection_manager/secd_connection_manager.cpp:716 } Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.282]  debug:  Did not find an available connection in the cache  { in getBestCachedConnection() at connection_manager/secd_connection_cache.cpp:224 } 000000ad.0000150d 001db95a Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.304]  debug:  Reserving a new LDAP (NIS & Name Mapping) server from discovery  { in getBestConnection() at connection_manager/secd_connection_manager.cpp:728 } 000000ad.0000150e 001db95a Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.324]  debug:  Created service key: 00000006..LDAP_NIS_AND_NAME_MAPPING  { in makeServiceKey() at server_discovery/secd_service_list.cpp:150 } Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.356]  debug:  Discovery returned 10.61.70.5 (10.61.70.5)  { in getBestConnection() at connection_manager/secd_connection_manager.cpp:743 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.000.377]  debug:  Connecting to LDAP (NIS & Name Mapping) server 10.61.70.5  { in addStartConnectionJournal() at connection_manager/secd_connection_manager.cpp:462 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.002.652]  debug:  Successfully authenticated over LDAP with 10.61.70.5  { in connect<LdapConnectionState>() at connection_manager/secd_connection.cpp:971 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.002.688]  debug:  Connected to new LDAP (NIS & Name Mapping) service on 10.61.70.5  { in makeConnectionAttempt() at connection_manager/secd_connection_manager.cpp:846 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.002.929]  debug:  Searching LDAP for the "uidNumber, gidNumber" attribute(s) within base "CN=users,DC=domain,DC=com" (scope: -1) using filter: (&(objectClass=User)(sAMAccountName=ldap))  { in searchLdap() at utils/secd_ldap_utils.cpp:200 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.352]  ERR  :  1057 in searchLdap() at utils/secd_ldap_utils.cpp:215
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.386]  ERR  :  searchLdap: LDAP Error: (80): 'Internal (implementation specific) error':
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.399]  ERR  :  1057 in getLdapInfoFromName() at authorization/secd_ldap_unix_authorization.cpp:652
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.465]  debug:  Closing service handle; reporting status 1  { in ~SecdConnection() at ../bedrock/obj/x86_64/secd/../../../export/common/headers/include/secd/secd_connection.h:106 }
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.488]  ERR  :  1057 in getIdsFromUserName() at authorization/secd_ldap_unix_authorization.cpp:139
Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.505]  warn :  Failed to get an ID for name ldap using UNIX authorization source LDAP, Error: 1057; ignoring; will try next source  { in handleNameAuthResult() at authorization/secd_unix_authorization.cpp:68 } 000000ad.0000151a 001db95a Thu Sep 15 2011 16:55:38 -04:00 [kern_secd:info:2402] | [000.003.575]  debug:  SecD RPC Server sending reply to RPC 351: secd_rpc_map_name  { in secdSendRpcResponse() at server/secd_rpc_server.cpp:1093 }


The name map traces convey the following:

  • The LDAP name mapping failure and the user being attempted
  • LDAP used to map users
  • Base DN used for searches
  • Attributes requested during the failure
  • Filter used
  • LDAP server contacted and if it connected properly
  • If the LDAP connection was cached or not
  • The vserver ID requested

 

CUSTOMER EXCLUSIVE CONTENT

Registered NetApp customers get unlimited access to our dynamic Knowledge Base.

New authoritative content is published and updated each day by our team of experts.

Current Customer or Partner?

Sign In for unlimited access

New to NetApp?

Learn more about our award-winning Support