https://bugzilla.redhat.com/show_bug.cgi?id=742875
Description of problem: After installing ipa-server with --setup-dns, if you have the short hostname ahead of fqdn in /etc/hosts, named fails to start. sssd tries to do a GSSAPI auth with the short hostname and does not find its respective principal in kerberos. Setting `hostname -s` at the end solves this issue. Version-Release number of selected component (if applicable): sssd-1.5.1-53.el6.x86_64 How reproducible: Always Steps to Reproduce: 1. Configure your /etc/hosts as [root@jetfire ]# cat /etc/hosts 127.0.0.1 localhost localhost.localdomain localhost4 localhost4.localdomain4 ::1 localhost6 localhost6.localdomain6 2620:52:0:41c9:5054:ff:fea8:b669 jetfire jetfire.lab.eng.pnq.redhat.com 2. Install ipa-server <snip> Configuring named: [1/9]: adding DNS container [2/9]: setting up our zone [3/9]: setting up reverse zone [4/9]: setting up our own record [5/9]: setting up kerberos principal [6/9]: setting up named.conf [7/9]: restarting named named service failed to start <<<<<<<<<<<<<< [8/9]: configuring named to start on boot [9/9]: changing resolv.conf to point to ourselves done configuring named. </snip> 3. service named resart # service named restart Stopping named: [ OK ] Starting named: [FAILED] Actual results: named fails to start. named starts successfully when I set the fqdn followed by `hostname -s` in /etc/hosts. Expected results: named should start successfully even when `hostname -s` preceeds fqdn in /etc/hosts. In RHEL6.2 the default /etc/hosts looks like: # cat /etc/hosts 127.0.0.1 localhost localhost.localdomain localhost4 localhost4.localdomain4 ::1 localhost localhost.localdomain localhost6 localhost6.localdomain6 So, it would be quite common for users to add `hostname -s` ahead of fqdn as that is how we specify for localhost. Additional info: /var/log/messages: Oct 3 03:03:06 jetfire named[15335]: starting BIND 9.7.3-P3-RedHat-9.7.3-7.P3.el6 -u named Oct 3 03:03:06 jetfire named[15335]: built with '--build=x86_64-redhat-linux-gnu' '--host=x86_64-redhat-linux-gnu' '--target=x86_64-redhat-linux-gnu' '--program-prefix=' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sbin' '--sysconfdir=/etc' '--datadir=/usr/share' '--includedir=/usr/include' '--libdir=/usr/lib64' '--libexecdir=/usr/libexec' '--sharedstatedir=/var/lib' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--with-libtool' '--localstatedir=/var' '--enable-threads' '--enable-ipv6' '--with-pic' '--disable-static' '--disable-openssl-version-check' '--with-dlz-ldap=yes' '--with-dlz-postgres=yes' '--with-dlz-mysql=yes' '--with-dlz-filesystem=yes' '--with-gssapi=yes' '--disable-isc-spnego' '--with-docbook-xsl=/usr/share/sgml/docbook/xsl-stylesheets' 'build_alias=x86_64-redhat-linux-gnu' 'host_alias=x86_64-redhat-linux-gnu' 'target_alias=x86_64-redhat-linux-gnu' 'CFLAGS= -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic' 'CPPFLAGS= -DDIG_SIGCHASE' Oct 3 03:03:06 jetfire named[15335]: adjusted limit on open files from 1024 to 1048576 Oct 3 03:03:06 jetfire named[15335]: found 1 CPU, using 1 worker thread Oct 3 03:03:06 jetfire named[15335]: using up to 4096 sockets Oct 3 03:03:06 jetfire named[15335]: loading configuration from '/etc/named.conf' Oct 3 03:03:06 jetfire named[15335]: using default UDP/IPv4 port range: [1024, 65535] Oct 3 03:03:06 jetfire named[15335]: using default UDP/IPv6 port range: [1024, 65535] Oct 3 03:03:06 jetfire named[15335]: listening on IPv6 interfaces, port 53 Oct 3 03:03:06 jetfire named[15335]: listening on IPv4 interface lo, 127.0.0.1#53 Oct 3 03:03:06 jetfire named[15335]: generating session key for dynamic DNS =============================== Oct 3 03:03:06 jetfire sssd_be: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Server ldap/jetfire@LAB.ENG.PNQ.REDHAT.COM not found in Kerberos database) Oct 3 03:03:16 jetfire named[15335]: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Server ldap/jetfire@LAB.ENG.PNQ.REDHAT.COM not found in Kerberos database) =============================== Oct 3 03:03:16 jetfire named[15335]: bind to LDAP server failed: Local error Oct 3 03:03:16 jetfire named[15335]: loading configuration: failure Oct 3 03:03:16 jetfire named[15335]: exiting (due to fatal error) /var/log/sssd/sssd_lab.eng.pnq.redhat.com.log: (Mon Oct 3 03:03:05 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): dbus conn: 24C3850 (Mon Oct 3 03:03:05 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): Dispatching. (Mon Oct 3 03:03:05 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_message_handler] (9): Received SBUS method [ping] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): dbus conn: 24D6990 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): Dispatching. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_get_account_info] (4): Got request for [4099][1][name=named] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_get_account_info] (4): Request processed. Returned 1,11,Fast reply - offline (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_step] (9): beginning to connect (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (7): Port status of port 0 for server 'jetfire.lab.eng.pnq.redhat.com' is 'not working' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (4): Reseting the status of port 0 for server 'jetfire.lab.eng.pnq.redhat.com' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_resolve_server_done] (4): Found address for server jetfire.lab.eng.pnq.redhat.com: [2620:52:0:41c9:5054:ff:fea8:b669] TTL 7200 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ipa_resolve_callback] (6): Constructed uri 'ldap://jetfire.lab.eng.pnq.redhat.com' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sss_ldap_init_send] (9): Using file descriptor [27] for LDAP connection. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://jetfire.lab.eng.pnq.redhat.com:389/??base] with fd [27]. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_rootdse_send] (9): Getting rootdse (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (6): calling ldap_search_ext with [(objectclass=*)][]. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [*] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [altServer] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [namingContexts] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedControl] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedExtension] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedFeatures] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedLDAPVersion] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedSASLMechanisms] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [defaultNamingContext] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [lastUSN] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [highestCommittedUSN] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (8): ldap_search_ext called, msgid = 1 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x24e6b10], connected[1], ops[0x24d9050], ldap[0x24e7890] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_parse_entry] (9): OriginalDN: []. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x24e6b10], connected[1], ops[0x24d9050], ldap[0x24e7890] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (6): Search result: Success(0), (null) (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_rootdse_done] (9): Got rootdse (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_send] (6): Attempting kinit ((null), host/jetfire.lab.eng.pnq.redhat.com, LAB.ENG.PNQ.REDHAT.COM, 86400) (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_next_kdc] (7): Resolving next KDC for service IPA (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (7): Port status of port 0 for server 'jetfire.lab.eng.pnq.redhat.com' is 'neutral' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_resolve_server_done] (4): Found address for server jetfire.lab.eng.pnq.redhat.com: [2620:52:0:41c9:5054:ff:fea8:b669] TTL 7200 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_kdc_resolved] (7): KDC resolved, attempting to get TGT... (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [create_tgt_req_send_buffer] (7): buffer size: 73 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_handler_setup] (8): Setting up signal handler up for pid [15334] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_handler_setup] (8): Signal handler set up for pid [15334] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [set_tgt_child_timeout] (6): Setting 6 seconds timeout for tgt child (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x24e6b10], connected[1], ops[(nil)], ldap[0x24e7890] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: ldap_result found nothing! (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [write_pipe_handler] (6): All data has been sent! (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [read_pipe_handler] (6): EOF received, client finished (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_tgt_recv] (6): Child responded: 0 [FILE:/var/lib/sss/db/ccache_LAB.ENG.PNQ.REDHAT.COM], expired on [1317711786] =============================== (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sasl_bind_send] (4): Executing sasl bind mech: GSSAPI, user: host/jetfire.lab.eng.pnq.redhat.com (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sasl_bind_send] (1): ldap_sasl_bind failed (-2)[Local error] =============================== (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_sig_handler] (7): Waiting for child [15334]. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_sig_handler] (4): child [15334] finished successfully. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_set_port_status] (4): Marking port 0 of server 'jetfire.lab.eng.pnq.redhat.com' as 'not working' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_handle_release] (8): Trace: sh[0x24e6b10], connected[1], ops[(nil)], ldap[0x24e7890], destructor_lock[0], release_memory[0] (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [remove_connection_callback] (9): Successfully removed connection callback. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (9): attempting failover retry on op #1 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_step] (9): beginning to connect (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (7): Port status of port 0 for server 'jetfire.lab.eng.pnq.redhat.com' is 'not working' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (1): No available servers for service 'IPA' (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_release_conn_data] (9): releasing unused connection (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (1): Failed to connect, going offline (5 [Input/output error]) (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_mark_offline] (8): Going offline! (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_run_offline_cb] (3): Going offline. Running callbacks. (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (9): notify offline to op #1 (Mon Oct 3 03:03:06 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_release_conn_data] (9): releasing unused connection (Mon Oct 3 03:03:07 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [remove_krb5_info_files] (5): Could not remove [/var/lib/sss/pubconf/kpasswdinfo.LAB.ENG.PNQ.REDHAT.COM], [2][No such file or directory]
attachment freeipa-rcrit-888-hostname.patch
Martin, your patch is superior to mine, going to let you follow this up.
attachment freeipa-mkosek-140-check-hostname-resolution-sanity.patch
Patch freeipa-mkosek-140-check-hostname-resolution-sanity.patch sent for review
master:[[br]] 363c23a[[br]] 9bff6cb
ipa-2-1:[[br]] 58918c4[[br]] 93feb52
Metadata Update from @dpal: - Issue assigned to mkosek - Issue set to the milestone: FreeIPA 2.1.3 (bug fixing)
Login to comment on this ticket.