Re: Windows-to-unix usermapping through LDAP not working: RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND
Hi,
I think we I found the cause of the problems after digging some more: it looks like one must copy one of the four built-in schemas into a new schema, and then build an LDAP client config from that schema, even if one of the built-in schemas is an exact fit of the LDAP schema one is looking for and no changes need to be made to the schema.
The built-in schemas that are provided are marked as readonly, and it appears secd has trouble finding a config derived from them even though there are no warning or error messages when doing this.
Thanks for taking the time to answering my question, Justin.
Best regards, Filip
On Wed, Oct 4, 2017 at 6:29 PM, Parisi, Justin Justin.Parisi@netapp.com wrote:
Try the “diag secd configuration query” commands to see if secd agrees with the ldap client show output.
Example:
ontap9-tme-8040::*> diag secd configuration query -node ontap9-tme-8040-01 -source-name ldap-config
If that doesn’t show any entry, run the “secd configuration reload” command.
If it does and things are still failing, I’d suggest opening a case.
*From:* toasters-bounces@teaparty.net [mailto:toasters-bounces@ teaparty.net] *On Behalf Of *Filip Sneppe *Sent:* Wednesday, October 4, 2017 6:11 AM *To:* toasters@teaparty.net *Subject:* Windows-to-unix usermapping through LDAP not working: RESULT_ERROR_SECD_CONFIGURATION_NOT_FOUND
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-windows-to-unix-user-mapping-over-ldap?language=en_US
(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
-
Filip Sneppe