[Bug 1197484] Re: Connection requests to saucy server VMs from a hosts fail after fresh VM installs

Tue Jul 16 20:10:53 UTC 2013

I'm quite convinced this is not an apparmor problem with interpreted
scripts. I created another test program that used wstatus and looped it
for many minutes and had no errors.

I took a look at the isc-dhcp source and while I can't be sure since I can't reproduce this here, I think the bit of code that is triggering this is bind_lease() from client/dhclient.c, specifically line 1292 that does:
1289         /* If the BOUND/RENEW code detects another machine using the            
1290            offered address, it exits nonzero.  We need to send a                
1291            DHCPDECLINE and toss the lease. */                                   
1292         if (script_go (client) == 2) {

script_go has:
3403         pid = fork ();                                                          
3404         if (pid < 0) { 
...                        
3407         } else if (pid) { 
...      
3415         } else {                                                                
3416                 /* We don't want to pass an open file descriptor for            
3417                  * dhclient.leases when executing dhclient-script.              
3418                  */                                                             
3419                 if (leaseFile != NULL)                                          
3420                         fclose(leaseFile);                                      
3421                 execve (scriptName, argv, envp);                                
3422                 log_error ("execve (%s, ...): %m", scriptName);

I still don't know what the problem, but I'm ok with adjusting the
access in the dhclient profile to allow reading of /bin/bash. I would
not be surprised if this didn't solve the connectivity issue.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to isc-dhcp in Ubuntu.
https://bugs.launchpad.net/bugs/1197484

Title:
  Connection requests to saucy server VMs from a hosts fail after fresh
  VM installs

Status in “isc-dhcp” package in Ubuntu:
  New

Bug description:
  The ssh/ ping requests from a precise host (aldebaran) to the client VMs of saucy server installations fail on reboot after fresh installations of today's images (20130703). The ping requests to the IP address allocated to the VMs during the installations fail  with 'Destination Host Unreachable'. There does not appear to be anything wrong during installations.
  The VMs use libvirt/KVM and using bridged interface.
  This issue happens not always but most of the time. I think the issue happens more often when more  VMs present in the host. 

  The following error is reported during the reboot, (though I am not sure if that is the cause for the above behaviour)
  ul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: Internet Systems Consortium DHCP Client 4.2.4
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: Copyright 2004-2012 Internet Systems Consortium.
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: All rights reserved.
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: For info, please visit https://www.isc.org/software/dhcp/
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: 
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: Listening on LPF/eth0/52:54:00:73:cc:82
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: Sending on   LPF/eth0/52:54:00:73:cc:82
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: Sending on   Socket/fallback
  Jul  3 05:20:38 utah-11011-saucy-server-i386 dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0x2bd1e2f7)
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    5.995994] type=1400 audit(1372843239.131:5): apparmor="STATUS" operation="profile_replace" parent=441 profile="unconfined" name="/sbin/dhclient" pid=442 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.008224] type=1400 audit(1372843239.147:6): apparmor="STATUS" operation="profile_replace" parent=441 profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=442 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.008368] type=1400 audit(1372843239.147:7): apparmor="STATUS" operation="profile_replace" parent=441 profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=442 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 failsafe: Failsafe of 120 seconds reached.
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.433462] type=1400 audit(1372843239.571:8): apparmor="STATUS" operation="profile_replace" parent=478 profile="unconfined" name="/sbin/dhclient" pid=486 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.433655] type=1400 audit(1372843239.571:9): apparmor="STATUS" operation="profile_replace" parent=478 profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=486 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.433788] type=1400 audit(1372843239.571:10): apparmor="STATUS" operation="profile_replace" parent=478 profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=486 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 ntpdate[602]: Can't find host ntp.ubuntu.com: System error (-11)
  Jul  3 05:20:39 utah-11011-saucy-server-i386 ntpdate[602]: no servers can be used, exiting
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.433655] type=1400 audit(1372843239.571:9): apparmor="STATUS" operation="profile_replace" parent=478 profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=486 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 kernel: [    6.433788] type=1400 audit(1372843239.571:10): apparmor="STATUS" operation="profile_replace" parent=478 profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=486 comm="apparmor_parser"
  Jul  3 05:20:39 utah-11011-saucy-server-i386 ntpdate[602]: Can't find host ntp.ubuntu.com: System error (-11)
  Jul  3 05:20:39 utah-11011-saucy-server-i386 ntpdate[602]: no servers can be used, exiting
  Jul  3 05:20:41 utah-11011-saucy-server-i386 dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0x2bd1e2f7)
  Jul  3 05:20:41 utah-11011-saucy-server-i386 dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0x2bd1e2f7)
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: DHCPREQUEST of 10.98.2.36 on eth0 to 255.255.255.255 port 67 (xid=0x2bd1e2f7)
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: DHCPOFFER of 10.98.2.36 from 10.98.2.1
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: DHCPREQUEST of 10.98.2.36 on eth0 to 255.255.255.255 port 67 (xid=0x2bd1e2f7)
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: DHCPOFFER of 10.98.2.36 from 10.98.2.1
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: DHCPACK of 10.98.2.36 from 10.98.2.1
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: execve (/sbin/dhclient-script, ...): Permission denied
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: bound to 10.98.2.36 -- renewal in 40307 seconds.
  Jul  3 05:20:42 utah-11011-saucy-server-i386 kernel: [    9.102657] type=1400 audit(1372843242.239:11): apparmor="DENIED" operation="file_perm" parent=508 profile="/sbin/dhclient" name="/bin/bash" pid=649 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: DHCPACK of 10.98.2.36 from 10.98.2.1
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: execve (/sbin/dhclient-script, ...): Permission denied
  Jul  3 05:20:42 utah-11011-saucy-server-i386 dhclient: bound to 10.98.2.36 -- renewal in 40307 seconds.
  Jul  3 05:20:42 utah-11011-saucy-server-i386 kernel: [    9.102657] type=1400 audit(1372843242.239:11): apparmor="DENIED" operation="file_perm" parent=508 profile="/sbin/dhclient" name="/bin/bash" pid=649 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
  Jul  3 05:20:42 utah-11011-saucy-server-i386 ntpdate[687]: Can't find host ntp.ubuntu.com: System error (-11)
  Jul  3 05:20:42 utah-11011-saucy-server-i386 ntpdate[687]: no servers can be used, exiting
  ==============================================
  How to reproduce:
  1. Install utah using
     sudo apt-add-repository -y ppa:utah/stable
     sudo apt-get update
     sudo apt-get install utah

  2. Now run the installation test using
  sudo -u utah -i run_utah_tests.py -i /path/to/saucy-server-amd64.iso -p lp:ubuntu-test-cases/server/preseeds/mail-server.preseed lp:ubuntu-test-cases/server/runlists/mail-server.run -x /etc/utah/bridged-network-vm.xml

  3. Now it could be seen that the the connection to the VMs from the
  host after the installation fails.

  https://jenkins.qa.ubuntu.com/view/Saucy/view/Smoke%20Testing/job
  /saucy-server-i386-smoke-mail-server/58/ is one of the impacted jobs

  Note: This issue is seen in our lab (precise host)and I have not yet
  tried reproducing in a local system..

  Installer syslog and the boot log of a failing job are attached.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/isc-dhcp/+bug/1197484/+subscriptions