Hi everyone,

I am trying to set up Windows-to-Unix mapping by following this reference as a guideline:

(I am using the MS-AD-BIS schema available in ONTAP 9  rather than copying and modifying RFC-2307).

We are using ONTAP 9.1P8.

secd throws up this error: RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND followed by RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR, which I cannot match to any information on the support site.

show-creds works for a Windows account (apart from the fact that the account is mapped to pcuser) and shows the Windows group memberships:

cluster::*> diag secd authentication show-creds -node cluster-01 -vserver nfscorpprd01 -win-name PROD\johndoe

 UNIX UID: pcuser <> Windows User: PROD\johndoe (Windows Domain User)

 GID: pcuser
 Supplementary GIDs (partial):
  pcuser

 Windows Membership:
  PROD\UX_domain_group_1 (Windows Domain group)
...
(snipped) 
...


When trying to map the user to a Unix name, this fails:

cluster::*> diag secd name-mapping show -node cluster-01 -vserver nfscorpprd01 -direction win-unix -name PROD\johndoe

ATTENTION: Mapping of Data ONTAP "admin" users to UNIX user "root" is enabled, but the following information does not reflect this mapping.

'PROD\johndoe' maps to 'pcuser'



cluster::*> diag secd authentication show-creds -node cluster-01 -vserver nfscorpprd01 -unix-user-name johndoe

Vserver: nfscorpprd01 (internal ID: 6)

Error: Acquire UNIX credentials procedure failed
  [ 13 ms] Successfully connected to ip 172.16.42.71, port 389 using
           TCP
  [    16] Entry for user-name: johndoe not found in the current
           source: LDAP. Ignoring and trying next available source
  [    16] Entry for user-name: johndoe not found in the current
           source: FILES. Entry for user-name: johndoe not found in
           any of the available sources
**[    16] FAILURE: Unable to retrieve UID for UNIX user johndoe

Error: command failed: Failed to resolve user name to a UNIX ID. Reason: "SecD
       Error: libc returned a transient error.  Please look at the journal for
       detail".

Some info on our configuration:

cluster::*> ldap show -vserver nfscorpprd01

                         Vserver: nfscorpprd01
       LDAP Client Configuration: CORP_PRD
(DEPRECATED)-LDAP Client Enabled: true 
 

cluster::*> vserver services ldap client show -vserver nfscorpprd01 -instance

                                  Vserver: nfscorpprd01
                Client Configuration Name: CORP_PRD
                         LDAP Server List: -
                  Active Directory Domain: prod.justacompany.be
       Preferred Active Directory Servers: -
Bind Using the Vserver's CIFS Credentials: true
                          Schema Template: MS-AD-BIS
                         LDAP Server Port: 389
                      Query Timeout (sec): 3
        Minimum Bind Authentication Level: simple
                           Bind DN (User): CN=janedoe_binduser,OU=Common,OU=Users,OU=NPRD,OU=CORP,OU=POSIX,OU=UNIX,DC=prod,DC=justacompany,DC=be
                                  Base DN: DC=prod,DC=justacompany,DC=be
                        Base Search Scope: subtree
                                  User DN: -
                        User Search Scope: subtree
                                 Group DN: -
                       Group Search Scope: subtree
                              Netgroup DN: -
                    Netgroup Search Scope: subtree
               Vserver Owns Configuration: true
      Use start-tls Over LDAP Connections: false
           Enable Netgroup-By-Host Lookup: false
                      Netgroup-By-Host DN: -
                   Netgroup-By-Host Scope: subtree
                  Client Session Security: none

