Bug 531222

Summary: config problem in /var/lib/dhclient/dhclient-wlan0.lease
Product: [Fedora] Fedora Reporter: Stefan Assmann <sassmann>
Component: dhcpAssignee: Jiri Popelka <jpopelka>
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 12CC: dcbw, jpopelka, sergeobelare
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2010-05-11 03:23:58 EDT Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Attachments:
Description Flags
dhclient-38781ed6-3472-48d6-af50-fe44aafb0c1a-wlan0.lease
none
dhclient lease file that generates syntax errors none

Description Stefan Assmann 2009-10-27 07:24:27 EDT
Created attachment 366238 [details]
dhclient-38781ed6-3472-48d6-af50-fe44aafb0c1a-wlan0.lease

Description of problem:
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'TitanNet'.
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
Oct 27 12:11:43 localhost NetworkManager: <info>  (wlan0): device state change: 5 -> 7 (reason 0)
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Beginning DHCP transaction (timeout in 45 seconds)
Oct 27 12:11:43 localhost NetworkManager: <info>  dhclient started with pid 1869
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) scheduled...
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) started...
Oct 27 12:11:43 localhost NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) complete.
Oct 27 12:11:43 localhost dhclient: Internet Systems Consortium DHCP Client 4.1.0p1
Oct 27 12:11:43 localhost dhclient: Copyright 2004-2009 Internet Systems Consortium.
Oct 27 12:11:43 localhost dhclient: All rights reserved.
Oct 27 12:11:43 localhost dhclient: For info, please visit http://www.isc.org/sw/dhcp/
Oct 27 12:11:43 localhost dhclient:
Oct 27 12:11:43 localhost dhclient: /var/lib/dhclient/dhclient-38781ed6-3472-48d6-af50-fe44aafb0c1a-wlan0.lease line 13: semicolon expected.
Oct 27 12:11:43 localhost dhclient:   rebind
Oct 27 12:11:43 localhost dhclient:    ^
Oct 27 12:11:43 localhost dhclient: /var/lib/dhclient/dhclient-38781ed6-3472-48d6-af50-fe44aafb0c1a-wlan0.lease line 15: semicolon expected.
Oct 27 12:11:43 localhost dhclient: }
Oct 27 12:11:43 localhost dhclient:  ^
Oct 27 12:11:43 localhost dhclient: /var/lib/dhclient/dhclient-38781ed6-3472-48d6-af50-fe44aafb0c1a-wlan0.lease line 15: unterminated lease declaration.
Oct 27 12:11:43 localhost dhclient: }
Oct 27 12:11:43 localhost dhclient:  ^
Oct 27 12:11:44 localhost NetworkManager: <info>  DHCP: device wlan0 state changed (null) -> preinit


Version-Release number of selected component (if applicable):
dhclient-4.1.0p1-12.fc12.i686
NetworkManager-0.7.996-5.git20091021.fc12.i686

Actual results:
config problem

Expected results:
no config problem

Additional info:
Comment 1 Dan Williams 2009-10-28 13:52:37 EDT
David, did dhclient ever have a problem writing out the lease file config correctly?  NM just passes a path to dhclient and doesn't ever write their contents, so either dhclient wrote it out wrong, a user edited it manually, or some other program touched it.  Any idea?

