Hi everyone,
I am trying to set up Windows-to-Unix mapping by following this reference as a guideline:
https://kb.netapp.com/support/s/article/ka31A00000012CQQAY/how-to-set-up-win...
(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]
Best regards, Filip