(I also tried with a bind without using the vserver's CIFS credentials, to no avail).               
                 

A packet trace reveals a successful SASL bind, but then the connection gets closed and nothing else happens, no actual  LDAP lookups/queries.

Note: I am also unable to query LDAP successfully using getxxbyyy queries (users or groups).

I have included secd debugging output, which is probably the most useful information at this point. I think things go wrong when the RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND errors are logged.

Does anyone have any idea what I am doing wrong ?

Thanks in advance.

secd debugging output:

00000970.00027039 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] .------------------------------------------------------------------------------.
00000970.0002703a 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |                                 RPC FAILURE:                                 |
00000970.0002703b 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |                   secd_rpc_auth_user_name_to_id has failed                   |
00000970.0002703d 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |                        Result = 0, RPC Result = 7035                         |
00000970.0002703e 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |                   RPC received at Wed Oct  4 14:07:43 2017                   |
00000970.0002703f 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |------------------------------------------------------------------------------'
00000970.00027040 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] Failure Summary:
00000970.00027041 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] Error: Acquire UNIX credentials procedure failed
00000970.00027042 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969]   [ 25 ms] Successfully connected to ip 172.16.42.71, port 389 using TCP
00000970.00027043 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969]   [    28] Entry for user-name: johndoe not found in the current source: LDAP. Ignoring and trying next available source
00000970.00027044 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969]   [    29] Entry for user-name: johndoe not found in the current source: FILES. Entry for user-name: johndoe not found in any of the available sources
00000970.00027045 01710074 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] **[    29] FAILURE: Unable to retrieve UID for UNIX user johndoe
00000970.00027046 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] Details:
00000970.00027047 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.032]  debug:  Worker Thread 34638696960 processing RPC 205:secd_rpc_auth_user_name_to_id with request ID:28849 which sat in the queue for 0 seconds.  { in run() at src/server/secd_rpc_server.cpp:2067 }
00000970.00027048 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.072]  debug:  Setting thread context. VServerId = 6 (name='nfscorpprd01'), Protocol = NONE, lifId = 0  { in setThreadContext() at src/utils/secd_thread_data_manager.cpp:411 }
00000970.00027049 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.089]  debug:  secd_rpc_auth_user_name_to_id_1_svc called with vserverid = 6  { in secd_rpc_auth_user_name_to_id_1_svc() at src/authorization/secd_rpc_authorization.cpp:1193 }
00000970.0002704a 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.099]  debug:  lookup for username: johndoe  { in secd_rpc_auth_user_name_to_id_1_svc() at src/authorization/secd_rpc_authorization.cpp:1198 }
00000970.0002704b 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.108]  debug:  Get UserId for UserName = johndoe  { in getUidFromUserNameViaLibc() at src/authorization/secd_unix_authorization.cpp:601 }
00000970.0002704c 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.119]  debug:  Calling lookupNameServicesUserCaches()  { in _getUserPasswdInfo() at src/authorization/secd_unix_authorization.cpp:1081 }
00000970.0002704d 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.126]  debug:  User Info from User Name = johndoe requested  { in lookupNameServicesUserCaches() at src/authorization/secd_unix_authorization.cpp:796 }
00000970.0002704e 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.132]  debug:  looking up userNameToInfoCache for User Name johndoe  { in lookupNameServicesUserCaches() at src/authorization/secd_unix_authorization.cpp:804 }
00000970.0002704f 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.140]  debug:  Info not in cache. Calling libc  { in _getUserPasswdInfo() at src/authorization/secd_unix_authorization.cpp:1090 }
00000970.00027050 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.000.152]  debug:  Calling getpwnam_r(), user name = johndoe  { in getUserInfoViaLibC() at src/utils/secd_ns_utils.cpp:435 }
00000970.00027051 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.659]  debug:  Calling ldapGetPasswd  { in SecdCbNsLdapQuery() at src/authorization/secd_rpc_authorization.cpp:3414 }
00000970.00027052 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.668]  debug:  ldapGetPasswd called with vserverId=6  { in ldapGetPasswd() at src/authorization/secd_rpc_authorization.cpp:3015 }
00000970.00027053 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.676]  debug:  getPasswdInfoFromLdap called with info type PASSWD_INFO_FROM_USER_NAME  { in getPasswdInfoFromLdap() at src/authorization/secd_rpc_authorization.cpp:2611 }
00000970.00027054 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.695]  debug:  getPasswdInfoFromLdap called with info type PASSWD_INFO_FROM_USER_NAME with userName johndoe  { in getPasswdInfoFromLdap() at src/authorization/secd_rpc_authorization.cpp:2618 }
00000970.00027055 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.703]  debug:  LDAP User Info from User Name = johndoe requested.  { in getLdapUserInfo() at src/authorization/secd_ldap_unix_authorization.cpp:2251 }
00000970.00027056 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.724]  debug:  Looking for LDAP (NIS & Name Mapping) cache (key: "") in vserver 6  { in getConnectionCache() at src/connection_manager/secd_connection_cache.cpp:616 }
00000970.00027057 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.762]  debug:  Looking for a connection to LDAP (NIS & Name Mapping)  { in getConnection() at src/connection_manager/secd_connection_manager.cpp:644 }
00000970.00027058 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.774]  debug:  Acquiring a new LDAP (NIS & Name Mapping) connection; favoring cache  { in getBestConnection() at src/connection_manager/secd_connection_manager.cpp:849 }
00000970.00027059 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.781]  debug:  Did not find an available connection in the cache  { in getBestCachedConnection() at src/connection_manager/secd_connection_cache.cpp:355 }
00000970.0002705a 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.788]  debug:  Reserving a new LDAP (NIS & Name Mapping) server from discovery  { in getBestConnection() at src/connection_manager/secd_connection_manager.cpp:866 }
00000970.0002705b 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.814]  debug:  Created service key: 00000006..LDAP_NIS_AND_NAME_MAPPING  { in makeServiceKey() at src/server_discovery/secd_service_list.cpp:182 }
00000970.0002705c 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.001.835]  debug:  Created service key: 00000006..LDAP_NIS_AND_NAME_MAPPING  { in makeServiceKey() at src/server_discovery/secd_service_list.cpp:182 }
00000970.0002705d 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.006.693]  debug:  Vserver's operational state: running  { in isVserverRunning() at src/configuration_manager/secd_configuration_manager.cpp:2753 }
00000970.0002705e 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.006.709]  debug:  Got serviceName : _ldap._tcp.Justacity._sites.prod.justacompany.be  { in parseServiceName() at src/server_discovery/secd_service_utilities.cpp:660 }
00000970.0002705f 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.006.726]  debug:  NSLIBC: get_state(), ../../../../../lib/libc/netapp/ns_res_state.c:204, Vsid = 6 Adding entry for VSID: 6
00000970.00027060 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.007.356]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.00027061 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.010.731]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.00027062 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.010.761]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying _ldap._tcp.Justacity._sites.prod.justacompany.be
00000970.00027063 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.010.840]  debug:  Dns name lookup for nameType: 1, hostName: prod452.prod.justacompany.be  { in DnsNameLookupViaLibC() at src/server_discovery/secd_service_utilities.cpp:435 }
00000970.00027064 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.011.409]  debug:  NSLIBC: format_and_add_journal(), ../../../../../lib/libc/netapp/ns_journal.c:248, Vsid = 6 Entry for host-name: prod452.prod.justacompany.be not found in the current source: FILES. Ignoring and trying next available source
00000970.00027065 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.011.532]  debug:  NSLIBC: is_res_init_needed(), ../../../../../lib/libc/netapp/ns_res_state.c:41, Vsid = 6 Not Initing. statp->options & RES_INIT = 1,statp->options & RES_STAYOPEN = 0, statp->vsid = 6, vcontext = 6,statp->conf_file_time = 1506698952, st.st_mtime = 1506698952
00000970.00027066 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.011.568]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.00027067 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.017]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.00027068 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.047]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying prod452.prod.justacompany.be
00000970.00027069 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.129]  debug:  Dns name lookup for nameType: 1, hostName: justaserver.prod.justacompany.be  { in DnsNameLookupViaLibC() at src/server_discovery/secd_service_utilities.cpp:435 }
00000970.0002706a 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.331]  debug:  NSLIBC: format_and_add_journal(), ../../../../../lib/libc/netapp/ns_journal.c:248, Vsid = 6 Entry for host-name: justaserver.prod.justacompany.be not found in the current source: FILES. Ignoring and trying next available source
00000970.0002706b 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.383]  debug:  NSLIBC: is_res_init_needed(), ../../../../../lib/libc/netapp/ns_res_state.c:41, Vsid = 6 Not Initing. statp->options & RES_INIT = 1,statp->options & RES_STAYOPEN = 0, statp->vsid = 6, vcontext = 6,statp->conf_file_time = 1506698952, st.st_mtime = 1506698952
00000970.0002706c 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.414]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.0002706d 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.863]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.0002706e 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.885]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying justaserver.prod.justacompany.be
00000970.0002706f 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.957]  debug:  Service discovery returned 2 servers  { in DnsServiceLookupViaLibc() at src/server_discovery/secd_service_utilities.cpp:621 }
00000970.00027070 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.980]  debug:  ***Adding server with ip: 172.16.42.72, nameLowercase: prod452.prod.justacompany.be, pref: 2, service: LDAP_NIS_AND_NAME_MAPPING  { in addDiscoveredServer() at src/server_discovery/secd_service_list.cpp:711 }
00000970.00027071 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.012.998]  debug:  ***Adding server with ip: 172.16.42.71, nameLowercase: justaserver.prod.justacompany.be, pref: 2, service: LDAP_NIS_AND_NAME_MAPPING  { in addDiscoveredServer() at src/server_discovery/secd_service_list.cpp:711 }
00000970.00027072 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.017.387]  debug:  Vserver's operational state: running  { in isVserverRunning() at src/configuration_manager/secd_configuration_manager.cpp:2753 }
00000970.00027073 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.017.401]  debug:  Got serviceName : _ldap._tcp.prod.justacompany.be  { in parseServiceName() at src/server_discovery/secd_service_utilities.cpp:660 }
00000970.00027074 01710075 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.017.700]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.00027075 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.018.217]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.00027076 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.018.245]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying _ldap._tcp.prod.justacompany.be
00000970.00027077 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.018.317]  debug:  Dns name lookup for nameType: 1, hostName: justaserver.prod.justacompany.be  { in DnsNameLookupViaLibC() at src/server_discovery/secd_service_utilities.cpp:435 }
00000970.00027078 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.018.554]  debug:  NSLIBC: format_and_add_journal(), ../../../../../lib/libc/netapp/ns_journal.c:248, Vsid = 6 Entry for host-name: justaserver.prod.justacompany.be not found in the current source: FILES. Ignoring and trying next available source
00000970.00027079 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.018.612]  debug:  NSLIBC: is_res_init_needed(), ../../../../../lib/libc/netapp/ns_res_state.c:41, Vsid = 6 Not Initing. statp->options & RES_INIT = 1,statp->options & RES_STAYOPEN = 0, statp->vsid = 6, vcontext = 6,statp->conf_file_time = 1506698952, st.st_mtime = 1506698952
00000970.0002707a 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.018.643]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.0002707b 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.126]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.0002707c 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.148]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying justaserver.prod.justacompany.be
00000970.0002707d 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.227]  debug:  Dns name lookup for nameType: 1, hostName: prod452.prod.justacompany.be  { in DnsNameLookupViaLibC() at src/server_discovery/secd_service_utilities.cpp:435 }
00000970.0002707e 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.431]  debug:  NSLIBC: format_and_add_journal(), ../../../../../lib/libc/netapp/ns_journal.c:248, Vsid = 6 Entry for host-name: prod452.prod.justacompany.be not found in the current source: FILES. Ignoring and trying next available source
00000970.0002707f 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.483]  debug:  NSLIBC: is_res_init_needed(), ../../../../../lib/libc/netapp/ns_res_state.c:41, Vsid = 6 Not Initing. statp->options & RES_INIT = 1,statp->options & RES_STAYOPEN = 0, statp->vsid = 6, vcontext = 6,statp->conf_file_time = 1506698952, st.st_mtime = 1506698952
00000970.00027080 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.514]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.00027081 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.019.988]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.00027082 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.011]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying prod452.prod.justacompany.be
00000970.00027083 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.083]  debug:  Dns name lookup for nameType: 1, hostName: prod454.prod.justacompany.be  { in DnsNameLookupViaLibC() at src/server_discovery/secd_service_utilities.cpp:435 }
00000970.00027084 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.283]  debug:  NSLIBC: format_and_add_journal(), ../../../../../lib/libc/netapp/ns_journal.c:248, Vsid = 6 Entry for host-name: prod454.prod.justacompany.be not found in the current source: FILES. Ignoring and trying next available source
00000970.00027085 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.334]  debug:  NSLIBC: is_res_init_needed(), ../../../../../lib/libc/netapp/ns_res_state.c:41, Vsid = 6 Not Initing. statp->options & RES_INIT = 1,statp->options & RES_STAYOPEN = 0, statp->vsid = 6, vcontext = 6,statp->conf_file_time = 1506698952, st.st_mtime = 1506698952
00000970.00027086 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.365]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.00027087 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.819]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.00027088 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.856]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying prod454.prod.justacompany.be
00000970.00027089 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.020.938]  debug:  Dns name lookup for nameType: 1, hostName: prod453.prod.justacompany.be  { in DnsNameLookupViaLibC() at src/server_discovery/secd_service_utilities.cpp:435 }
00000970.0002708a 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.149]  debug:  NSLIBC: format_and_add_journal(), ../../../../../lib/libc/netapp/ns_journal.c:248, Vsid = 6 Entry for host-name: prod453.prod.justacompany.be not found in the current source: FILES. Ignoring and trying next available source
00000970.0002708b 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.204]  debug:  NSLIBC: is_res_init_needed(), ../../../../../lib/libc/netapp/ns_res_state.c:41, Vsid = 6 Not Initing. statp->options & RES_INIT = 1,statp->options & RES_STAYOPEN = 0, statp->vsid = 6, vcontext = 6,statp->conf_file_time = 1506698952, st.st_mtime = 1506698952
00000970.0002708c 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.233]  debug:  CM_STATS:  Skipping stats for connect() to 172.16.46.10 with port 53 (DNS): not a SecD initiated conn  { in isConnInfoValidForStats() at src/cm/secd_cm_stats_manager.cpp:828 }
00000970.0002708d 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.599]  debug:  NSLIBC: __res_nsend(), ../../../../../lib/libc/resolv/res_send.c:828, Vsid = 6 Connected to 172.16.46.10 for DNS
00000970.0002708e 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.620]  debug:  NSLIBC: log_rcode_and_update_stats(), ../../../../../lib/libc/resolv/res_send.c:485, Vsid = 6 Rcode received from the DNS server(172.16.46.10): 0 when querying prod453.prod.justacompany.be
00000970.0002708f 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.691]  debug:  Service discovery returned 4 servers  { in DnsServiceLookupViaLibc() at src/server_discovery/secd_service_utilities.cpp:621 }
00000970.00027090 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.720]  debug:  ***Adding server with ip: 172.16.42.133, nameLowercase: prod454.prod.justacompany.be, pref: 3, service: LDAP_NIS_AND_NAME_MAPPING  { in addDiscoveredServer() at src/server_discovery/secd_service_list.cpp:711 }
00000970.00027091 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.736]  debug:  ***Adding server with ip: 172.16.42.132, nameLowercase: prod453.prod.justacompany.be, pref: 3, service: LDAP_NIS_AND_NAME_MAPPING  { in addDiscoveredServer() at src/server_discovery/secd_service_list.cpp:711 }
00000970.00027092 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.764]  debug:  Created service key: 00000006..LDAP_NIS_AND_NAME_MAPPING  { in makeServiceKey() at src/server_discovery/secd_service_list.cpp:182 }
00000970.00027093 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.809]  debug:  Discovery returned justaserver.prod.justacompany.be (172.16.42.71)  { in getBestConnection() at src/connection_manager/secd_connection_manager.cpp:904 }
00000970.00027094 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.825]  debug:  Connecting to LDAP (NIS & Name Mapping) server justaserver.prod.justacompany.be (172.16.42.71)  { in addStartConnectionLog() at src/connection_manager/secd_connection_manager.cpp:551 }
00000970.00027095 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.948]  debug:  Attemping a SASL bind as "NFSCORPPRD01$@PROD.JUSTACOMPANY.BE"  { in ldapSaslBind() at src/connection_manager/secd_connection.cpp:822 }
00000970.00027096 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.021.966]  debug:  LDAP security level is NONE, attempting bind using SPNEGO  { in ldapSaslBind() at src/connection_manager/secd_connection.cpp:876 }
00000970.00027097 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.024.258]  debug:  Found matching cache 'cc:C:6:0'  { in secd_ccache_resolve() at src/utils/secd_krb_ccache.cpp:897 }
00000970.00027098 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.025.176]  info :  [krb5 context 10B23600] Getting credentials NFSCORPPRD01$@PROD.JUSTACOMPANY.BE -> cifs/justaserver.prod.justacompany.be@ using ccache NETAPPCC:cc:C:6:0
00000970.00027099 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.025.194]  debug:  Found matching cache 'cc:C:6:0'  { in secd_ccache_resolve() at src/utils/secd_krb_ccache.cpp:897 }
00000970.0002709a 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.025.247]  info :  [krb5 context 10B23600] Retrieving NFSCORPPRD01$@PROD.JUSTACOMPANY.BE -> cifs/justaserver.prod.justacompany.be@ from NETAPPCC:cc:C:6:0 with result: 0/Unknown code 0
00000970.0002709b 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.025.316]  info :  [krb5 context 10B23600] Creating authenticator for NFSCORPPRD01$@PROD.JUSTACOMPANY.BE -> cifs/justaserver.prod.justacompany.be@, seqnum 227739542, subkey aes256-cts/FBF9, session key aes256-cts/F40B
00000970.0002709c 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.025.590]  debug:  CM_STATS:  Tracking connect() to server 172.16.42.71, port 389  { in startConnectTracking() at src/cm/secd_cm_stats_manager.cpp:863 }
00000970.0002709d 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.025.832]  info :  Successfully connected to ip 172.16.42.71, port 389 using TCP { in _connect() at src/connection_manager/secd_connection_shim.cpp:317 }
00000970.0002709e 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.026.676]  info :  [krb5 context 10B23600] Read AP-REP, time 1507118863.924740, subkey aes256-cts/1D80, seqnum 474173867
00000970.0002709f 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.609]  debug:  Successfully authenticated over LDAP with justaserver.prod.justacompany.be  { in connect() at src/connection_manager/secd_connection.cpp:1888 }
00000970.000270a0 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.623]  debug:  Connected to new LDAP (NIS & Name Mapping) service on justaserver.prod.justacompany.be  { in makeConnectionAttempt() at src/connection_manager/secd_connection_manager.cpp:1020 }
00000970.000270a1 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.714]  ERR  :  RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND:6943 in query() at src/configuration_manager/secd_configuration_sources.cpp:3936
00000970.000270a2 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.729]  ERR  :  RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND:6943 in getLdapSearchDetails() at src/configuration_manager/secd_configuration_manager.cpp:1171
00000970.000270a3 01710076 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.741]  ERR  :  RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND:6943 in getLdapUserInfo() at src/authorization/secd_ldap_unix_authorization.cpp:2296
00000970.000270a4 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.812]  debug:  Closing service handle; reporting status 1  { in ~SecdConnection() at src/include/secd_connection.h:118 }
00000970.000270a5 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.830]  ERR  :  Failed to get user info for name johndoe  { in getPasswdInfoFromLdap() at src/authorization/secd_rpc_authorization.cpp:2638 }
00000970.000270a6 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.837]  ERR  :  RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND:6943 in getPasswdInfoFromLdap() at src/authorization/secd_rpc_authorization.cpp:2640
00000970.000270a7 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.846]  ERR  :  RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND:6943 in ldapGetPasswd() at src/authorization/secd_rpc_authorization.cpp:3018
00000970.000270a8 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.855]  ERR  :  RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND:6943 in SecdCbNsLdapQuery() at src/authorization/secd_rpc_authorization.cpp:3415
00000970.000270a9 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.865]  debug:  NSLIBC: ldap_match(), ../../../../../lib/libc/netapp/ldap_secd.c:1161, Vsid = 6 secd RPC SECD_LDAP_PASSWD_PROC returned 6943
00000970.000270aa 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.872]  ERR  :  NSLIBC: map_secd_err_to_retval(), ../../../../../lib/libc/netapp/ldap_secd.c:485, Vsid = 6 Received secd_err: '6943'
00000970.000270ab 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.028.892]  info :  Entry for user-name: johndoe not found in the current source: LDAP. Ignoring and trying next available source { in SecdCbNsJournal() at src/utils/secd_ns_utils.cpp:82 }
00000970.000270ac 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.295]  debug:  NSLIBC: files_passwd(), ../../../../../lib/libc/gen/getpwent.c:1030, Vsid = 6 Time taken for passwd DB lookup for user johndoe: 386 microseconds
00000970.000270ad 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.313]  info :  Entry for user-name: johndoe not found in the current source: FILES. Entry for user-name: johndoe not found in any of the available sources { in SecdCbNsJournal() at src/utils/secd_ns_utils.cpp:82 }
00000970.000270ae 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.332]  debug:  getpwnam_r() returned error code=0, files_err=5, nis_err=0, ldap_err=22, dns_err=0  { in getUserInfoViaLibC() at src/utils/secd_ns_utils.cpp:465 }
00000970.000270af 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.337]  ERR  :  getpwnam_r() has a transient error  { in getUserInfoViaLibC() at src/utils/secd_ns_utils.cpp:471 }
00000970.000270b0 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.345]  ERR  :  RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR:7035 in getUserInfoViaLibC() at src/utils/secd_ns_utils.cpp:472
00000970.000270b1 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.355]  ERR  :  RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR:7035 in _getUserPasswdInfo() at src/authorization/secd_unix_authorization.cpp:1109
00000970.000270b2 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.364]  ERR  :  RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR:7035 in _getUserInfo() at src/authorization/secd_unix_authorization.cpp:886
00000970.000270b3 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.373]  ERR  :  RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR:7035 in _getUserInfo() at src/authorization/secd_unix_authorization.cpp:856
00000970.000270b4 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.381]  ERR  :  RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR:7035 in getUidFromUserNameViaLibc() at src/authorization/secd_unix_authorization.cpp:604
00000970.000270b5 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.394]  ERR  :  Unable to retrieve UID for UNIX user johndoe { in secd_rpc_auth_user_name_to_id_1_svc() at src/authorization/secd_rpc_authorization.cpp:1209 }
00000970.000270b6 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.400]  ERR  :  RESULT_ERROR_SECD_LIBC_TRANSIENT_ERROR:7035 in secd_rpc_auth_user_name_to_id_1_svc() at src/authorization/secd_rpc_authorization.cpp:1210
00000970.000270b7 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.442]  debug:  SecD RPC Server sending reply to RPC 205: secd_rpc_auth_user_name_to_id  { in secdSendRpcResponse() at src/server/secd_rpc_server.cpp:1888 }
00000970.000270b8 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.515]  ERR  :  RESULT_ERROR_SECD_UNIX_CRED_LOOKUP_FAILED:6987 in getFailureCode() at src/utils/secd_thread_task_journal.cpp:348
00000970.000270b9 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] | [000.029.588]  debug:  Logged secd.unixLookupFailure to EMS  { in logEmsEventWithJournalForUnixAuthError() at src/utils/secd_ems_utils.cpp:1289 }
00000970.000270ba 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |------------------------------------------------------------------------------.
00000970.000270bb 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |                  RPC completed at Wed Oct  4 14:07:43 2017                   |
00000970.000270bc 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] |           End of log for failed RPC secd_rpc_auth_user_name_to_id            |
00000970.000270bd 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969] '------------------------------------------------------------------------------'
00000970.000270be 01710077 Wed Oct 04 2017 14:07:43 +02:00 [kern_secd:info:6969]