Reporter, have you recently connected to this network?  Or did you just now connect after a long period of not having used it?  What's the date on the lease file?
Comment 2 David Cantrell 2009-10-28 15:57:46 EDT
(In reply to comment #1)
> David, did dhclient ever have a problem writing out the lease file config
> correctly?  NM just passes a path to dhclient and doesn't ever write their
> contents, so either dhclient wrote it out wrong, a user edited it manually, or
> some other program touched it.  Any idea?

dhclient has never had any problems writing out the lease file, to my knowledge.  It's entirely possible that the lease file has been left over from a previous old version of dhclient and that's screwing up the parsing.  But that would be my only guess.
Comment 3 Stefan Assmann 2009-10-29 05:43:40 EDT
Hi Dan and David,

this happened on a fresh installation of of F12 Beta. The only thing I've kept from the previous install is /home. I've deleted dhclient-38781ed6-3472-48d6-af50-fe44aafb0c1a-wlan0.lease and after a reboot everything is fine now.
Comment 4 Dan Williams 2009-11-06 20:33:52 EST
David, the only thing I can think of is that maybe dhclient was in the middle of writing out the lease file when NM sent it a SIGTERM or SIGKILL?  NM would do that when switching connections or quitting, but NM tries to be nice and sends a SIGTERM first and then 2 seconds later will SIGKILL it if it hasn't yet quit.

Any idea if the dhclient exit code will reflect a bad lease file at all?  If so we could blow away the lease file if dhclient quit the first time.  But this leasefile looks really odd, because the 'rebind' line is malformed but there is a closing '}'.  So it doesn't look like dhclient got killed in the middle of writing out data, it looks like it just failed to write the rest of the rebind line...
Comment 5 Bug Zapper 2009-11-16 09:24:37 EST
This bug appears to have been reported against 'rawhide' during the Fedora 12 development cycle.
Changing version to '12'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 6 sergeobelare 2010-05-03 08:21:41 EDT
Similar problem:

May  3 08:06:17 localhost NetworkManager: <info> (wlan0): supplicant connection state:  4-way handshake -> group handshake
May  3 08:06:17 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'airlangb'.
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
May  3 08:06:17 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 7 (reason 0)
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
May  3 08:06:17 localhost NetworkManager: <info> dhclient started with pid 2782
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) scheduled...
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) started...
May  3 08:06:17 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) complete.
May  3 08:06:17 localhost dhclient[2782]: Internet Systems Consortium DHCP Client 4.1.1
May  3 08:06:17 localhost dhclient[2782]: Copyright 2004-2010 Internet Systems Consortium.
May  3 08:06:17 localhost dhclient[2782]: All rights reserved.
May  3 08:06:17 localhost dhclient[2782]: For info, please visit https://www.isc.org/software/dhcp/
May  3 08:06:17 localhost dhclient[2782]: 
May  3 08:06:17 localhost dhclient[2782]: /var/lib/dhclient/dhclient-5a14eb4f-6f75-4903-91cd-02638022f51b-wlan0.lease line 28: semicolon expected.
May  3 08:06:17 localhost dhclient[2782]:   rebind 
May  3 08:06:17 localhost dhclient[2782]:    ^
May  3 08:06:17 localhost dhclient[2782]: /var/lib/dhclient/dhclient-5a14eb4f-6f75-4903-91cd-02638022f51b-wlan0.lease line 30: semicolon expected.
May  3 08:06:17 localhost dhclient[2782]: }
May  3 08:06:17 localhost dhclient[2782]:  ^
May  3 08:06:17 localhost dhclient[2782]: /var/lib/dhclient/dhclient-5a14eb4f-6f75-4903-91cd-02638022f51b-wlan0.lease line 30: unterminated lease declaration.
May  3 08:06:17 localhost dhclient[2782]: }
May  3 08:06:17 localhost dhclient[2782]:  ^
May  3 08:06:17 localhost NetworkManager: <info> (wlan0): DHCPv4 state changed nbi -> preinit
May  3 08:06:17 localhost dhclient[2782]: Listening on LPF/wlan0/00:14:a5:eb:7d:79
May  3 08:06:17 localhost dhclient[2782]: Sending on   LPF/wlan0/00:14:a5:eb:7d:79
May  3 08:06:17 localhost dhclient[2782]: Sending on   Socket/fallback
May  3 08:06:19 localhost avahi-daemon[1189]: Registering new address record for fe80::214:a5ff:feeb:7d79 on wlan0.*.
May  3 08:06:20 localhost dhclient[2782]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 8
May  3 08:06:20 localhost dhclient[2782]: DHCPOFFER from 192.168.0.1
May  3 08:06:20 localhost dhclient[2782]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
May  3 08:06:20 localhost dhclient[2782]: DHCPACK from 192.168.0.1
May  3 08:06:20 localhost NetworkManager: <info> (wlan0): DHCPv4 state changed preinit -> bound
May  3 08:06:20 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled...
May  3 08:06:20 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started...
May  3 08:06:20 localhost NetworkManager: <info>   address 192.168.0.111
May  3 08:06:20 localhost NetworkManager: <info>   prefix 24 (255.255.255.0)
May  3 08:06:20 localhost NetworkManager: <info>   gateway 192.168.0.1
May  3 08:06:20 localhost NetworkManager: <info>   nameserver '192.168.0.1'
May  3 08:06:20 localhost NetworkManager: <info>   domain name 'hsd1.md.comcast.net.'
May  3 08:06:20 localhost NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
May  3 08:06:20 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete.
May  3 08:06:20 localhost NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
May  3 08:06:20 localhost avahi-daemon[1189]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.111.
May  3 08:06:20 localhost avahi-daemon[1189]: New relevant interface wlan0.IPv4 for mDNS.
May  3 08:06:20 localhost avahi-daemon[1189]: Registering new address record for 192.168.0.111 on wlan0.IPv4.
May  3 08:06:20 localhost dhclient[2782]: bound to 192.168.0.111 -- renewal in 874595267 seconds.
May  3 08:06:21 localhost NetworkManager: <info> (wlan0): device state change: 7 -> 8 (reason 0)
May  3 08:06:21 localhost NetworkManager: <info> Policy set 'airlangb' (wlan0) as default for routing and DNS.
May  3 08:06:21 localhost NetworkManager: <info> Activation (wlan0) successful, device activated.
May  3 08:06:21 localhost NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
May  3 08:06:21 localhost ntpd[1485]: Listening on interface #8 wlan0, fe80::214:a5ff:feeb:7d79#123 Enabled
May  3 08:06:21 localhost ntpd[1485]: Listening on interface #9 wlan0, 192.168.0.111#123 Enabled
May  3 08:10:36 localhost kernel: CE: hpet increasing min_delta_ns to 15000 nsec
May  3 08:10:50 localhost ntpd[1485]: synchronized to 217.160.254.116, stratum 2
May  3 08:10:50 localhost ntpd[1485]: time reset -0.649868 s
May  3 08:10:50 localhost ntpd[1485]: kernel time sync status change 2001

I'm wondering if some of the wireless disassociation problems could be due ta a short default lease time because the actual renew time isn't configured?
Comment 7 Dan Williams 2010-05-04 16:26:27 EDT
Could be; I'd say dhclient shouldn't ever be writing out invalid config files; lets see what dhclient maintainers have to say.  If you could attach the badly formatted lease file that would be useful.  Thanks.
Comment 8 sergeobelare 2010-05-06 10:41:30 EDT
Created attachment 412075 [details]
dhclient lease file that generates syntax errors

The parser points at renew never, etc, but could it be the extra dot at the end of the domain name in the line above it? the "renew never" syntax should be good.
Comment 9 Jiri Popelka 2010-05-11 03:23:58 EDT
David Cantrell created a patch (see bug #514828, comment #3) for dhclient for this issue, but there were reported (according to his words) some problems with it, so he removed that patch again.

*** This bug has been marked as a duplicate of bug 514828 ***