This looks like a possible IP address conflict. From the log:
|19461|265:265|new| ---- WARNING ----
|19461|265:265|new| 2014-10-09 15:07:11|19461|265:265|new|
Ubuntu.pm:set_static_public_address(1000)|ip_address 192.168.93.128 is
pingable, can not assign to vm28
It's possible that mass-reloading the VMs is resulting in new and proper
DHCP requests/acknowledgments going out. Is there more than one DHCP
server with this IP range in-scope?
You could also set a static IP in VCL directly and avoid using DHCP for the
public interface altogether, in which case you'd need to remove the IP
range from the DHCP scope.
On Thu, Oct 9, 2014 at 10:43 AM, António Aragão <aara...@di.uminho.pt>
wrote:
> Hi,
>
> this happens a lots with Linux images. Sometimes I reload a bunch of
> virtual machines and it solves temporarily the problem.
>
> Any clue ?
>
> ---------- Forwarded message ----------
> From: <r...@vclnode1.apachevcl.di.uminho.pt>
> Date: 2014-10-09 15:07 GMT+01:00
> Subject: PROBLEM -- vclnode1|265:265|new|State.pm|vm28>
> servidor12.di.uminho.pt
> |vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0|vcl_a70373
> To: aara...@di.uminho.pt
>
>
> reservation failed on vm28: failed to update public IP address
> ------------------------------------------------------------------------
> time: 2014-10-09 15:07:11
> caller: State.pm:reservation_failed(240)
> ( 0) State.pm, reservation_failed (line: 240)
> (-1) new.pm, confirm_public_ip_address (line: 1324)
> (-2) new.pm, reserve_computer (line: 950)
> (-3) new.pm, process (line: 408)
> (-4) vcld, make_new_child (line: 571)
> (-5) vcld, main (line: 350)
> ------------------------------------------------------------------------
> management node: vclnode1.apachevcl.di.uminho.pt
> reservation PID: 19461
> parent vcld PID: 1888
>
> request ID: 265
> reservation ID: 265
> request state/laststate: new/new
> request start time: 2014-10-09 15:00:00
> request end time: 2014-10-09 16:15:00
> for imaging: no
> log ID: 172
>
> computer: vm28.apachevcl.di.uminho.pt
> computer id: 32
> computer type: virtualmachine
> computer eth0 MAC address: 00:50:56:00:00:36
> computer eth1 MAC address: 00:50:56:00:00:37
> computer private IP address: 10.100.0.128
> computer public IP address: 192.168.93.128
> computer in block allocation: no
> provisioning module: VCL::Module::Provisioning::VMware::VMware
>
> vm host: servidor12.di.uminho.pt
> vm host ID: 1
> vm host computer ID: 1
> vm profile: vmhostprofile1
> vm profile VM path: /vmfs/volumes/datastore1/
> vm profile repository path: /vmfs/volumes/vcl_images/
> vm profile datastore path: /vmfs/volumes/datastore1/
> vm profile disk type: shared
>
> image: vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0
> image display name: UBUNTU1204_20140403_VMWARE_00001
> image ID: 74
> image revision ID: 70
> image size: 13682 MB
> use Sysprep: yes
> root access: yes
> image owner ID: 1
> image owner affiliation: Local
> image revision date created: 2014-04-03 10:39:09
> image revision production: yes
> OS module: VCL::Module::OS::Linux::Ubuntu
>
> user: vcl_a70373
> user name:
> user ID: 56
> user affiliation: DIALUNOSLDAP
> ------------------------------------------------------------------------
> RECENT LOG ENTRIES FOR THIS PROCESS:
> |19461|265:265|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
> ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x vm28 'cat
> /proc/cpuinfo' 2>&1
> 2014-10-09
> 15:07:11|19461|265:265|new|utils.pm:run_ssh_command(5020)|run_ssh_command
> output:
> |19461|265:265|new| processor : 0
> |19461|265:265|new| vendor_id : AuthenticAMD
> |19461|265:265|new| cpu family : 21
> |19461|265:265|new| model : 2
> |19461|265:265|new| model name : AMD Opteron(tm) Processor 6380
> |19461|265:265|new| stepping : 0
> |19461|265:265|new| microcode : 0x600081f
> |19461|265:265|new| cpu MHz : 2500.000
> |19461|265:265|new| cache size : 2048 KB
> |19461|265:265|new| fdiv_bug : no
> |19461|265:265|new| hlt_bug : no
> |19461|265:265|new| f00f_bug : no
> |19461|265:265|new| coma_bug : no
> |19461|265:265|new| fpu : yes
> |19461|265:265|new| fpu_exception : yes
> |19461|265:265|new| cpuid level : 13
> |19461|265:265|new| wp : yes
> |19461|265:265|new| flags : fpu vme de pse tsc msr pae mce cx8 apic sep
> mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 syscall nx mmxext
> fxsr_opt rdtscp lm constant_tsc up tsc_reliable nonstop_tsc aperfmperf pni
> cx16 popcnt hypervisor lahf_lm extapic abm sse4a misalignsse 3dnowprefetch
> arat
> |19461|265:265|new| bogomips : 5000.00
> |19461|265:265|new| clflush size : 64
> |19461|265:265|new| cache_alignment : 64
> |19461|265:265|new| address sizes : 40 bits physical, 48 bits virtual
> |19461|265:265|new| power management:
> 2014-10-09 15:07:11|19461|265:265|new|utils.pm:run_ssh_command(5034)|SSH
> command executed on vm28, returning (0, "processor : 0 vendor_id : Auth...")
> 2014-10-09
> 15:07:11|19461|265:265|new|Linux.pm:get_cpu_core_count(3435)|retrieved vm28
> CPU core count: 1
> |19461|265:265|new| cpuinfo 'processor' line count: 1
> |19461|265:265|new| cpuinfo 'cpu cores': 1
> |19461|265:265|new| cpuinfo 'siblings': 1
> |19461|265:265|new| hyperthreading enabled: no
> 2014-10-09
> 15:07:11|19461|265:265|new|VMware.pm:get_vm_cpu_configuration(5163)|VM CPU
> configuration:
> |19461|265:265|new| sockets: 1
> |19461|265:265|new| cores per socket: 1
> |19461|265:265|new| total cores: 1
> 2014-10-09 15:07:11|19461|265:265|new|VMware.pm:load(547)|verified VM OS
> recognized correct number of CPUs: 1
> 2014-10-09
> 15:07:11|19461|265:265|new|new.pm:reload_image(672)|vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0
> was successfully reloaded on vm28
> 2014-10-09 15:07:11|19461|265:265|new|utils.pm:insertloadlog(3665)|inserted
> computer=32, loadimagecomplete,
> vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0 was successfully
> reloaded on vm28
> 2014-10-09
> 15:07:11|19461|265:265|new|utils.pm:update_currentimage(5685)|updating
> computer 32: image=74, imagerevision=70
> 2014-10-09
> 15:07:11|19461|265:265|new|utils.pm:update_currentimage(5715)|updated
> currentimageid and imagerevision id for computer id 32
> 2014-10-09 15:07:11|19461|265:265|new|new.pm:reload_image(683)|updated
> computer table for vm28: currentimageid=74
> 2014-10-09 15:07:11|19461|265:265|new|new.pm:reload_image(703)|returning 1
> 2014-10-09 15:07:11|19461|265:265|new|new.pm:process(292)|vm28 is loaded
> with vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0
> 2014-10-09 15:07:11|19461|265:265|new|utils.pm:insertloadlog(3665)|inserted
> computer=32, nodeready, vm28 is loaded with
> vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0
> 2014-10-09 15:07:11|19461|265:265|new|new.pm:process(374)|request_state_name=
> new
> 2014-10-09 15:07:11|19461|265:265|new|new.pm:process(386)|vm28 next image
> is already set to vmwareubuntu-UBUNTU1204_20140403_VMWARE_0000174-v0
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:is_parent_reservation(1004)|returning
> true: parent reservation ID for this request: 265
> 2014-10-09
> 15:07:11|19461|265:265|new|new.pm:reserve_computer(936)|user_standalone=1,
> image OS type=linux
> 2014-10-09
> 15:07:11|19461|265:265|new|OS.pm:get_public_interface_name(1150)|returning
> public interface name previously retrieved: eth1
> |19461|265:265|new| ---- WARNING ----
> |19461|265:265|new| 2014-10-09
> 15:07:11|19461|265:265|new|OS.pm:get_ip_address(1531)|unable to determine
> public IP address, 'ip_address' value is not set in the network
> configuration info:
> |19461|265:265|new| : {
> |19461|265:265|new| : "ip_address" => {},
> |19461|265:265|new| : "name" => "eth1",
> |19461|265:265|new| : "physical_address" => "00:50:56:00:00:37"
> |19461|265:265|new| : }
> |19461|265:265|new| ( 0) OS.pm, get_ip_address (line: 1531)
> |19461|265:265|new| (-1) OS.pm, get_public_ip_address (line: 1587)
> |19461|265:265|new| (-2) new.pm, confirm_public_ip_address (line: 1301)
> |19461|265:265|new| (-3) new.pm, reserve_computer (line: 950)
> |19461|265:265|new| (-4) new.pm, process (line: 408)
> |19461|265:265|new| (-5) vcld, make_new_child (line: 571)
> |19461|265:265|new| ---- WARNING ----
> |19461|265:265|new| 2014-10-09
> 15:07:11|19461|265:265|new|new.pm:confirm_public_ip_address(1322)|failed
> to retrieve dynamic public IP address from vm28
> |19461|265:265|new| ( 0) new.pm, confirm_public_ip_address (line: 1322)
> |19461|265:265|new| (-1) new.pm, reserve_computer (line: 950)
> |19461|265:265|new| (-2) new.pm, process (line: 408)
> |19461|265:265|new| (-3) vcld, make_new_child (line: 571)
> |19461|265:265|new| (-4) vcld, main (line: 350)
> 2014-10-09
> 15:07:11|19461|265:265|new|OS.pm:update_public_ip_address(980)|IP
> configuration is set to static, attempting to set public IP address
> 2014-10-09
> 15:07:11|19461|265:265|new|OS.pm:get_public_interface_name(1150)|returning
> public interface name previously retrieved: eth1
> 2014-10-09 15:07:11|19461|265:265|new|utils.pm:is_valid_ip_address(9013)|IP
> address is valid: 192.168.93.254
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:get_management_node_public_default_gateway(2271)|returning
> default gateway configured in vcld.conf: 192.168.93.254
> 2014-10-09
> 15:07:11|19461|265:265|new|Ubuntu.pm:set_static_public_address(994)|attempting
> to set static public IP address on vm28
> |19461|265:265|new| ---- WARNING ----
> |19461|265:265|new| 2014-10-09
> 15:07:11|19461|265:265|new|Ubuntu.pm:set_static_public_address(1000)|ip_address
> 192.168.93.128 is pingable, can not assign to vm28
> |19461|265:265|new| ( 0) Ubuntu.pm, set_static_public_address (line: 1000)
> |19461|265:265|new| (-1) OS.pm, update_public_ip_address (line: 984)
> |19461|265:265|new| (-2) new.pm, confirm_public_ip_address (line: 1324)
> |19461|265:265|new| (-3) new.pm, reserve_computer (line: 950)
> |19461|265:265|new| (-4) new.pm, process (line: 408)
> |19461|265:265|new| (-5) vcld, make_new_child (line: 571)
> |19461|265:265|new| ---- WARNING ----
> |19461|265:265|new| 2014-10-09
> 15:07:11|19461|265:265|new|OS.pm:update_public_ip_address(989)|failed to
> set static public IP address on vm28
> |19461|265:265|new| ( 0) OS.pm, update_public_ip_address (line: 989)
> |19461|265:265|new| (-1) new.pm, confirm_public_ip_address (line: 1324)
> |19461|265:265|new| (-2) new.pm, reserve_computer (line: 950)
> |19461|265:265|new| (-3) new.pm, process (line: 408)
> |19461|265:265|new| (-4) vcld, make_new_child (line: 571)
> |19461|265:265|new| (-5) vcld, main (line: 350)
> 2014-10-09 15:07:11|19461|265:265|new|utils.pm:insertloadlog(3665)|inserted
> computer=32, staticIPaddress, failed to set static public IP address on vm28
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:get_computer_state_name(2436)|attempting
> to retrieve current state of computer vm28 from the database
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:get_computer_state_name(2467)|retrieved
> current state of computer vm28 from the database: reloading
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:_automethod(847)|data structure
> updated, hash path:
> $self->request_data->{reservation}{265}{computer}{state}{name}, data
> identifier: computer_state_name, data:
> |19461|265:265|new| : "reloading"
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:get_computer_private_ip_address(1617)|returning
> private IP address previously retrieved: 10.100.0.128
> 2014-10-09 15:07:11|19461|265:265|new|utils.pm:is_inblockrequest(5760)|zero
> rows were returned from database select
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:get_image_affiliation_name(2121)|image
> owner id: 1
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:retrieve_user_data(1412)|attempting
> to retrieve and store data for user: user.id = '1'
> 2014-10-09
> 15:07:11|19461|265:265|new|DataStructure.pm:retrieve_user_data(1475)|data
> has been retrieved for user: admin (id: 1)
>
>
>
> --
> http://www.di.uminho.pt/~apa/email/cartao_virtual_email_aaragao.png
>
