Bug 863646

Summary: dhclient segfault; dns_client_cancelupdate () from /lib64/libdns-export.so.93
Product: [Fedora] Fedora Reporter: fedora-bugs
Component: dhcpAssignee: Jiri Popelka <jpopelka>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 17CC: jpopelka, thozza
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-07-31 21:31:19 EDT Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Description fedora-bugs 2012-10-06 05:39:44 EDT
Description of problem:

When dhclient requests an ip address, dhclient complains about formatting issues with the dhclient.conf (/etc/dhcp/dhclient.conf) file, but otherwise follows the directives in dhclient.conf:

Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 18: semicolon expected.
Oct  4 05:59:10 client dhclient[8217]: #011do-forward-updates false;
Oct  4 05:59:10 client dhclient[8217]:                             ^
Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 20: semicolon expected.
Oct  4 05:59:10 client dhclient[8217]: #011request
Oct  4 05:59:10 client dhclient[8217]:          ^
Oct  4 05:59:10 client dhclient[8217]: DHCPREQUEST on p1p1 to 255.255.255.255 port 67 (xid=0xdd81aea)
Oct  4 05:59:10 client dhclient[8217]: DHCPACK from x.x.x.x (xid=0xdd81aea)
Oct  4 05:59:12 client NET[8279]: /usr/sbin/dhclient-script : updated /etc/resolv.conf
Oct  4 05:59:12 client dhclient[8217]: bound to y.y.y.y -- renewal in 61319 seconds.

The client is setup to update its dns record dynamically. At this point, the dns server receives the client's ip (y.y.y.y) update appropriately. 

Afterwards, when dhclient is to renew the address, it segfaults right after renewal:

Oct  5 23:03:13 client dhclient[8287]: DHCPREQUEST on p1p1 to x.x.x.x port 67 (xid=0xdd81aea)
Oct  5 23:03:14 client dhclient[8287]: DHCPACK from x.x.x.x (xid=0xdd81aea)
Oct  5 23:03:16 client dhclient[8287]: bound to y.y.y.y -- renewal in 104947 seconds.
Oct  5 23:03:16 client kernel: [479353.075866] dhclient[8287]: segfault at 65736c61663d ip 00007f6810cc07f2 sp 00007fffcd56dad0 error 4 in libdns-export.so.93.1.1[7f6810c8a000+113000]

At this point, the server receives no dynamic dns update request from the client. 

This is what is in the dhclient.conf file:

key client.dns.example.com {
    algorithm HMAC-MD5;
    secret "[0-9a-zA-Z=]+";
}

zone dns.example.com {
        primary ns1.example.com;
        key client.dns.example.com;
}

interface "p1p1" {
        supersede domain-name "dns.example.com";
        send fqdn.fqdn "client.dns.example.com.";
        send fqdn.encoded off;
        send fqdn.server-update off;
        retry 90;

        do-forward-updates false;
        request subnet-mask, broadcast-address, dhcp-lease-time, time-offset, routers, domain-name-servers;
        prepend domain-name-servers 127.0.0.1;
        prepend domain-search "example.com";
        prepend domain-search "backend.example.com";
}

Version-Release number of selected component (if applicable):

bind-libs.x86_64                       32:9.9.1-9.P3.fc17
bind-libs-lite.x86_64                  32:9.9.1-9.P3.fc17
bind-utils.x86_64                      32:9.9.1-9.P3.fc17
dhclient.x86_64                        12:4.2.4-13.P2.fc17

How reproducible:

This has been going on for quite some time. IIRC, it worked fine in Fedora 13. The issue occurred for the first time in Fedora 14 but could be resolved by using dhclient from Fedora 13. The client has now been (freshly) reinstalled (not upgraded) to Fedora 17 (skipping Fedora 15 and 16) and the issue occurs again. The exact error messages when this occurred in Fedora 14 are unavailable but the pattern is similar to what's reoccurring in Fedora 17.

