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
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