Re: [Freeipa-users] Kerberos hanging approx. once a day
Dear Rich, all, Am 28.07.15 um 19:08 schrieb Rich Megginson: >>> # ldapsearch -xLLL -D "cn=directory manager" -W -s base -b >>> "dc=uni-wuppertal,dc=de" [...] >> >> >> real0m4.559s >> user0m0.403s >> sys 0m0.057s >> [root@ipa httpd]# >> >> Looks okay to us, or? > > 4 seconds? That seems way too long. No.. that includes the time it took me to enter the password. Only the "user" line is relevant, so 0.4 seconds. >> >> So.. here is the problem which is left over. When logging in as admin >> now through th web page or locally: >> >> [Thu Jul 23 21:43:47.340133 2015] [wsgi:error] [pid 1134] ipa: INFO: >> [jsonserver_session] wens...@pleiades.uni-wuppertal.de: >> radiusproxy_find(None, version=u'2.114'): SUCCESS >> [Thu Jul 23 21:43:48.758849 2015] [wsgi:error] [pid 1133] ipa: INFO: >> [jsonserver_session] wens...@pleiades.uni-wuppertal.de: user_find(None, >> version=u'2.114'): SUCCESS >> [Fri Jul 24 07:20:10.198903 2015] [wsgi:error] [pid 1134] ipa: INFO: 401 >> Unauthorized: kinit: Clients credentials have been revoked while getting >> initial credentials >> [Fri Jul 24 07:20:10.198977 2015] [wsgi:error] [pid 1134] >> [Fri Jul 24 07:20:18.181715 2015] [wsgi:error] [pid 1133] ipa: INFO: 401 >> Unauthorized: kinit: Clients credentials have been revoked while getting >> initial credentials >> [Fri Jul 24 07:20:18.181809 2015] [wsgi:error] [pid 1133] >> [Fri Jul 24 07:21:12.919751 2015] [wsgi:error] [pid 1134] ipa: INFO: 401 >> Unauthorized: kinit: Clients credentials have been revoked while getting >> initial credentials >> [Fri Jul 24 07:21:12.919878 2015] [wsgi:error] [pid 1134] >> [root@ipa httpd]# kinit admin >> kinit: Clients credentials have been revoked while getting initial >> credentials >> [root@ipa httpd]# klist >> Ticket cache: KEYRING:persistent:0:0 >> Default principal: ad...@pleiades.uni-wuppertal.de >> >> Valid starting Expires Service principal >> 07/23/2015 11:44:13 07/24/2015 11:44:08 >> HTTP/ipa.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de >> 07/23/2015 11:44:11 07/24/2015 11:44:08 >> krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de >> [root@ipa httpd]# >> >> >> Hope you have an idea about that one as well :). > > I do not, sorry. Maybe one of our kerberos experts will know. Hope so.. the problem still persists. Strangely, it's not always there. And it's only on the primary, not on the secondary server. with an strace there is a difference when it does NOT work: keyctl(KEYCTL_GET_PERSISTENT, 0, KEY_SPEC_PROCESS_KEYRING) = 294917837 keyctl(KEYCTL_SEARCH, 294917837, "keyring", "_krb", KEY_SPEC_PROCESS_KEYRING) = 780102244 keyctl(KEYCTL_SEARCH, 780102244, "user", "krb_ccache:primary", 0) = 12049273 keyctl(KEYCTL_READ, 12049273, NULL, 0) = 10 keyctl(KEYCTL_READ, 12049273, "", 10) = 10 keyctl(KEYCTL_READ, 780102244, NULL, 0) = 4 keyctl(KEYCTL_READ, 780102244, "y\333\267", 4) = 4 keyctl(KEYCTL_SEARCH, 780102244, "keyring", "0", 0) = -1 ENOKEY (Required key not available) keyctl(KEYCTL_DESCRIBE, 12049273, NULL, 0) = 37 keyctl(KEYCTL_DESCRIBE, 12049273, "user;0;0;3f01;krb_ccache:pri"..., 37) = 37 compared to when it WORKS: keyctl(KEYCTL_GET_PERSISTENT, 0, KEY_SPEC_PROCESS_KEYRING) = 294917837 keyctl(KEYCTL_SEARCH, 294917837, "keyring", "_krb", KEY_SPEC_PROCESS_KEYRING) = 780102244 keyctl(KEYCTL_SEARCH, 780102244, "user", "krb_ccache:primary", 0) = 12049273 keyctl(KEYCTL_READ, 12049273, NULL, 0) = 10 keyctl(KEYCTL_READ, 12049273, "", 10) = 10 keyctl(KEYCTL_SEARCH, 780102244, "keyring", "0", 0) = 17381009 keyctl(KEYCTL_SEARCH, 17381009, "user", "__krb5_princ__", 0) = 378086918 keyctl(KEYCTL_SEARCH, 17381009, "user", "__krb5_time_offsets__", 0) = 416824569 keyctl(KEYCTL_READ, 416824569, NULL, 0) = 8 keyctl(KEYCTL_READ, 416824569, "", 8) = 8 keyctl(KEYCTL_READ, 378086918, NULL, 0) = 46 keyctl(KEYCTL_READ, 378086918, "", 46) = 46 keyctl(KEYCTL_GET_PERSISTENT, 0, KEY_SPEC_PROCESS_KEYRING) = 294917837 keyctl(KEYCTL_SEARCH, 294917837, "keyring", "_krb", KEY_SPEC_PROCESS_KEYRING) = 780102244 keyctl(KEYCTL_SEARCH, 780102244, "user", "krb_ccache:primary", 0) = 12049273 keyctl(KEYCTL_READ, 12049273, NULL, 0) = 10 keyctl(KEYCTL_READ, 12049273, "", 10) = 10 keyctl(KEYCTL_READ, 780102244, NULL, 0) = 12 keyctl(KEYCTL_READ, 780102244, "y\333\267", 12) = 12 keyctl(KEYCTL_SEARCH, 780102244, "keyring", "0", 0) = 17381009 keyctl(KEYCTL_SEARCH, 17381009, "user", "__krb5_princ__", 0) = 378086918 keyctl(KEYCTL_READ, 378086918, NULL, 0) = 46 keyctl(KEYCTL_READ, 378086918, "", 46) = 46 Best regards Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/24/2015 01:20 AM, Torsten Harenberg wrote: Dear Rich and all, thanks to everbody! Really thankful for your support. The situation really approved. We: - enlarged the caches for 389ds until the WARNING messages disappeared in the log files, - (just to be sure) re-sync'ed firewalld rules between primary and secondary server. Now the server was stable, Kerberos and 389ds are still alive and all clients can still resolve all users. There is only one issue left (see bottom). First let us answer that: Am 23.07.15 um 18:28 schrieb Rich Megginson: # ldapsearch -xLLL -D "cn=directory manager" -W -s base -b "dc=uni-wuppertal,dc=de" This search should return immediately. If it hangs, then the problem is in slapd, and get a stack trace as before. [root@ipa httpd]# time ldapsearch -xLLL -D "cn=directory manager" -W -s base -b "dc=pleiades,dc=uni-wuppertal,dc=de" Enter LDAP Password: dn: dc=pleiades,dc=uni-wuppertal,dc=de objectClass: top objectClass: domain objectClass: pilotObject objectClass: domainRelatedObject objectClass: nisDomainObject dc: pleiades info: IPA V2.0 nisDomain: pleiades.uni-wuppertal.de associatedDomain: pleiades.uni-wuppertal.de real0m4.559s user0m0.403s sys 0m0.057s [root@ipa httpd]# Looks okay to us, or? 4 seconds? That seems way too long. What does the dirsrv access log look like for this sequence of operations? There will be a connection, a BIND, a SRCH, and an UNBIND. So.. here is the problem which is left over. When logging in as admin now through th web page or locally: [Thu Jul 23 21:43:47.340133 2015] [wsgi:error] [pid 1134] ipa: INFO: [jsonserver_session] wens...@pleiades.uni-wuppertal.de: radiusproxy_find(None, version=u'2.114'): SUCCESS [Thu Jul 23 21:43:48.758849 2015] [wsgi:error] [pid 1133] ipa: INFO: [jsonserver_session] wens...@pleiades.uni-wuppertal.de: user_find(None, version=u'2.114'): SUCCESS [Fri Jul 24 07:20:10.198903 2015] [wsgi:error] [pid 1134] ipa: INFO: 401 Unauthorized: kinit: Clients credentials have been revoked while getting initial credentials [Fri Jul 24 07:20:10.198977 2015] [wsgi:error] [pid 1134] [Fri Jul 24 07:20:18.181715 2015] [wsgi:error] [pid 1133] ipa: INFO: 401 Unauthorized: kinit: Clients credentials have been revoked while getting initial credentials [Fri Jul 24 07:20:18.181809 2015] [wsgi:error] [pid 1133] [Fri Jul 24 07:21:12.919751 2015] [wsgi:error] [pid 1134] ipa: INFO: 401 Unauthorized: kinit: Clients credentials have been revoked while getting initial credentials [Fri Jul 24 07:21:12.919878 2015] [wsgi:error] [pid 1134] [root@ipa httpd]# kinit admin kinit: Clients credentials have been revoked while getting initial credentials [root@ipa httpd]# klist Ticket cache: KEYRING:persistent:0:0 Default principal: ad...@pleiades.uni-wuppertal.de Valid starting Expires Service principal 07/23/2015 11:44:13 07/24/2015 11:44:08 HTTP/ipa.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de 07/23/2015 11:44:11 07/24/2015 11:44:08 krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de [root@ipa httpd]# Hope you have an idea about that one as well :). I do not, sorry. Maybe one of our kerberos experts will know. Thanks Marisa and Torsten -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Dear Rich and all, thanks to everbody! Really thankful for your support. The situation really approved. We: - enlarged the caches for 389ds until the WARNING messages disappeared in the log files, - (just to be sure) re-sync'ed firewalld rules between primary and secondary server. Now the server was stable, Kerberos and 389ds are still alive and all clients can still resolve all users. There is only one issue left (see bottom). First let us answer that: Am 23.07.15 um 18:28 schrieb Rich Megginson: > > # ldapsearch -xLLL -D "cn=directory manager" -W -s base -b > "dc=uni-wuppertal,dc=de" > > This search should return immediately. If it hangs, then the problem is > in slapd, and get a stack trace as before. > [root@ipa httpd]# time ldapsearch -xLLL -D "cn=directory manager" -W -s base -b "dc=pleiades,dc=uni-wuppertal,dc=de" Enter LDAP Password: dn: dc=pleiades,dc=uni-wuppertal,dc=de objectClass: top objectClass: domain objectClass: pilotObject objectClass: domainRelatedObject objectClass: nisDomainObject dc: pleiades info: IPA V2.0 nisDomain: pleiades.uni-wuppertal.de associatedDomain: pleiades.uni-wuppertal.de real0m4.559s user0m0.403s sys 0m0.057s [root@ipa httpd]# Looks okay to us, or? So.. here is the problem which is left over. When logging in as admin now through th web page or locally: [Thu Jul 23 21:43:47.340133 2015] [wsgi:error] [pid 1134] ipa: INFO: [jsonserver_session] wens...@pleiades.uni-wuppertal.de: radiusproxy_find(None, version=u'2.114'): SUCCESS [Thu Jul 23 21:43:48.758849 2015] [wsgi:error] [pid 1133] ipa: INFO: [jsonserver_session] wens...@pleiades.uni-wuppertal.de: user_find(None, version=u'2.114'): SUCCESS [Fri Jul 24 07:20:10.198903 2015] [wsgi:error] [pid 1134] ipa: INFO: 401 Unauthorized: kinit: Clients credentials have been revoked while getting initial credentials [Fri Jul 24 07:20:10.198977 2015] [wsgi:error] [pid 1134] [Fri Jul 24 07:20:18.181715 2015] [wsgi:error] [pid 1133] ipa: INFO: 401 Unauthorized: kinit: Clients credentials have been revoked while getting initial credentials [Fri Jul 24 07:20:18.181809 2015] [wsgi:error] [pid 1133] [Fri Jul 24 07:21:12.919751 2015] [wsgi:error] [pid 1134] ipa: INFO: 401 Unauthorized: kinit: Clients credentials have been revoked while getting initial credentials [Fri Jul 24 07:21:12.919878 2015] [wsgi:error] [pid 1134] [root@ipa httpd]# kinit admin kinit: Clients credentials have been revoked while getting initial credentials [root@ipa httpd]# klist Ticket cache: KEYRING:persistent:0:0 Default principal: ad...@pleiades.uni-wuppertal.de Valid starting Expires Service principal 07/23/2015 11:44:13 07/24/2015 11:44:08 HTTP/ipa.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de 07/23/2015 11:44:11 07/24/2015 11:44:08 krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de [root@ipa httpd]# Hope you have an idea about that one as well :). Thanks Marisa and Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal <> <> <> <><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><> -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/22/2015 11:47 PM, Torsten Harenberg wrote: Good morning, Am 22.07.15 um 19:25 schrieb Rich Megginson: On 07/22/2015 11:03 AM, Torsten Harenberg wrote: Dear Rich, Am 22.07.2015 um 17:03 schrieb Rich Megginson: It might be helpful to do a # debuginfo-install 389-ds-base ipa-server slapi-nis and follow the directions at http://www.port389.org/docs/389ds/FAQ/faq.html#debugging-hangs to get a full stack trace thanks for the hint. Did that. But assume I need to wait until it hangs again, right? Right. problem happend again, this time with slightly different symtoms: [root@wn108 ~]# id atlasprd020 id: atlasprd020: No such user after restarting dirserv: [root@wn108 ~]# id atlasprd020 uid=18970(atlasprd020) gid=1407(atlasprd) groups=1407(atlasprd) [root@wn108 ~]# So of course the whole site was down. the dirserv log file has not much: [22/Jul/2015:11:03:35 +0200] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=pleiades,dc=uni-wuppertal,dc=de--no CoS Templates found, which should be add ed before the CoS Definition. [22/Jul/2015:11:03:38 +0200] NSMMReplicationPlugin - replica_check_for_data_reload: Warning: disordely shutdown for replica dc=pleiades,dc=uni-wuppertal,dc=de. Check if DB RUV needs to be updated [22/Jul/2015:11:03:38 +0200] NSMMReplicationPlugin - Force update of database RUV (from CL RUV) -> 55af7af3000e0004 [22/Jul/2015:11:03:39 +0200] set_krb5_creds - Could not get initial credentials for principal [ldap/ipa.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de] in keyta b [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for requested realm) [22/Jul/2015:11:03:39 +0200] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=pleiades,dc=uni-wuppertal,dc=de--no CoS Templates found, which should be add ed before the CoS Definition. [22/Jul/2015:11:03:39 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL( -1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (No Kerberos credentials available)) errno 0 (Success) [22/Jul/2015:11:03:39 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -2 (Local error) [22/Jul/2015:11:03:39 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Replication bind with GSSAPI auth failed: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (No Kerberos credentials available)) [22/Jul/2015:11:03:39 +0200] - slapd started. Listening on All Interfaces port 389 for LDAP requests [22/Jul/2015:11:03:39 +0200] - Listening on All Interfaces port 636 for LDAPS requests [22/Jul/2015:11:03:39 +0200] - Listening on /var/run/slapd-PLEIADES-UNI-WUPPERTAL-DE.socket for LDAPI requests [22/Jul/2015:11:03:43 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Replication bind with GSSAPI auth resumed [22/Jul/2015:15:15:41 +0200] find_sid_for_ldap_entry - [file ipa_sidgen_common.c, line 522]: Cannot convert Posix ID [51351] into an unused SID. [22/Jul/2015:15:15:41 +0200] ipa_sidgen_add_post_op - [file ipa_sidgen.c, line 149]: Cannot add SID to new entry. [23/Jul/2015:07:33:05 +0200] - slapd shutting down - signaling operation threads - op stack size 48 max work q size 22 max work q stack size 22 [23/Jul/2015:07:33:05 +0200] - slapd shutting down - waiting for 1 thread to terminate [23/Jul/2015:07:33:05 +0200] - slapd shutting down - closing down internal subsystems and plugins [23/Jul/2015:07:33:05 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Warning: Attempting to release replica, but unable to r eceive endReplication extended operation response from the replica. Error -5 (Timed out) [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - timeout registering with portmap service [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - timeout registering with portmap service [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - timeout registering with portmap service [23/Jul/2015:07:33:06 +0200] nis-plugin -
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Thu, Jul 23, 2015 at 10:21:41AM +0200, Marisa Sandhoff wrote: > Hi Sumit, > > > > > I'm not a 389ds expert but in my setup nsslapd-cachememsize is set to > > 10M and since I didn't do any tuning I would expect that this is some > > default. > > > > Perhaps we should start with increasing the nsslapd-cachememsize to 10M > and than see what happens with our server. Actually, how can we increase > this cachmemsize? Does https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/8.2/html/Performance_Tuning_Guide/memoryusage.html help? bye, Sumit > > Thanks for your help, > Torsten and Marisa > > -- > Dr. Marisa Sandhoff > Experimentelle Elementarteilchenphysik > Fachbereich C - Physik > Bergische Universitaet Wuppertal > Gaussstr. 20 > D-42097 Wuppertal, Germany > --- > marisa.sandh...@cern.ch > sandh...@physik.uni-wuppertal.de > Phone +49 202 439 3521 > Fax +49 202 439 2811 > > -- > Manage your subscription for the Freeipa-users mailing list: > https://www.redhat.com/mailman/listinfo/freeipa-users > Go to http://freeipa.org for more info on the project -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
you can change the cachememsize online: ldapmodify dn: cn=,cn=ldbm database,cn=plugins,cn=config changetype: modify replace: nsslapd-cachememsize nsslapd-cachememsize: But I would also increase the dbcache size, which would require a restart to be effective. So you could also stop DS, edit /etc/dirsrv/slapd-/dse.ldif search all *cache* attributes and replace the valu. Ludwig On 07/23/2015 10:21 AM, Marisa Sandhoff wrote: Hi Sumit, I'm not a 389ds expert but in my setup nsslapd-cachememsize is set to 10M and since I didn't do any tuning I would expect that this is some default. Perhaps we should start with increasing the nsslapd-cachememsize to 10M and than see what happens with our server. Actually, how can we increase this cachmemsize? Thanks for your help, Torsten and Marisa -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Hi Sumit, > > I'm not a 389ds expert but in my setup nsslapd-cachememsize is set to > 10M and since I didn't do any tuning I would expect that this is some > default. > Perhaps we should start with increasing the nsslapd-cachememsize to 10M and than see what happens with our server. Actually, how can we increase this cachmemsize? Thanks for your help, Torsten and Marisa -- Dr. Marisa Sandhoff Experimentelle Elementarteilchenphysik Fachbereich C - Physik Bergische Universitaet Wuppertal Gaussstr. 20 D-42097 Wuppertal, Germany --- marisa.sandh...@cern.ch sandh...@physik.uni-wuppertal.de Phone +49 202 439 3521 Fax +49 202 439 2811 -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/23/2015 09:56 AM, Sumit Bose wrote: On Thu, Jul 23, 2015 at 09:18:43AM +0200, Torsten Harenberg wrote: Hi Sumit, The principal looks strange, I would at least expect the fully-qualified name of the ipa server here. What does the 'hostname' command return? It [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# hostname ipa.pleiades.uni-wuppertal.de is expected that it will return the fully-qualified name. Additionally if you added the ipa server to /etc/hosts please only use the fully-qualified name to be on the safe side (iirc it is ok to have the short name as a second name, but the fully-qualified one should be always first). I removed the entries vom /etc/hosts again. The keytab file /etc/krb5.keytab looks strange here. Later on the right one /etc/dirsrv/ds.keytab is used. Did you try to run the /usr/sbin/ns-slapd binary manually at some time? Yes.. once .. after it did not came up. After another reboot, the system came up now. But what I found is https://fedorahosted.org/freeipa/ticket/2739 and indeed: [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# grep WARNING * errors:[21/Jul/2015:17:15:21 +0200] - WARNING: cache too small, increasing to 500K bytes errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING: userRoot: entry cache size 512000B is less than db size 4177920B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[21/Jul/2015:17:15:21 +0200] - WARNING: changelog: entry cache size 512000B is less than db size 18096128B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING: userRoot: entry cache size 512000B is less than db size 4218880B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[22/Jul/2015:11:03:31 +0200] - WARNING: changelog: entry cache size 512000B is less than db size 27992064B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[23/Jul/2015:07:33:09 +0200] - WARNING: cache too small, increasing to 500K bytes errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up I'm not a 389ds expert but in my setup nsslapd-cachememsize is set to 10M and since I didn't do any tuning I would expect that this is some default. yes, 10M should be the default. and OOM would be triggered by a memleak, not by the cache size. Also the server seems to stop and start cleanly, and is not killed by oom And what I see is that nodes occasionaly loose their users. I haven't seen that the two month while testing (of course there were no real users during that time, so I'm not 100% sure that it did not happen). Could that be the cause of the trouble?? The users and groups are delivered to the system via SSSD. If SSSD loses the connection to the IPA servers, e.g. because the server does not respond, SSSD cannot lookup new users. Nevertheless SSSD has a cache and users and groups are delivered from the cache in this case. But system users which important for the services to run like the users dirsrv, apache, pkiuser etc are defined in /etc/passwd. So I don't expect this to bethe casue of the trouble. bye, Sumit Kind regards, Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Thu, Jul 23, 2015 at 09:18:43AM +0200, Torsten Harenberg wrote: > Hi Sumit, > > > > The principal looks strange, I would at least expect the fully-qualified > > name of the ipa server here. What does the 'hostname' command return? It > > [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# hostname > ipa.pleiades.uni-wuppertal.de > > > is expected that it will return the fully-qualified name. Additionally if > > you added the ipa server to /etc/hosts please only use the > > fully-qualified name to be on the safe side (iirc it is ok to have the > > short name as a second name, but the fully-qualified one should be > > always first). > > I removed the entries vom /etc/hosts again. > > > > > The keytab file /etc/krb5.keytab looks strange here. Later on the right > > one /etc/dirsrv/ds.keytab is used. Did you try to run the > > /usr/sbin/ns-slapd binary manually at some time? > > > > Yes.. once .. after it did not came up. > > After another reboot, the system came up now. > > But what I found is > > https://fedorahosted.org/freeipa/ticket/2739 > > and indeed: > > [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# grep WARNING * > errors:[21/Jul/2015:17:15:21 +0200] - WARNING: cache too small, > increasing to 500K bytes > errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[21/Jul/2015:17:15:21 +0200] - WARNING: userRoot: entry cache > size 512000B is less than db size 4177920B; We recommend to increase the > entry cache size nsslapd-cachememsize. > errors:[21/Jul/2015:17:15:21 +0200] - WARNING: changelog: entry cache > size 512000B is less than db size 18096128B; We recommend to increase > the entry cache size nsslapd-cachememsize. > errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[22/Jul/2015:11:03:31 +0200] - WARNING: userRoot: entry cache > size 512000B is less than db size 4218880B; We recommend to increase the > entry cache size nsslapd-cachememsize. > errors:[22/Jul/2015:11:03:31 +0200] - WARNING: changelog: entry cache > size 512000B is less than db size 27992064B; We recommend to increase > the entry cache size nsslapd-cachememsize. > errors:[23/Jul/2015:07:33:09 +0200] - WARNING: cache too small, > increasing to 500K bytes > errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up > errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is > 512000 -- rounding up I'm not a 389ds expert but in my setup nsslapd-cachememsize is set to 10M and since I didn't do any tuning I would expect that this is some default. > > > And what I see is that nodes occasionaly loose their users. I haven't > seen that the two month while testing (of course there were no real > users during that time, so I'm not 100% sure that it did not happen). > > Could that be the cause of the trouble?? The users and groups are delivered to the system via SSSD. If SSSD loses the connection to the IPA servers, e.g. because the server does not respond, SSSD cannot lookup new users. Nevertheless SSSD has a cache and users and groups are delivered from the cache in this case. But system users which important for the services to run like the users dirsrv, apache, pkiuser etc are defined in /etc/passwd. So I don't expect this to bethe casue of the trouble. bye, Sumit > > Kind regards, > > Torsten > > > > -- > <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> > <> <> > <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> > <> Bergische Universitaet
Re: [Freeipa-users] Kerberos hanging approx. once a day
Hi Sumit, > The principal looks strange, I would at least expect the fully-qualified > name of the ipa server here. What does the 'hostname' command return? It [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# hostname ipa.pleiades.uni-wuppertal.de > is expected that it will return the fully-qualified name. Additionally if > you added the ipa server to /etc/hosts please only use the > fully-qualified name to be on the safe side (iirc it is ok to have the > short name as a second name, but the fully-qualified one should be > always first). I removed the entries vom /etc/hosts again. > > The keytab file /etc/krb5.keytab looks strange here. Later on the right > one /etc/dirsrv/ds.keytab is used. Did you try to run the > /usr/sbin/ns-slapd binary manually at some time? > Yes.. once .. after it did not came up. After another reboot, the system came up now. But what I found is https://fedorahosted.org/freeipa/ticket/2739 and indeed: [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# grep WARNING * errors:[21/Jul/2015:17:15:21 +0200] - WARNING: cache too small, increasing to 500K bytes errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[21/Jul/2015:17:15:21 +0200] - WARNING: userRoot: entry cache size 512000B is less than db size 4177920B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[21/Jul/2015:17:15:21 +0200] - WARNING: changelog: entry cache size 512000B is less than db size 18096128B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[22/Jul/2015:11:03:31 +0200] - WARNING: userRoot: entry cache size 512000B is less than db size 4218880B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[22/Jul/2015:11:03:31 +0200] - WARNING: changelog: entry cache size 512000B is less than db size 27992064B; We recommend to increase the entry cache size nsslapd-cachememsize. errors:[23/Jul/2015:07:33:09 +0200] - WARNING: cache too small, increasing to 500K bytes errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up errors:[23/Jul/2015:07:33:09 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up And what I see is that nodes occasionaly loose their users. I haven't seen that the two month while testing (of course there were no real users during that time, so I'm not 100% sure that it did not happen). Could that be the cause of the trouble?? Kind regards, Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal <> <> <> <><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><> -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Thu, Jul 23, 2015 at 08:35:45AM +0200, Torsten Harenberg wrote: > Huu.. situation is getting worse. > > Even after a full reboot, slapd does not start at all anymore on the > primary server. > > This is the full log (looks like the realm is missing suddenly?): > ... > [23/Jul/2015:08:25:09 +0200] set_krb5_creds - Could not get initial > credentials for principal [ldap/ipa@] in keytab [FILE:/etc/krb5.keytab]: > -1765328164 (Cannot resolve network address for KDC in requested realm) The principal looks strange, I would at least expect the fully-qualified name of the ipa server here. What does the 'hostname' command return? It is expected that it will return the fully-qualified name. Additionally if you added the ipa server to /etc/hosts please only use the fully-qualified name to be on the safe side (iirc it is ok to have the short name as a second name, but the fully-qualified one should be always first). The keytab file /etc/krb5.keytab looks strange here. Later on the right one /etc/dirsrv/ds.keytab is used. Did you try to run the /usr/sbin/ns-slapd binary manually at some time? bye, Sumit -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Huu.. situation is getting worse. Even after a full reboot, slapd does not start at all anymore on the primary server. This is the full log (looks like the realm is missing suddenly?): [23/Jul/2015:07:40:53 +0200] - slapd stopped. [23/Jul/2015:08:25:06 +0200] - Config Warning: - nsslapd-maxdescriptors: invalid value "8192", maximum file descriptors must range from 1 to 4096 (the current process limit). Server will use a setting of 4096. [23/Jul/2015:08:25:06 +0200] nis-plugin - error connecting rpcbind client socket to the service [23/Jul/2015:08:25:06 +0200] SSL Initialization - Configured SSL version range: min: TLS1.0, max: TLS1.2 [23/Jul/2015:08:25:06 +0200] - SSL alert: Configured NSS Ciphers [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_AES_128_GCM_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_DSS_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_AES_128_CBC_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_CAMELLIA_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_DSS_WITH_CAMELLIA_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_DSS_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_RSA_WITH_CAMELLIA_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_DHE_DSS_WITH_CAMELLIA_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDH_RSA_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_AES_128_GCM_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_AES_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_AES_128_CBC_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_CAMELLIA_128_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_AES_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_AES_256_CBC_SHA256: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_CAMELLIA_256_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - SSL alert: TLS_RSA_WITH_SEED_CBC_SHA: enabled [23/Jul/2015:08:25:06 +0200] - 389-Directory/1.3.3.8 B2015.036.047 starting up [23/Jul/2015:08:25:06 +0200] - WARNING: cache too small, increasing to 500K bytes [23/Jul/2015:08:25:06 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up [23/Jul/2015:08:25:06 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up [23/Jul/2015:08:25:06 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up [23/Jul/2015:08:25:06 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up [23/Jul/2015:08:25:06 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up [23/Jul/2015:08:25:06 +0200] - WARNING -- Minimum cache size is 512000 -- rounding up [23/Jul/2015:08:25:06 +0200] - WARNING: userRoot: entry cache size 512000B is less than db size 4251648B; We recommend to increase the entry cache size nsslapd-cachememsize. [23/Jul/2015:08:25:06 +0200] - WARNING: changelog: entry cache size 512000B is less than db size 173367296B; We recommend to increase the entry cache size nsslapd-cachememsize. [23/Jul/2015:08:25:07 +0200] - resizing db cache size: 32 -> 40 [23/Jul/2015:08:25:07 +0200] nis-plugin - warning: no entries in domain=pleiades.uni-wuppertal.de,map=ethers.byaddr [23/Jul/2015:08:25:07 +0200] nis-plugin - warning: no entries in domain=pleiades.uni-wuppertal.de,map=ethers.byname [23/Jul/2015:08:25:08 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:08:25:08 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:08:25:08 +0200] nis-plugin - timeout regis
Re: [Freeipa-users] Kerberos hanging approx. once a day
Maybe related or not: even after rebooting both IPA servers, the "secondary" has every 5 minutes (not only during startup) [23/Jul/2015:08:00:25 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1 (Can't contact LDAP server) ((null)) errno 107 (Transport endpoint is not connected) [23/Jul/2015:08:00:25 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -1 (Can't contact LDAP server) [23/Jul/2015:08:02:01 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1 (Can't contact LDAP server) ((null)) errno 107 (Transport endpoint is not connected) [23/Jul/2015:08:02:01 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -1 (Can't contact LDAP server) [23/Jul/2015:08:05:13 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1 (Can't contact LDAP server) ((null)) errno 107 (Transport endpoint is not connected) [23/Jul/2015:08:05:13 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -1 (Can't contact LDAP server) [23/Jul/2015:08:10:13 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1 (Can't contact LDAP server) ((null)) errno 107 (Transport endpoint is not connected) [23/Jul/2015:08:10:13 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -1 (Can't contact LDAP server) [23/Jul/2015:08:15:13 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1 (Can't contact LDAP server) ((null)) errno 107 (Transport endpoint is not connected) [23/Jul/2015:08:15:13 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -1 (Can't contact LDAP server) in the dirserv log. Best regards Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal <> <> <> <><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><> -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Good morning, Am 22.07.15 um 19:25 schrieb Rich Megginson: > On 07/22/2015 11:03 AM, Torsten Harenberg wrote: >> Dear Rich, >> >> Am 22.07.2015 um 17:03 schrieb Rich Megginson: >>> It might be helpful to do a # debuginfo-install 389-ds-base ipa-server >>> slapi-nis >>> and follow the directions at >>> http://www.port389.org/docs/389ds/FAQ/faq.html#debugging-hangs >>> to get a full stack trace >> thanks for the hint. Did that. But assume I need to wait until it hangs >> again, right? > > Right. problem happend again, this time with slightly different symtoms: [root@wn108 ~]# id atlasprd020 id: atlasprd020: No such user after restarting dirserv: [root@wn108 ~]# id atlasprd020 uid=18970(atlasprd020) gid=1407(atlasprd) groups=1407(atlasprd) [root@wn108 ~]# So of course the whole site was down. the dirserv log file has not much: [22/Jul/2015:11:03:35 +0200] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=pleiades,dc=uni-wuppertal,dc=de--no CoS Templates found, which should be add ed before the CoS Definition. [22/Jul/2015:11:03:38 +0200] NSMMReplicationPlugin - replica_check_for_data_reload: Warning: disordely shutdown for replica dc=pleiades,dc=uni-wuppertal,dc=de. Check if DB RUV needs to be updated [22/Jul/2015:11:03:38 +0200] NSMMReplicationPlugin - Force update of database RUV (from CL RUV) -> 55af7af3000e0004 [22/Jul/2015:11:03:39 +0200] set_krb5_creds - Could not get initial credentials for principal [ldap/ipa.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de] in keyta b [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for requested realm) [22/Jul/2015:11:03:39 +0200] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=pleiades,dc=uni-wuppertal,dc=de--no CoS Templates found, which should be add ed before the CoS Definition. [22/Jul/2015:11:03:39 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL( -1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (No Kerberos credentials available)) errno 0 (Success) [22/Jul/2015:11:03:39 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -2 (Local error) [22/Jul/2015:11:03:39 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Replication bind with GSSAPI auth failed: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (No Kerberos credentials available)) [22/Jul/2015:11:03:39 +0200] - slapd started. Listening on All Interfaces port 389 for LDAP requests [22/Jul/2015:11:03:39 +0200] - Listening on All Interfaces port 636 for LDAPS requests [22/Jul/2015:11:03:39 +0200] - Listening on /var/run/slapd-PLEIADES-UNI-WUPPERTAL-DE.socket for LDAPI requests [22/Jul/2015:11:03:43 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Replication bind with GSSAPI auth resumed [22/Jul/2015:15:15:41 +0200] find_sid_for_ldap_entry - [file ipa_sidgen_common.c, line 522]: Cannot convert Posix ID [51351] into an unused SID. [22/Jul/2015:15:15:41 +0200] ipa_sidgen_add_post_op - [file ipa_sidgen.c, line 149]: Cannot add SID to new entry. [23/Jul/2015:07:33:05 +0200] - slapd shutting down - signaling operation threads - op stack size 48 max work q size 22 max work q stack size 22 [23/Jul/2015:07:33:05 +0200] - slapd shutting down - waiting for 1 thread to terminate [23/Jul/2015:07:33:05 +0200] - slapd shutting down - closing down internal subsystems and plugins [23/Jul/2015:07:33:05 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Warning: Attempting to release replica, but unable to r eceive endReplication extended operation response from the replica. Error -5 (Timed out) [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - timeout registering with portmap service [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - timeout registering with portmap service [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [23/Jul/2015:07:33:06 +0200] nis-plugin - timeout registering with portmap service [23/Jul/2015:07:33:06 +0200] nis-plugin - error sending req
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/22/2015 02:09 PM, Torsten Harenberg wrote: Am 22.07.2015 um 21:49 schrieb Rich Megginson: but strage: there is no bind binary: Then I'm not sure what's going on. currently there is a java process on ldaps: [root@ipa ~]# netstat -p -n | grep 636 tcp6 0 0 132.195.124.12:636 132.195.124.12:36546 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36553 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36546132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36549132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36551132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36553132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36549 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36548132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36550132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36554 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36554132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36548 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36547 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36552132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36547132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36550 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36552 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36551 VERBUNDEN 800/ns-slapd [root@ipa ~]# ps ax | grep 1331 1331 ?Ssl2:19 /usr/lib/jvm/jre/bin/java -DRESTEASY_LIB=/usr/share/java/resteasy -classpath /usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/lib/java/commons-daemon.jar -Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp -Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.security.manager -Djava.security.policy==/var/lib/pki/pki-tomcat/conf/catalina.policy org.apache.catalina.startup.Bootstrap start 8411 pts/1S+ 0:00 grep --color=auto 1331 [root@ipa ~]# Could that cause these requests? Possibly, but I didn't think DogTag used persistent search. Best regards, Torsten -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Am 22.07.2015 um 21:49 schrieb Rich Megginson: >> >> but strage: there is no bind binary: > > Then I'm not sure what's going on. currently there is a java process on ldaps: [root@ipa ~]# netstat -p -n | grep 636 tcp6 0 0 132.195.124.12:636 132.195.124.12:36546 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36553 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36546132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36549132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36551132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36553132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36549 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36548132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36550132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36554 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36554132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36548 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36547 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:36552132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:36547132.195.124.12:636 VERBUNDEN 1331/java tcp6 0 0 132.195.124.12:636 132.195.124.12:36550 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36552 VERBUNDEN 800/ns-slapd tcp6 0 0 132.195.124.12:636 132.195.124.12:36551 VERBUNDEN 800/ns-slapd [root@ipa ~]# ps ax | grep 1331 1331 ?Ssl2:19 /usr/lib/jvm/jre/bin/java -DRESTEASY_LIB=/usr/share/java/resteasy -classpath /usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/lib/java/commons-daemon.jar -Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp -Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.security.manager -Djava.security.policy==/var/lib/pki/pki-tomcat/conf/catalina.policy org.apache.catalina.startup.Bootstrap start 8411 pts/1S+ 0:00 grep --color=auto 1331 [root@ipa ~]# Could that cause these requests? Best regards, Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal <> <> <> <><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><> -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Am 22.07.2015 um 21:32 schrieb Rich Megginson: > On 07/22/2015 01:17 PM, Jakub Hrozek wrote: >> On Wed, Jul 22, 2015 at 11:25:12AM -0600, Rich Megginson wrote: >> /lib64/libpthread.so.0 >> #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so >> #2 0x7fb8565f19a5 in ps_send_results () >> #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so >> #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 >> #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 > What is the client here that is doing a persistent search or syncrepl? > Is it BIND? To be honest, I have no idea. Bind ist installed (with ipa) but I haven't configured DNS services. My first guess would be the secondary IPA? >>> No, probably not. I think it is either BIND or sssd. >> Rich, if you're certain that the lient is doing a syncrepl, then it's >> bind. SSSD doesn't do syncrepl..(yet) >> > > I'm not sure how else 389 would be in ps_send_results without a client > doing a persistent search. So BIND it is. > but strage: there is no bind binary: [root@ipa ~]# rpm -qa | grep bind bind-libs-9.9.6-9.P1.fc21.x86_64 bind-utils-9.9.6-9.P1.fc21.x86_64 samba-winbind-modules-4.1.17-1.fc21.x86_64 bind-license-9.9.6-9.P1.fc21.noarch jackson-databind-2.4.1.3-1.fc21.noarch invokebinder-1.1-8.fc21.noarch samba-winbind-4.1.17-1.fc21.x86_64 cmpi-bindings-pywbem-0.9.5-8.fc21.x86_64 bind-libs-lite-9.9.6-9.P1.fc21.x86_64 rpcbind-0.2.2-2.1.fc21.x86_64 [root@ipa ~]# [root@ipa ~]# rpm -qi bind Das Paket bind ist nicht installiert [root@ipa ~]# [root@ipa ~]# ps ax | grep bind 1449 ?Ss 0:00 /usr/sbin/winbindd 1450 ?S 0:01 /usr/sbin/winbindd 8094 pts/1S+ 0:00 grep --color=auto bind [root@ipa ~]# Cheers Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal <> <> <> <><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><> -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/22/2015 01:47 PM, Torsten Harenberg wrote: Am 22.07.2015 um 21:32 schrieb Rich Megginson: On 07/22/2015 01:17 PM, Jakub Hrozek wrote: On Wed, Jul 22, 2015 at 11:25:12AM -0600, Rich Megginson wrote: /lib64/libpthread.so.0 #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so #2 0x7fb8565f19a5 in ps_send_results () #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 What is the client here that is doing a persistent search or syncrepl? Is it BIND? To be honest, I have no idea. Bind ist installed (with ipa) but I haven't configured DNS services. My first guess would be the secondary IPA? No, probably not. I think it is either BIND or sssd. Rich, if you're certain that the lient is doing a syncrepl, then it's bind. SSSD doesn't do syncrepl..(yet) I'm not sure how else 389 would be in ps_send_results without a client doing a persistent search. So BIND it is. but strage: there is no bind binary: Then I'm not sure what's going on. [root@ipa ~]# rpm -qa | grep bind bind-libs-9.9.6-9.P1.fc21.x86_64 bind-utils-9.9.6-9.P1.fc21.x86_64 samba-winbind-modules-4.1.17-1.fc21.x86_64 bind-license-9.9.6-9.P1.fc21.noarch jackson-databind-2.4.1.3-1.fc21.noarch invokebinder-1.1-8.fc21.noarch samba-winbind-4.1.17-1.fc21.x86_64 cmpi-bindings-pywbem-0.9.5-8.fc21.x86_64 bind-libs-lite-9.9.6-9.P1.fc21.x86_64 rpcbind-0.2.2-2.1.fc21.x86_64 [root@ipa ~]# [root@ipa ~]# rpm -qi bind Das Paket bind ist nicht installiert [root@ipa ~]# [root@ipa ~]# ps ax | grep bind 1449 ?Ss 0:00 /usr/sbin/winbindd 1450 ?S 0:01 /usr/sbin/winbindd 8094 pts/1S+ 0:00 grep --color=auto bind [root@ipa ~]# Cheers Torsten -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/22/2015 01:17 PM, Jakub Hrozek wrote: On Wed, Jul 22, 2015 at 11:25:12AM -0600, Rich Megginson wrote: /lib64/libpthread.so.0 #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so #2 0x7fb8565f19a5 in ps_send_results () #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 What is the client here that is doing a persistent search or syncrepl? Is it BIND? To be honest, I have no idea. Bind ist installed (with ipa) but I haven't configured DNS services. My first guess would be the secondary IPA? No, probably not. I think it is either BIND or sssd. Rich, if you're certain that the lient is doing a syncrepl, then it's bind. SSSD doesn't do syncrepl..(yet) I'm not sure how else 389 would be in ps_send_results without a client doing a persistent search. So BIND it is. -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Wed, Jul 22, 2015 at 11:25:12AM -0600, Rich Megginson wrote: > >>>/lib64/libpthread.so.0 > >>>#1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so > >>>#2 0x7fb8565f19a5 in ps_send_results () > >>>#3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so > >>>#4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 > >>>#5 0x7fb853bd722d in clone () from /lib64/libc.so.6 > >>What is the client here that is doing a persistent search or syncrepl? > >>Is it BIND? > >To be honest, I have no idea. Bind ist installed (with ipa) but I > >haven't configured DNS services. > > > >My first guess would be the secondary IPA? > > No, probably not. I think it is either BIND or sssd. Rich, if you're certain that the lient is doing a syncrepl, then it's bind. SSSD doesn't do syncrepl..(yet) -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Hi Rich, Am 22.07.2015 um 19:25 schrieb Rich Megginson: > > No, probably not. I think it is either BIND or sssd. from that I would say sssd: [root@ipa ~]# netstat -p Aktive Internetverbindungen (ohne Server) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp0 0 ipa.pleiades.uni-:54189 ipa.pleiades.uni-w:ldap VERBUNDEN 456/sssd_be tcp0192 ipa.pleiades.uni-wu:ssh grid-admin.physik:37125 VERBUNDEN 6077/sshd: root@pts tcp0 0 ipa.pleiades.uni-:38159 ipa2.pleiades.uni-:ldap VERBUNDEN 800/ns-slapd [...] Best regards Torsten -- <><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><><> <> <> <> Dr. Torsten Harenberg harenb...@physik.uni-wuppertal.de <> <> Bergische Universitaet <> <> FB C - Physik Tel.: +49 (0)202 439-3521 <> <> Gaussstr. 20 Fax : +49 (0)202 439-2811 <> <> 42097 Wuppertal <> <> <> <><><><><><><>< Of course it runs NetBSD http://www.netbsd.org ><> -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/22/2015 11:03 AM, Torsten Harenberg wrote: Dear Rich, Am 22.07.2015 um 17:03 schrieb Rich Megginson: It might be helpful to do a # debuginfo-install 389-ds-base ipa-server slapi-nis and follow the directions at http://www.port389.org/docs/389ds/FAQ/faq.html#debugging-hangs to get a full stack trace thanks for the hint. Did that. But assume I need to wait until it hangs again, right? Right. Or is the trace now useful as well? /lib64/libpthread.so.0 #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so #2 0x7fb8565f19a5 in ps_send_results () #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 What is the client here that is doing a persistent search or syncrepl? Is it BIND? To be honest, I have no idea. Bind ist installed (with ipa) but I haven't configured DNS services. My first guess would be the secondary IPA? No, probably not. I think it is either BIND or sssd. But I do see a connection in the connection list: [root@ipa ~]# netstat -n | grep 389 tcp0 0 132.195.124.12:54165132.195.124.12:389 VERBUNDEN tcp0 0 132.195.124.12:38147132.195.124.13:389 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.87:53329 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.82:40318 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.175:38594 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.103:49170 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.149:56597 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.140:54072 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.78:40696 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.84:48177 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.96:49207 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.171:42650 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.130:50921 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.76:50983 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.211:52241 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.156:58316 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.89:53923 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.41:52193 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.55:49024 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.47:43523 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.115:57328 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.105:41527 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.165:59116 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.69:37154 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.112:35861 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.34:35281 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.66:38854 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.62:41879 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.71:38302 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.108:45796 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.36:59637 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.80:54565 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.102:49728 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.97:36546 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.155:45730 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.75:53949 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.33:46382 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.98:53164 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.213:45945 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.160:48080 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.29:56264 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.180:58558 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.74:58274 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.52:42197 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.158:44226 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.151:46135 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.25:50124 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.181:54617 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.99:52665 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.126:40899 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.24:36240 VERBUNDEN tcp6
Re: [Freeipa-users] Kerberos hanging approx. once a day
Dear Rich, Am 22.07.2015 um 17:03 schrieb Rich Megginson: >> > > It might be helpful to do a # debuginfo-install 389-ds-base ipa-server > slapi-nis > and follow the directions at > http://www.port389.org/docs/389ds/FAQ/faq.html#debugging-hangs > to get a full stack trace thanks for the hint. Did that. But assume I need to wait until it hangs again, right? Or is the trace now useful as well? >> /lib64/libpthread.so.0 >> #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so >> #2 0x7fb8565f19a5 in ps_send_results () >> #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so >> #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 >> #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 > > What is the client here that is doing a persistent search or syncrepl? > Is it BIND? To be honest, I have no idea. Bind ist installed (with ipa) but I haven't configured DNS services. My first guess would be the secondary IPA? But I do see a connection in the connection list: [root@ipa ~]# netstat -n | grep 389 tcp0 0 132.195.124.12:54165132.195.124.12:389 VERBUNDEN tcp0 0 132.195.124.12:38147132.195.124.13:389 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.87:53329 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.82:40318 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.175:38594 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.103:49170 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.149:56597 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.140:54072 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.78:40696 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.84:48177 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.96:49207 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.171:42650 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.130:50921 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.76:50983 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.211:52241 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.156:58316 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.89:53923 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.41:52193 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.55:49024 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.47:43523 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.115:57328 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.105:41527 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.165:59116 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.69:37154 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.112:35861 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.34:35281 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.66:38854 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.62:41879 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.71:38302 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.108:45796 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.36:59637 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.80:54565 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.102:49728 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.97:36546 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.155:45730 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.75:53949 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.33:46382 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.98:53164 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.213:45945 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.160:48080 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.29:56264 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.180:58558 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.74:58274 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.52:42197 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.158:44226 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.151:46135 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.25:50124 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.181:54617 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.99:52665 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.126:40899 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.124.24:36240 VERBUNDEN tcp6 0 0 132.195.124.12:389 132.195.125.184:50084 VERBUNDEN tcp6 0
Re: [Freeipa-users] Kerberos hanging approx. once a day
On 07/22/2015 03:39 AM, Torsten Harenberg wrote: Dear Alexander, dear Sumit, thank you very much indeed for the quick replies. Am 22.07.15 um 11:21 schrieb Sumit Bose: Looks like there are issues getting the needed data from the local LDAP server. The message below about the master key points into the same direction. Can you check the 389ds logs? I have attached the /var/log/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE/errors file to the end of the mail, it's a bit larger. There are some "ticket expired" messages, could that point to the source of the problem? Am 22.07.15 um 11:22 schrieb Alexander Bokovoy: Do you have 389-ds actually operating? If you would install debuginfo packages, what does 'pstack ' print? here is the output: It might be helpful to do a # debuginfo-install 389-ds-base ipa-server slapi-nis and follow the directions at http://www.port389.org/docs/389ds/FAQ/faq.html#debugging-hangs to get a full stack trace /lib64/libpthread.so.0 #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so #2 0x7fb8565f19a5 in ps_send_results () #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 What is the client here that is doing a persistent search or syncrepl? Is it BIND? Thread 1 (Thread 0x7fb856808800 (LWP 800)): #0 0x7fb853bcbc8d in poll () from /lib64/libc.so.6 #1 0x7fb8544f6da8 in _pr_poll_with_poll () from /lib64/libnspr4.so #2 0x7fb8565e9b11 in slapd_daemon () #3 0x7fb8565dc4f4 in main () [root@ipa log]# Best regards and thanks again Torsten /var/log/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE/errors: [root@ipa slapd-PLEIADES-UNI-WUPPERTAL-DE]# cat errors 389-Directory/1.3.3.8 B2015.036.047 ipa.pleiades.uni-wuppertal.de:636 (/etc/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE) [20/Jul/2015:16:48:26 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) errno 2 (No such file or directory) [20/Jul/2015:16:48:26 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) errno 2 (No such file or directory) [20/Jul/2015:16:48:26 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -2 (Local error) [20/Jul/2015:16:48:26 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Replication bind with GSSAPI auth failed: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) [20/Jul/2015:16:48:30 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) errno 2 (No such file or directory) [20/Jul/2015:16:48:30 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) errno 2 (No such file or directory) [20/Jul/2015:16:48:30 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -2 (Local error) [20/Jul/2015:16:48:36 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) errno 2 (No such file or directory) [20/Jul/2015:16:48:36 +0200] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Ticket expired)) errno 2 (No such file or directory) [20/Jul/2015:16:48:36 +0200] slapi_ldap_bind - Error: could not perform interactive bind for id [] authentication mechanism [GSSAPI]: error -2 (Local error) [20/Jul/2015:16:48:48 +0200] NSMMReplicationPlugin - agmt="cn=meToipa2.pleiades.uni-wuppertal.de" (ipa2:389): Replication bind with GSSAPI auth resumed [21/Jul/2015:14:41:05 +0200] find_sid_for_ldap_entry - [file ipa_sidgen_common.c, line 522]: Cannot convert Posix ID [50088] into an unused SID. [21/Jul/2015:14:41:05 +0200] ipa_sidgen_add_post_op - [file ipa_sidgen.c, li
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Wed, Jul 22, 2015 at 11:39:25AM +0200, Torsten Harenberg wrote: > Dear Alexander, dear Sumit, > > thank you very much indeed for the quick replies. > > Am 22.07.15 um 11:21 schrieb Sumit Bose: > > Looks like there are issues getting the needed data from the local LDAP > > server. The message below about the master key points into the same > > direction. Can you check the 389ds logs? > > I have attached the > /var/log/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE/errors file to the end > of the mail, it's a bit larger. > > There are some "ticket expired" messages, could that point to the source > of the problem? > > > Am 22.07.15 um 11:22 schrieb Alexander Bokovoy: > > Do you have 389-ds actually operating? If you would install debuginfo > > packages, what does 'pstack ' print? > > here is the output: Thank you for the logs. It looks like the KDC cannot talk to the LDAP server and the LDAP server cannot talk to the KDC to renew a Kerberos ticket. So we have to find out which came first. To rule out KDC lookup issues it would be good if you can send the content for /etc/krb5.conf and /var/lib/sss/pubconf/kdcinfo.* . Feel free to send it to Alexander and me by private mail if you do not want to disclose details of your environment on a public list. bye, Sumit -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Wed, 22 Jul 2015, Torsten Harenberg wrote: Dear Alexander, dear Sumit, thank you very much indeed for the quick replies. Am 22.07.15 um 11:21 schrieb Sumit Bose: Looks like there are issues getting the needed data from the local LDAP server. The message below about the master key points into the same direction. Can you check the 389ds logs? I have attached the /var/log/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE/errors file to the end of the mail, it's a bit larger. There are some "ticket expired" messages, could that point to the source of the problem? No. It is, in a sense, a chicken-and-egg problem -- something caused KDC to fail its connection to LDAP server and those LDAP server plugins that needed Kerberos authentication (replication, for example), attempted to obtain a ticket but failed because KDC failed. The backtrace is also showing no problems as it is. Most threads are simply in a wait state until clients come. Also, sidgen plugin has issues: [21/Jul/2015:14:41:05 +0200] find_sid_for_ldap_entry - [file ipa_sidgen_common.c, line 522]: Cannot convert Posix ID [50088] into an unused SID. [21/Jul/2015:14:41:05 +0200] ipa_sidgen_add_post_op - [file ipa_sidgen.c, line 149]: Cannot add SID to new entry. I'm slightly worried with the slapi-nis plugin reporting issues of talking to rpcbind to register itself. [21/Jul/2015:17:15:20 +0200] nis-plugin - error connecting rpcbind client socket to the service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - error sending request to portmap or rpcbind on 9: Connection refused [21/Jul/2015:17:15:24 +0200] nis-plugin - timeout registering with portmap service -- / Alexander Bokovoy -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
Dear Alexander, dear Sumit, thank you very much indeed for the quick replies. Am 22.07.15 um 11:21 schrieb Sumit Bose: > Looks like there are issues getting the needed data from the local LDAP > server. The message below about the master key points into the same > direction. Can you check the 389ds logs? I have attached the /var/log/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE/errors file to the end of the mail, it's a bit larger. There are some "ticket expired" messages, could that point to the source of the problem? Am 22.07.15 um 11:22 schrieb Alexander Bokovoy: > Do you have 389-ds actually operating? If you would install debuginfo > packages, what does 'pstack ' print? here is the output: [root@ipa log]# ps ax | grep slapd 800 ?Sl 0:33 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE -i /var/run/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE.pid -w /var/run/dirsrv/slapd-PLEIADES-UNI-WUPPERTAL-DE.startpid 1596 pts/0S+ 0:00 grep --color=auto slapd [root@ipa log]# pstack 800 Thread 47 (Thread 0x7fb843ae3700 (LWP 841)): #0 0x7fb853bcdae3 in select () from /lib64/libc.so.6 #1 0x7fb856145a99 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0 #2 0x7fb847d15987 in deadlock_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 46 (Thread 0x7fb8432e2700 (LWP 842)): #0 0x7fb853bcdae3 in select () from /lib64/libc.so.6 #1 0x7fb856145a99 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0 #2 0x7fb847d19a4e in checkpoint_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 45 (Thread 0x7fb842ae1700 (LWP 843)): #0 0x7fb853bcdae3 in select () from /lib64/libc.so.6 #1 0x7fb856145a99 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0 #2 0x7fb847d15c0f in trickle_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 44 (Thread 0x7fb8422e0700 (LWP 844)): #0 0x7fb853bcdae3 in select () from /lib64/libc.so.6 #1 0x7fb856145a99 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0 #2 0x7fb847d10667 in perf_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 43 (Thread 0x7fb841adf700 (LWP 924)): #0 0x7fb853bcbc8d in poll () from /lib64/libc.so.6 #1 0x7fb84720b1ab in dispatch_thread () from /usr/lib64/dirsrv/plugins/nisserver-plugin.so #2 0x7fb84721a7b7 in wrap_pthread_starter () from /usr/lib64/dirsrv/plugins/nisserver-plugin.so #3 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #4 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #5 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 42 (Thread 0x7fb8410d5700 (LWP 971)): #0 0x7fb853ea0590 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 #1 0x7fb8544f5440 in PR_WaitCondVar () from /lib64/libnspr4.so #2 0x7fb856135c68 in slapi_wait_condvar () from /usr/lib64/dirsrv/libslapd.so.0 #3 0x7fb84c8145be in cos_cache_wait_on_change () from /usr/lib64/dirsrv/plugins/libcos-plugin.so #4 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #5 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #6 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 41 (Thread 0x7fb8408d4700 (LWP 973)): #0 0x7fb853bcbc8d in poll () from /lib64/libc.so.6 #1 0x7fb84a193440 in ipa_cldap_worker () from /usr/lib64/dirsrv/plugins/libipa_cldap.so #2 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #3 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 40 (Thread 0x7fb85671c700 (LWP 1072)): #0 0x7fb853ea0939 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 #1 0x7fb8544f4ef8 in pt_TimedWait () from /lib64/libnspr4.so #2 0x7fb8544f53be in PR_WaitCondVar () from /lib64/libnspr4.so #3 0x7fb847a71e84 in _cl5TrimMain () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so #4 0x7fb8544facab in _pt_root () from /lib64/libnspr4.so #5 0x7fb853e9b52a in start_thread () from /lib64/libpthread.so.0 #6 0x7fb853bd722d in clone () from /lib64/libc.so.6 Thread 39 (Thread 0x7fb833fff700 (LWP 1073)): #0 0x7fb853ea0939 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 #1 0x7fb8544f4ef8 in pt_TimedWait (
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Wed, 22 Jul 2015, Torsten Harenberg wrote:
Dear community,
we just moved our infrastructure (about 200 node cluster plus about 30
workstations) from NIS to FreeIPA (version 4.1.4 on FC 21).
We have two IPA servers (called "ipa" and "ipa2" both paravirtualized on
Xen4).
Approx once a day, the Kerberos service on the primary server suddenly
stops working and I am unable to re-start the service. Only a "full"
reboot helps and during that, the Kerberos shutdown takes about 2
minutes (unsure if it really finishes or if it's the final timeout of
the shutdown script).
Trying to collect as many log messages as possible:
Jul 22 10:52:06 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
AS_REQ (4 etypes {18 17 16 23}) 132.195.124.213: LOOKING_UP_CLIENT:
host/proton.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de for
krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de, Server error
Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
AS_REQ (4 etypes {18 17 16 23}) 132.195.125.171: LOOKING_UP_CLIENT:
host/wn161.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de for
krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de, Server error
Looking at the Kerberos KDC code I see that LOOKING_UP_CLIENT is shown
when DAL driver returns something different than 'entry does not exist':
errcode = krb5_db_get_principal(kdc_context, state->request->client,
state->c_flags, &state->client);
if (errcode == KRB5_KDB_CANTLOCK_DB)
errcode = KRB5KDC_ERR_SVC_UNAVAILABLE;
if (errcode == KRB5_KDB_NOENTRY) {
state->status = "CLIENT_NOT_FOUND";
if (vague_errors)
errcode = KRB5KRB_ERR_GENERIC;
else
errcode = KRB5KDC_ERR_C_PRINCIPAL_UNKNOWN;
goto errout;
} else if (errcode) {
state->status = "LOOKING_UP_CLIENT";
goto errout;
}
Our DAL driver may return KRB5_KDB_DBNOTINITED, KRB5_KDB_SERVER_INTERNAL_ERR,
or KRB5_KDB_INTERNAL_ERROR which all may point towards 389-ds failures.
Do you have 389-ds actually operating? If you would install debuginfo
packages, what does 'pstack ' print?
--
/ Alexander Bokovoy
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Kerberos hanging approx. once a day
On Wed, Jul 22, 2015 at 11:06:53AM +0200, Torsten Harenberg wrote:
> Dear community,
>
> we just moved our infrastructure (about 200 node cluster plus about 30
> workstations) from NIS to FreeIPA (version 4.1.4 on FC 21).
>
> We have two IPA servers (called "ipa" and "ipa2" both paravirtualized on
> Xen4).
>
> Approx once a day, the Kerberos service on the primary server suddenly
> stops working and I am unable to re-start the service. Only a "full"
> reboot helps and during that, the Kerberos shutdown takes about 2
> minutes (unsure if it really finishes or if it's the final timeout of
> the shutdown script).
>
> Trying to collect as many log messages as possible:
>
>
> Jul 22 10:52:06 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> AS_REQ (4 etypes {18 17 16 23}) 132.195.124.213: LOOKING_UP_CLIENT:
> host/proton.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de for
> krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de, Server error
> Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> AS_REQ (4 etypes {18 17 16 23}) 132.195.125.171: LOOKING_UP_CLIENT:
> host/wn161.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de for
> krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de, Server error
Looks like there are issues getting the needed data from the local LDAP
server. The message below about the master key points into the same
direction. Can you check the 389ds logs?
bye,
Sumit
>
>
> [root@ipa ~]# systemctl status krb5kdc.service
> ● krb5kdc.service - Kerberos 5 KDC
>Loaded: loaded (/usr/lib/systemd/system/krb5kdc.service; disabled)
>Active: failed (Result: exit-code) since Mi 2015-07-22 10:54:22 CEST;
> 10s ago
> Process: 11910 ExecStart=/usr/sbin/krb5kdc -P /var/run/krb5kdc.pid
> $KRB5KDC_ARGS (code=exited, status=1/FAILURE)
> Main PID: 1114 (code=exited, status=0/SUCCESS)
>
> Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de krb5kdc[11910]: krb5kdc:
> cannot initialize realm PLEIADES.UNI-WUPPERTAL.DE - see log file for details
> Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]:
> krb5kdc.service: control process exited, code=exited status=1
> Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]: Failed to
> start Kerberos 5 KDC.
> Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]: Unit
> krb5kdc.service entered failed state.
> Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]:
> krb5kdc.service failed.
> [root@ipa ~]# tail -f /var/log/krb5kdc.log
> Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> closing down fd 13
> Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> DISPATCH: repeated (retransmitted?) request from 132.195.124.213,
> resending previous response
> Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> DISPATCH: repeated (retransmitted?) request from 132.195.125.171,
> resending previous response
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](debug): Got
> signal to request exit
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> closing down fd 10
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> closing down fd 11
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> closing down fd 9
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> closing down fd 8
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
> shutting down
> krb5kdc: Server error - while fetching master key K/M for realm
> PLEIADES.UNI-WUPPERTAL.DE
>
>
> [root@ipa ~]# journalctl -xe
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen and
> drop on 1 v6wildcard :: UDP 123
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
> normally on 2 lo 127.0.0.1 UDP 123
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
> normally on 3 eth0 132.195.124.12 UDP 123
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
> normally on 4 lo ::1 UDP 123
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
> normally on 5 eth0 fe80::216:3eff:fe14:c27a UDP 123
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listening on
> routing socket on fd #22 for interface updates
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de systemd[1]: Started
> Network Time Service.
> -- Subject: Unit ntpd.service has finished start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ntpd.service has finished starting up.
> --
> -- The start-up result is done.
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: 0.0.0.0 c016
> 06 restart
> Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: 0.0.0.0 c012
> 02 freq_set ntpd -23.557 PPM
> Jul 22 10:53:16 ipa.pleiades.uni-wuppertal.de ntpd[11903]: 0.0.0.0 c615
> 05 clock_sync
> Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de systemd[1]: Stopping
> Kerberos 5 KDC...
> -- Subject: Unit krb5kdc.service has begun shutting
[Freeipa-users] Kerberos hanging approx. once a day
Dear community,
we just moved our infrastructure (about 200 node cluster plus about 30
workstations) from NIS to FreeIPA (version 4.1.4 on FC 21).
We have two IPA servers (called "ipa" and "ipa2" both paravirtualized on
Xen4).
Approx once a day, the Kerberos service on the primary server suddenly
stops working and I am unable to re-start the service. Only a "full"
reboot helps and during that, the Kerberos shutdown takes about 2
minutes (unsure if it really finishes or if it's the final timeout of
the shutdown script).
Trying to collect as many log messages as possible:
Jul 22 10:52:06 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
AS_REQ (4 etypes {18 17 16 23}) 132.195.124.213: LOOKING_UP_CLIENT:
host/proton.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de for
krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de, Server error
Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
AS_REQ (4 etypes {18 17 16 23}) 132.195.125.171: LOOKING_UP_CLIENT:
host/wn161.pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de for
krbtgt/pleiades.uni-wuppertal...@pleiades.uni-wuppertal.de, Server error
[root@ipa ~]# systemctl status krb5kdc.service
● krb5kdc.service - Kerberos 5 KDC
Loaded: loaded (/usr/lib/systemd/system/krb5kdc.service; disabled)
Active: failed (Result: exit-code) since Mi 2015-07-22 10:54:22 CEST;
10s ago
Process: 11910 ExecStart=/usr/sbin/krb5kdc -P /var/run/krb5kdc.pid
$KRB5KDC_ARGS (code=exited, status=1/FAILURE)
Main PID: 1114 (code=exited, status=0/SUCCESS)
Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de krb5kdc[11910]: krb5kdc:
cannot initialize realm PLEIADES.UNI-WUPPERTAL.DE - see log file for details
Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]:
krb5kdc.service: control process exited, code=exited status=1
Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]: Failed to
start Kerberos 5 KDC.
Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]: Unit
krb5kdc.service entered failed state.
Jul 22 10:54:22 ipa.pleiades.uni-wuppertal.de systemd[1]:
krb5kdc.service failed.
[root@ipa ~]# tail -f /var/log/krb5kdc.log
Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
closing down fd 13
Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
DISPATCH: repeated (retransmitted?) request from 132.195.124.213,
resending previous response
Jul 22 10:52:11 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
DISPATCH: repeated (retransmitted?) request from 132.195.125.171,
resending previous response
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](debug): Got
signal to request exit
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
closing down fd 10
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
closing down fd 11
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
closing down fd 9
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
closing down fd 8
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de krb5kdc[1114](info):
shutting down
krb5kdc: Server error - while fetching master key K/M for realm
PLEIADES.UNI-WUPPERTAL.DE
[root@ipa ~]# journalctl -xe
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen and
drop on 1 v6wildcard :: UDP 123
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
normally on 2 lo 127.0.0.1 UDP 123
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
normally on 3 eth0 132.195.124.12 UDP 123
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
normally on 4 lo ::1 UDP 123
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listen
normally on 5 eth0 fe80::216:3eff:fe14:c27a UDP 123
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: Listening on
routing socket on fd #22 for interface updates
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de systemd[1]: Started
Network Time Service.
-- Subject: Unit ntpd.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit ntpd.service has finished starting up.
--
-- The start-up result is done.
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: 0.0.0.0 c016
06 restart
Jul 22 10:53:15 ipa.pleiades.uni-wuppertal.de ntpd[11903]: 0.0.0.0 c012
02 freq_set ntpd -23.557 PPM
Jul 22 10:53:16 ipa.pleiades.uni-wuppertal.de ntpd[11903]: 0.0.0.0 c615
05 clock_sync
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de systemd[1]: Stopping
Kerberos 5 KDC...
-- Subject: Unit krb5kdc.service has begun shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit krb5kdc.service has begun shutting down.
Jul 22 10:54:12 ipa.pleiades.uni-wuppertal.de systemd[1]: Starting
Kerberos 5 KDC...
-- Subject: Unit krb5kdc.service has begun with start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit krb5kdc.service has begun starting up.
Jul 22 10:54:22 ipa.pleiad