Steps to Reproduce:
1. Setup dhclient.conf accordingly
2. Use Fedora 14 or 17 with dhclient belonging to Fedora 14 or 17 respectively.
  
Actual results:

Aforementioned dhclient error messages and dhclient segfault.

Expected results:

No dhclient error messages and no dhclient segfault.

Additional info:

The messages appearing in /var/log/messages concerning "semicolon expected" make no sense. Either a semicolon is present where it is supposedly expected, or else a semicolon isn't be present where it is fallaciously expected. 

The '#011' string is apparently the tab character which should be fine. 

When the segfault occurs, selinux reports something akin to:

auid=0 uid=0 gid=0 ses=57 subj=unconfined_u:system_r:dhcpc_t:s0-s0:c0.c1023 pid=8287 comm="dhclient" reason="memory violation" sig=11
Comment 1 Jiri Popelka 2012-10-08 08:19:56 EDT
(In reply to comment #0)

> Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 18:
> semicolon expected.
> Oct  4 05:59:10 client dhclient[8217]: #011do-forward-updates false;
> Oct  4 05:59:10 client dhclient[8217]:                             ^
> Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 20:
> semicolon expected.
> Oct  4 05:59:10 client dhclient[8217]: #011request

Your dhclient.conf looks ok, I'll try to reproduce the error messages here.

> Oct  5 23:03:16 client kernel: [479353.075866] dhclient[8287]: segfault at
> 65736c61663d ip 00007f6810cc07f2 sp 00007fffcd56dad0 error 4 in
> libdns-export.so.93.1.1[7f6810c8a000+113000]

This is probably not related to the error messages.
Would you be able to get some stack trace ?
The ways how to do that are described here
http://fedoraproject.org/wiki/StackTraces
You'll need dhcp-debuginfo and bind-debuginfo packages.

> auid=0 uid=0 gid=0 ses=57 subj=unconfined_u:system_r:dhcpc_t:s0-s0:c0.c1023
> pid=8287 comm="dhclient" reason="memory violation" sig=11

This looks more like a logging of the segfault than SELinux AVC. Could you try to reproduce the problem with SELinux in Permissive mode: 'setenforce 0' ?

Also: what does 'restorecon -v /usr/sbin/dhclient*' show ?
Comment 2 fedora-bugs 2012-10-08 18:27:17 EDT
(In reply to comment #1)
> (In reply to comment #0)
> 
> > Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 18:
> > semicolon expected.
> > Oct  4 05:59:10 client dhclient[8217]: #011do-forward-updates false;
> > Oct  4 05:59:10 client dhclient[8217]:                             ^
> > Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 20:
> > semicolon expected.
> > Oct  4 05:59:10 client dhclient[8217]: #011request
> 
> Your dhclient.conf looks ok, I'll try to reproduce the error messages here.
> 
> > Oct  5 23:03:16 client kernel: [479353.075866] dhclient[8287]: segfault at
> > 65736c61663d ip 00007f6810cc07f2 sp 00007fffcd56dad0 error 4 in
> > libdns-export.so.93.1.1[7f6810c8a000+113000]
> 
> This is probably not related to the error messages.
> Would you be able to get some stack trace ?
> The ways how to do that are described here
> http://fedoraproject.org/wiki/StackTraces
> You'll need dhcp-debuginfo and bind-debuginfo packages.

I have to setup a similar configuration elsewhere, as the host where this is occurring is beyond my physical reach and I can't afford to play around (too much) with it remotely. I'll see if I can setup a pair of virtual machines in order to reproduce the bug.

> 
> > auid=0 uid=0 gid=0 ses=57 subj=unconfined_u:system_r:dhcpc_t:s0-s0:c0.c1023
> > pid=8287 comm="dhclient" reason="memory violation" sig=11
> 
> This looks more like a logging of the segfault than SELinux AVC. Could you
> try to reproduce the problem with SELinux in Permissive mode: 'setenforce 0'
> ?

It is the selinux log entry, which is not a denial, rather this was included to illustrate that the segfault is (apparently) not due to selinux getting in the way. 

'setenforce 0' is also going to be difficult or else undesirable with this particular machine, in this case because of security constraints. 

> 
> Also: what does 'restorecon -v /usr/sbin/dhclient*' show ?

Empty output. 

$ ls -lZ /usr/sbin/dhclient*
-rwxr-xr-x. root root system_u:object_r:dhcpc_exec_t:s0 /usr/sbin/dhclient
-rwxr-xr-x. root root system_u:object_r:dhcpc_exec_t:s0 /usr/sbin/dhclient-script

I've been trying to rule out the segfault being due to faulty memory. No other processes report segfaults and when the machine was running Fedora 14 (with dhclient from Fedora 13), it had been running for over 600 days, providing a variety of services, without any issues. I'm 99% sure it's not due to faulty memory.

I'll be setting up a pair of VMs to see if I can mimic the behaviour in an environment I can play around with. 

Thanks.
Comment 3 Jiri Popelka 2012-10-09 09:05:51 EDT
(In reply to comment #0)
> Oct  4 05:59:10 client dhclient[8217]: /etc/dhcp/dhclient.conf line 18:
> semicolon expected.
> Oct  4 05:59:10 client dhclient[8217]: #011do-forward-updates false;

The do-forward-updates statement hasn't actually been recognized at all - the lexical analyzer was looking for do-forward-update (notice the missing s).

It should be fixed with this build:
https://koji.fedoraproject.org/koji/taskinfo?taskID=4574069
Comment 4 fedora-bugs 2012-10-10 05:07:06 EDT
The issue with singular/plural is interesting. 

After installing 4.2.4-15.P2:

Oct 10 10:07:28 client dhclient[25456]: DHCPREQUEST on p1p1 to 255.255.255.255 port 67 (xid=0x73360b63)
Oct 10 10:07:28 client dhclient[25456]: DHCPACK from x.x.x.x (xid=0x73360b63)
Oct 10 10:07:30 client NET[25517]: /usr/sbin/dhclient-script : updated /etc/resolv.conf
Oct 10 10:07:30 client dhclient[25456]: bound to y.y.y.y -- renewal in 111443 seconds.

So the dhclient.conf format/parse issues aren't showing up anymore. 

The segfault normally occurs upon the first renewal after the lease is initially obtained, so we'll have to wait and see.

It would be (historically) interesting to see if the plural 'do-forward-updates' (rather than the singular 'do-forward-update') was being recognized/parsed in a version prior to 4.2.4-13.P2. IIRC, the client used to or else was intended to update its dns record using the dhclient-script but was switched to having dhclient do the update, possibly because 'do-forward-updates' wasn't having any effect. Suffice to say, with the current intention of dhclient doing the dns update, 'do-forward-updates' is currently set to 'true'.

Thanks.
Comment 5 Jiri Popelka 2012-10-10 06:42:52 EDT
I reported it upstream and will post the response here.

Yes, it's interesting because the the same code is in all older (the oldest being 3.0.5) versions I looked at.
Comment 6 fedora-bugs 2012-10-11 15:38:19 EDT
The renewal went fine;

Oct 11 21:35:00 client dhclient[26522]: DHCPREQUEST on p1p1 to x.x.x.x port 67 (xid=0x39073654)
Oct 11 21:35:00 client dhclient[26522]: DHCPACK from x.x.x.x (xid=0x39073654)
Oct 11 21:35:02 client dhclient[26522]: bound to y.y.y.y -- renewal in 56150 seconds.

and the client appropriately updated its dns record. 

It seems like that's the end of this bug. 

Thanks a lot.
Comment 7 Jiri Popelka 2012-10-12 09:18:11 EDT
That's nice but we only hide the bug by making the client to finally set the do-forward-updates to false. Previously it was not recognized, i.e. set to default value = true (according to dhclient.conf(5)).

Setting it to true or removing it at all should AFAICT reveal it again.
Comment 8 fedora-bugs 2012-10-16 07:36:42 EDT
(In reply to comment #7)
> That's nice but we only hide the bug by making the client to finally set the
> do-forward-updates to false. Previously it was not recognized, i.e. set to
> default value = true (according to dhclient.conf(5)).
> 
> Setting it to true or removing it at all should AFAICT reveal it again.

You're correct. It took some time but it showed up again:

Oct 14 16:47:17 client dhclient[26522]: DHCPREQUEST on p1p1 to x.x.x.x port 67 (xid=0x39073654)
Oct 14 16:47:17 client dhclient[26522]: DHCPACK from x.x.x.x (xid=0x39073654)
Oct 14 16:47:20 client dhclient[26522]: bound to y.y.y.y -- renewal in 109597 seconds.
Oct 14 16:47:20 client kernel: [1234396.489896] dhclient[26522] general protection ip:7fb5a35d27f2 sp:7fff817b3e50 error:0 in libdns-export.so.93.1.1[7fb5a359c000+113000]

Different failure (symptoms), but still failing. 

I can also confirm that dhclient wasn't crashing on Fedora 13. It started with Fedora 14's dhclient, although I can't say anything about Fedora 15 and 16.
Comment 9 fedora-bugs 2012-10-23 20:41:39 EDT
I've setup 2 VMs on a host, both guests running Fedora 17 with the latest dhclient/bind/dhcp packages.

Both guests have 2 network interfaces, one interface (eth0) bridged with the host's LAN interface, and one interface (eth1) which is bridged with an internal interface on the host. Both guests are running 2 instances of dhclient, one for each of their interfaces.

One guest (guest 00) is using the default setup for its network interfaces. The other guest (guest 01) is using the default setup with the addition of the following /etc/dhcp/dhclient.conf: 

#
# guest 01
#

key dynamic.example.com {
        algorithm HMAC-MD5;
        secret "...";
}

zone example.com {
        primary 10.14.17.254; # the physical host's IP 
        key dynamic.example.com;
}

interface "eth1" { # 
        supersede domain-name "example.com";
        send fqdn.fqdn "dynamic.example.com.";
        send fqdn.encoded off;
        send fqdn.server-update off;
        retry 90;

        request subnet-mask, broadcast-address, dhcp-lease-time, time-offset, routers, domain-name-servers;
        prepend domain-name-servers 127.0.0.1;
        prepend domain-search "example.com";
}

The dhclients running on guest 00 have been running non-stop. The dhclients running on guest 01 both crash on the first renewal of their lease. The stack trace of the dhclient which is running on eth1 is very sparse, but shows the following output:

Program received signal SIGABRT, Aborted.
0x00007fbbce9b0925 in raise () from /lib64/libc.so.6
#0  0x00007fbbce9b0925 in raise () from /lib64/libc.so.6
#1  0x00007fbbce9b20d8 in abort () from /lib64/libc.so.6
#2  0x00007fbbcf3a108f in isc_assertion_failed () from /lib64/libisc-export.so.90
#3  0x00007fbbcf6178c7 in dns_client_cancelupdate () from /lib64/libdns-export.so.93
#4  0x00007fbbcfd679cd in ?? ()
#5  0x00007fbbcfd525bd in ?? ()
#6  0x00007fbbcfd52905 in ?? ()
#7  0x00007fbbcfd52cff in ?? ()
#8  0x00007fbbcfd4d5f6 in ?? ()
#9  0x00007fbbcfd739fc in do_packet ()
#10 0x00007fbbcfd63380 in ?? ()
#11 0x00007fbbcf9091e6 in omapi_iscsock_cb () from /lib64/libomapi.so.0
#12 0x00007fbbcf3c03bd in ?? () from /lib64/libisc-export.so.90
#13 0x00007fbbcf3c72ab in isc__taskmgr_dispatch () from /lib64/libisc-export.so.90
#14 0x00007fbbcf3caa82 in ?? () from /lib64/libisc-export.so.90
#15 0x00007fbbcfd64ed4 in ?? ()
#16 0x00007fbbcfd47993 in main ()
Comment 10 Jiri Popelka 2012-11-01 05:12:01 EDT
I tried to configure something similar as your guest01 here,
but I haven't been able to reproduce the crash.
Could there be any other configuration involved, like dhcp & dns server ?
Can you attach it here or send it to my email ?
Comment 11 Jiri Popelka 2012-11-02 08:26:31 EDT
(In reply to comment #9)
> #4  0x00007fbbcfd679cd in ?? ()
> #5  0x00007fbbcfd525bd in ?? ()
> #6  0x00007fbbcfd52905 in ?? ()
> #7  0x00007fbbcfd52cff in ?? ()
> #8  0x00007fbbcfd4d5f6 in ?? ()

The most important part is missing,
have you had dhcp-debuginfo installed ?
Comment 12 Jiri Popelka 2012-11-02 09:12:33 EDT
I made this [1] scratch-build with debugging of DNS updates turned on - this way we should see (/var/log/messages) the requests and replies between the DHCP code and the DNS library code. It'd be welcome if you could install it (also the debuginfo package) on guest01 and try it once more. Thanks.

[1] http://koji.fedoraproject.org/koji/taskinfo?taskID=4649587
Comment 13 fedora-bugs 2012-11-02 09:16:15 EDT
(In reply to comment #10)
> I tried to configure something similar as your guest01 here,
> but I haven't been able to reproduce the crash.

That's peculiar. 

> Could there be any other configuration involved, like dhcp & dns server ?

There is no configuration change/addition other than the addition of aforementioned /etc/dhcp/dhclient.conf.
Comment 14 fedora-bugs 2012-11-02 09:16:45 EDT
(In reply to comment #11)
> (In reply to comment #9)
> > #4  0x00007fbbcfd679cd in ?? ()
> > #5  0x00007fbbcfd525bd in ?? ()
> > #6  0x00007fbbcfd52905 in ?? ()
> > #7  0x00007fbbcfd52cff in ?? ()
> > #8  0x00007fbbcfd4d5f6 in ?? ()
> 
> The most important part is missing,
> have you had dhcp-debuginfo installed ?

Yes, together with bind-debuginfo.
Comment 15 fedora-bugs 2012-11-02 09:17:50 EDT
(In reply to comment #12)
> I made this [1] scratch-build with debugging of DNS updates turned on - this
> way we should see (/var/log/messages) the requests and replies between the
> DHCP code and the DNS library code. It'd be welcome if you could install it
> (also the debuginfo package) on guest01 and try it once more. Thanks.
> 
> [1] http://koji.fedoraproject.org/koji/taskinfo?taskID=4649587

I'll try this out. 

Thanks.
Comment 17 fedora-bugs 2013-03-01 00:30:41 EST
I recently (physically) moved and haven't had the time to follow up on the debugging of this issue. I'll be continuing this shortly.
Comment 18 Fedora End Of Life 2013-07-03 19:07:59 EDT
This message is a reminder that Fedora 17 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 17. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '17'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 17's end of life.

Bug Reporter:  Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 17 is end of life. If you 
would still like  to see this bug fixed and are able to reproduce it 
against a later version  of Fedora, you are encouraged  change the 
'version' to a later Fedora version prior to Fedora 17's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.
Comment 19 Fedora End Of Life 2013-07-31 21:31:23 EDT
Fedora 17 changed to end-of-life (EOL) status on 2013-07-30. Fedora 17 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.