761163 – RHEL 5.7 failed to build with <?xml version="1.0" encoding="UTF-8"?> in system template

Bug 761163 - RHEL 5.7 failed to build with <?xml version="1.0" encoding="UTF-8"?> in system template

Summary: RHEL 5.7 failed to build with <?xml version="1.0" encoding="UTF-8"?> in syste...

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	CloudForms Cloud Engine
Classification:	Retired
Component:	imagefactory
Sub Component:
Version:	1.0.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Assignee:	Ian McLeod
QA Contact:	Martin Kočí
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2011-12-07 19:46 UTC by Steve Reichard
Modified:	2012-08-30 17:18 UTC (History)
CC List:	11 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:
Embargoed:

Attachments	(Terms of Use)

Description Steve Reichard 2011-12-07 19:46:24 UTC

Description of problem:


Attempt to build RHEL 5.7 with the template that follows:

<?xml version="1.0" encoding="UTF-8"?>
<template>
  <name>r57_brew</name>
  <description>r57-brew-simple</description>
  <os>
    <name>RHEL-5</name>
    <version>U7</version>
    <arch>x86_64</arch>
    <install type="url">
      <url>http://download.devel.redhat.com/released/RHEL-5-Server/U7/x86_64/os/</url>
    </install>
    <rootpw>redhat</rootpw>
  </os>
</template>

Will fail with the following in the imagefactory.log

2011-12-07 13:43:29,912 INFO oz.Guest.RHEL5Guest pid(3021) Message: Cleaning up guest named r57_brew-5aa58127-2bb9-4397-8391-e2c1c8ab2741
2011-12-07 13:43:30,117 INFO oz.Guest.RHEL5Guest pid(3021) Message: Cleaning up after install
2011-12-07 13:43:30,155 DEBUG imgfac.builders.BaseBuilder.RHEL5_rhevm_Builder pid(3021) Message: Exception caught in ImageFactory
2011-12-07 13:43:30,165 DEBUG imgfac.builders.BaseBuilder.RHEL5_rhevm_Builder pid(3021) Message: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/imgfac/builders/Fedora_rhevm_Builder.py", line 65, in build_image
    self.build_upload(build_id)
  File "/usr/lib/python2.6/site-packages/imgfac/builders/Fedora_rhevm_Builder.py", line 116, in build_upload
    self.output_descriptor = guest.customize_and_generate_icicle(libvirt_xml)
  File "/usr/lib/python2.6/site-packages/oz/RedHat.py", line 1147, in customize_and_generate_icicle
    return self._internal_customize(libvirt_xml, True)
  File "/usr/lib/python2.6/site-packages/oz/RedHat.py", line 1120, in _internal_customize
    guestaddr = self._wait_for_guest_boot(libvirt_dom)
  File "/usr/lib/python2.6/site-packages/oz/Guest.py", line 991, in _wait_for_guest_boot
    raise oz.OzException.OzException("Guest checked in with bogus data")
OzException: Guest checked in with bogus data


RHEL 6.1 build with this tag in the xml.

It appears this tag is put in place in system engine templates.



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


[root@cf-cloudforms9 ~]# /pub/scripts/post_install_configuration_scripts/cf-versions 
Red Hat Enterprise Linux Server release 6.1 (Santiago)
Linux cf-cloudforms9.cloud.lab.eng.bos.redhat.com 2.6.32-131.17.1.el6.x86_64 #1 SMP Thu Sep 29 10:24:25 EDT 2011 x86_64 x86_64 x86_64 GNU/Linux
postgresql-8.4.9-1.el6_1.1.x86_64
mongodb-1.8.0-6.el6.x86_64
euca2ools-1.3.1-4.el6_0.noarch
ruby-1.8.7.299-7.el6_1.1.x86_64
rubygems-1.8.10-1.el6.noarch
deltacloud-core-0.4.1-8.el6.noarch
rubygem-deltacloud-client-0.4.0-3.el6.noarch
package libdeltacloud is not installed
hail-0.8-0.2.gf9c5b967.el6_0.x86_64
puppet-2.6.6-1.el6_0.noarch
aeolus-configure-2.3.0-1.el6.noarch
iwhd-1.0-1.el6.x86_64
imagefactory-0.8.9-1.el6.noarch
aeolus-conductor-daemons-0.6.0-3.el6.noarch
aeolus-conductor-0.6.0-3.el6.noarch
[root@cf-cloudforms9 ~]# 




How reproducible:

easily 


Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Steve Reichard 2011-12-08 14:41:30 UTC

Not so sure it is was the XML tag.

While it failed 3 time with the tag then worked 3 time without it, I just had the failure without the tag.

JoeV  is also seeing flakeyness doing RHEL 5.7 build.   We both happen to be using the same install url.

spr

Comment 2 Steve Reichard 2011-12-08 18:48:18 UTC

Also seeing using RHEL 5.6 building for RHEV..

spr

Comment 3 Steve Reichard 2011-12-08 18:49:05 UTC

Now see it with 5.6 build for vsphere.

spr

Comment 4 Ian McLeod 2011-12-08 20:07:00 UTC

I made a small change to the exception code to show the actual data received over the socket connection.  This is the result:

2011-12-08 14:59:20,161 DEBUG imgfac.builders.BaseBuilder.RHEL5_rhevm_Builder pid(28762) Message: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/imgfac/builders/Fedora_rhevm_Builder.py", line 65, in build_image
    self.build_upload(build_id)
  File "/usr/lib/python2.6/site-packages/imgfac/builders/Fedora_rhevm_Builder.py", line 116, in build_upload
    self.output_descriptor = guest.customize_and_generate_icicle(libvirt_xml)
  File "/usr/lib/python2.6/site-packages/oz/RedHat.py", line 1147, in customize_and_generate_icicle
    return self._internal_customize(libvirt_xml, True)
  File "/usr/lib/python2.6/site-packages/oz/RedHat.py", line 1120, in _internal_customize
    guestaddr = self._wait_for_guest_boot(libvirt_dom)
  File "/usr/lib/python2.6/site-packages/oz/Guest.py", line 991, in _wait_for_guest_boot
    raise oz.OzException.OzException("Guest checked in with bogus data (%s)" % (match.group(1)))
OzException: Guest checked in with bogus data (192.168.122.222,38209d10-48ec-461c-9bdb-db8ba85f01d0!!192.168.122.222,38209d10-48ec-461c-9bdb-db8ba85f01d0)

So, it would seem to be sending this twice before we are able to read it.

Comment 5 James Laska 2011-12-08 20:19:41 UTC

Reproduced on qeblade32 (using rhevm on qeblade26) using rhel57 TDL posted in comment#0 using the following packages:
 imagefactory-1.0.0rc1-1.el6.noarch
 iwhd-1.2-3.el6.x86_64
 aeolus-conductor-0.7.0-4.el6.noarch
 oz-0.7.9-5.el6.noarch

Let me know if you need any additional debugging information

Comment 6 Ian McLeod 2011-12-08 22:07:53 UTC

Steve has tested the fix here:

https://github.com/clalancette/oz/pull/13

It seems to fix the issue.

Comment 7 wes hayutin 2011-12-12 01:26:06 UTC

A hand built RHEL57 template does not have issue.. just FYI..


12-11 15:30:30,757 INFO oz.Guest.RHEL5Guest pid(9383) Message: Generate XML for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 with bootdev hd
2011-12-11 15:30:30,758 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Generated XML:
<?xml version="1.0"?>
<domain type="kvm">
  <name>RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0</name>
  <memory>1048576</memory>
  <currentMemory>1048576</currentMemory>
  <uuid>21acff52-2a24-47d6-841e-f36b1797d9f3</uuid>
  <clock offset="utc"/>
  <vcpu>1</vcpu>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <os>
    <type>hvm</type>
    <boot dev="hd"/>
  </os>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>destroy</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <console device="pty"/>
    <graphics port="-1" type="vnc"/>
    <interface type="bridge">
      <source bridge="virbr0"/>
      <mac address="52:54:00:c2:b5:ab"/>
      <model type="virtio"/>
    </interface>
    <input bus="ps2" type="mouse"/>
    <console type="pty">
      <target port="0"/>
    </console>
    <serial type="tcp">
      <source mode="bind" host="127.0.0.1" service="22484"/>
      <protocol type="raw"/>
      <target port="1"/>
    </serial>
    <disk device="disk" type="file">
      <target dev="vda" bus="virtio"/>
      <source file="/var/lib/imagefactory/images/base-image-94b35b19-71b8-46d1-813c-f612105b40f0.dsk"/>
    </disk>
  </devices>
</domain>

2011-12-11 15:30:30,758 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Base install complete - Doing customization and ICICLE generation
2011-12-11 15:30:30,758 DEBUG imgfac.BuildJob.BuildJob pid(9383) Message: Builder (94b35b19-71b8-46d1-813c-f612105b40f0) changed percent complete from 10 to 30
2011-12-11 15:30:30,758 INFO oz.Guest.RHEL5Guest pid(9383) Message: Customizing image
2011-12-11 15:30:30,759 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Generated XML:
<?xml version="1.0"?>
<domain type="kvm">
  <name>RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0</name>
  <memory>1048576</memory>
  <currentMemory>1048576</currentMemory>
  <uuid>21acff52-2a24-47d6-841e-f36b1797d9f3</uuid>
  <clock offset="utc"/>
  <vcpu>1</vcpu>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <os>
    <type>hvm</type>
    <boot dev="hd"/>
  </os>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>destroy</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <console device="pty"/>
    <graphics port="-1" type="vnc"/>
    <interface type="bridge">
      <source bridge="virbr0"/>
      <mac address="52:54:00:c2:b5:ab"/>
      <model type="virtio"/>
    </interface>
    <input bus="ps2" type="mouse"/>
    <console type="pty">
      <target port="0"/>
    </console>
    
    <disk device="disk" type="file">
      <target dev="vda" bus="virtio"/>
      <source file="/var/lib/imagefactory/images/base-image-94b35b19-71b8-46d1-813c-f612105b40f0.dsk"/>
    </disk>
  <serial type="tcp"><source mode="bind" host="127.0.0.1" service="22484"/><protocol type="raw"/><target port="1"/></serial></devices>
</domain>

2011-12-11 15:30:30,759 INFO oz.Guest.RHEL5Guest pid(9383) Message: Collection Setup
2011-12-11 15:30:30,761 INFO oz.Guest.RHEL5Guest pid(9383) Message: Setting up guestfs handle for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0
2011-12-11 15:30:30,761 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Adding disk image /var/lib/imagefactory/images/base-image-94b35b19-71b8-46d1-813c-f612105b40f0.dsk
2011-12-11 15:30:30,762 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Launching guestfs
2011-12-11 15:30:34,250 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Inspecting guest OS
2011-12-11 15:30:35,139 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Getting mountpoints
2011-12-11 15:30:35,139 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Root device: /dev/VolGroup00/LogVol00
2011-12-11 15:30:35,253 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Step 1: Uploading ssh keys
2011-12-11 15:30:35,264 INFO oz.Guest.RHEL5Guest pid(9383) Message: Generating new openssh key
2011-12-11 15:30:35,265 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Step 2: setup sshd
2011-12-11 15:30:35,384 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Step 3: Open up the firewall
2011-12-11 15:30:35,385 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Step 4: Guest announcement
2011-12-11 15:30:35,425 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Step 5: Set SELinux to permissive mode
2011-12-11 15:30:35,443 INFO oz.Guest.RHEL5Guest pid(9383) Message: Cleaning up guestfs handle for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0
2011-12-11 15:30:35,443 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Syncing
2011-12-11 15:30:35,771 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Unmounting all
2011-12-11 15:30:36,372 INFO oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot
2011-12-11 15:30:36,373 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 300/300
2011-12-11 15:30:46,413 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 290/300
2011-12-11 15:30:56,946 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 280/300
2011-12-11 15:31:07,046 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 270/300
2011-12-11 15:31:16,964 DEBUG paste.httpserver.ThreadPool pid(9383) Message: Added task (0 tasks queued)
2011-12-11 15:31:17,125 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 260/300
2011-12-11 15:31:27,205 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 250/300
2011-12-11 15:31:37,297 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 240/300
2011-12-11 15:31:47,333 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 230/300
2011-12-11 15:31:57,407 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 220/300
2011-12-11 15:32:07,488 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 210/300
2011-12-11 15:32:17,545 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 200/300
2011-12-11 15:32:27,609 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 190/300
2011-12-11 15:32:37,662 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 180/300
2011-12-11 15:32:47,777 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for guest RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to boot, 170/300
2011-12-11 15:32:55,888 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: IP address of guest is 192.168.122.150
2011-12-11 15:32:55,890 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Installing additional repository files
2011-12-11 15:32:57,344 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Installing custom packages
2011-12-11 15:33:09,759 INFO oz.Guest.RHEL5Guest pid(9383) Message: Uploading custom files
2011-12-11 15:33:09,759 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Running custom commands
2011-12-11 15:33:09,759 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Syncing
2011-12-11 15:33:12,463 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Generating ICICLE
2011-12-11 15:33:13,509 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to shutdown, 60/60
2011-12-11 15:33:17,171 DEBUG paste.httpserver.ThreadPool pid(9383) Message: Added task (0 tasks queued)
2011-12-11 15:33:23,548 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to shutdown, 50/60
2011-12-11 15:33:33,629 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Waiting for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0 to shutdown, 40/60
2011-12-11 15:33:37,645 INFO oz.Guest.RHEL5Guest pid(9383) Message: Collection Teardown
2011-12-11 15:33:37,647 INFO oz.Guest.RHEL5Guest pid(9383) Message: Setting up guestfs handle for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0
2011-12-11 15:33:37,647 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Adding disk image /var/lib/imagefactory/images/base-image-94b35b19-71b8-46d1-813c-f612105b40f0.dsk
2011-12-11 15:33:37,647 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Launching guestfs
2011-12-11 15:33:41,141 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Inspecting guest OS
2011-12-11 15:33:42,068 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Getting mountpoints
2011-12-11 15:33:42,068 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Root device: /dev/VolGroup00/LogVol00
2011-12-11 15:33:42,192 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Teardown step 1
2011-12-11 15:33:42,192 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Resetting authorized_keys
2011-12-11 15:33:42,225 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Teardown step 2
2011-12-11 15:33:42,225 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Resetting sshd_config
2011-12-11 15:33:42,254 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Resetting sshd service
2011-12-11 15:33:42,301 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Teardown step 3
2011-12-11 15:33:42,301 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Resetting iptables rules
2011-12-11 15:33:42,303 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Teardown step 4
2011-12-11 15:33:42,303 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Resetting announcement to host
2011-12-11 15:33:42,308 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Removing reportip
2011-12-11 15:33:42,308 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Resetting crond service
2011-12-11 15:33:42,318 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Teardown step 5
2011-12-11 15:33:42,331 INFO oz.Guest.RHEL5Guest pid(9383) Message: Cleaning up guestfs handle for RHEL5_VMWareTools-94b35b19-71b8-46d1-813c-f612105b40f0
2011-12-11 15:33:42,332 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Syncing
2011-12-11 15:33:42,508 DEBUG oz.Guest.RHEL5Guest pid(9383) Message: Unmounting all
2011-12-11 15:33:42,625 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Customization and ICICLE generation complete
2011-12-11 15:33:42,625 DEBUG imgfac.BuildJob.BuildJob pid(9383) Message: Builder (94b35b19-71b8-46d1-813c-f612105b40f0) changed percent complete from 30 to 50
2011-12-11 15:33:42,625 INFO oz.Guest.RHEL5Guest pid(9383) Message: Cleaning up after install
2011-12-11 15:33:42,629 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Generated disk image (/var/lib/imagefactory/images/base-image-94b35b19-71b8-46d1-813c-f612105b40f0.dsk)
2011-12-11 15:33:42,629 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Doing further Factory specific modification of Oz image
2011-12-11 15:33:42,630 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: init guestfs
2011-12-11 15:33:42,630 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: add input image
2011-12-11 15:33:42,630 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: launch guestfs
2011-12-11 15:33:46,168 INFO imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Creating cloud-info file indicating target (vsphere)
2011-12-11 15:33:46,189 INFO imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Updating rc.local with Audrey conditional
2011-12-11 15:33:47,989 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Removed HWADDR from image's /etc/sysconfig/network-scripts/ifcfg-eth0
2011-12-11 15:33:48,428 INFO imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Transforming image for use on VMWare
2011-12-11 15:33:48,428 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Converting raw kvm image (/var/lib/imagefactory/images/base-image-94b35b19-71b8-46d1-813c-f612105b40f0.dsk) to vmware stream-optimized image (/var/lib/imagefactory/images/vmware-image-94b35b19-71b8-46d1-813c-f612105b40f0.vmdk)
2011-12-11 15:35:08,590 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: VMWare stream conversion complete
2011-12-11 15:35:08,590 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Storing Fedora image at http://localhost:9090/...
2011-12-11 15:35:08,634 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Image Warehouse returned status (500) with message: 
2011-12-11 15:35:08,634 INFO imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Creating a bucket returned status (500), .
2011-12-11 15:35:08,645 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Setting metadata ({'object_type': 'template', 'uuid': '862fe430-8b81-48df-bfb4-837bc08721a9'}) for http://localhost:9090/templates/862fe430-8b81-48df-bfb4-837bc08721a9
2011-12-11 15:35:08,730 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Image Warehouse returned status (500) with message: 
2011-12-11 15:35:08,730 INFO imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Creating a bucket returned status (500), .
2011-12-11 15:35:08,743 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Setting metadata ({'object_type': 'icicle', 'uuid': 'a0e6032a-0e4f-4c7e-8826-e1caebea59fe'}) for http://localhost:9090/icicles/a0e6032a-0e4f-4c7e-8826-e1caebea59fe
2011-12-11 15:35:08,829 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Image Warehouse returned status (500) with message: 
2011-12-11 15:35:08,829 INFO imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Creating a bucket returned status (500), .
2011-12-11 15:35:08,833 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 0kB of 293395kB
2011-12-11 15:35:08,970 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 10240kB of 293395kB
2011-12-11 15:35:09,173 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 20480kB of 293395kB
2011-12-11 15:35:09,275 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 30720kB of 293395kB
2011-12-11 15:35:09,378 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 40960kB of 293395kB
2011-12-11 15:35:09,482 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 51200kB of 293395kB
2011-12-11 15:35:09,603 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 61440kB of 293395kB
2011-12-11 15:35:09,706 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 71680kB of 293395kB
2011-12-11 15:35:09,804 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 81920kB of 293395kB
2011-12-11 15:35:09,903 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 92160kB of 293395kB
2011-12-11 15:35:09,998 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 102400kB of 293395kB
2011-12-11 15:35:10,097 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 112640kB of 293395kB
2011-12-11 15:35:10,196 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 122880kB of 293395kB
2011-12-11 15:35:10,294 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 133120kB of 293395kB
2011-12-11 15:35:10,379 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 143360kB of 293395kB
2011-12-11 15:35:10,478 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 153600kB of 293395kB
2011-12-11 15:35:10,579 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 163840kB of 293395kB
2011-12-11 15:35:10,676 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 174080kB of 293395kB
2011-12-11 15:35:10,776 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 184320kB of 293395kB
2011-12-11 15:35:10,898 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 194560kB of 293395kB
2011-12-11 15:35:11,002 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 204800kB of 293395kB
2011-12-11 15:35:11,104 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 215040kB of 293395kB
2011-12-11 15:35:11,207 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 225280kB of 293395kB
2011-12-11 15:35:11,309 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 235520kB of 293395kB
2011-12-11 15:35:11,412 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 245760kB of 293395kB
2011-12-11 15:35:11,514 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 256000kB of 293395kB
2011-12-11 15:35:11,616 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 266240kB of 293395kB
2011-12-11 15:35:11,711 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 276480kB of 293395kB
2011-12-11 15:35:11,814 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 286720kB of 293395kB
2011-12-11 15:35:11,875 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 293395kB of 293395kB
2011-12-11 15:35:11,875 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 293395kB of 293395kB
2011-12-11 15:35:11,881 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 293395kB of 293395kB
2011-12-11 15:35:11,882 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 293395kB of 293395kB
2011-12-11 15:35:11,882 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Uploading 293395kB of 293395kB
2011-12-11 15:35:11,882 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(9383) Message: Setting metadata ({'icicle': 'a0e6032a-0e4f-4c7e-8826-e1caebea59fe', 'uuid': '94b35b19-71b8-46d1-813c-f612105b40f0', 'template': '862fe430-8b81-48df-bfb4-837bc08721a9', 'target_parameters': 'No target parameters for cloud type vsphere', 'object_type': 'target_image', 'target': 'vsphere', 'build': '39db696a-bdb0-4303-8ea7-68632760b4f3'}) for http://localhost:9090/target_images/94b35b19-71b8-46d1-813c-f612105b40f0
2011-12-11 15:35:12,139 DEBUG imgfac.builders.BaseBuilder.RHEL5_vsphere_Builder pid(9383) Message: Image warehouse storage complete
2011-12-11 15:35:12,139 DEBUG imgfac.BuildJob.BuildJob pid(9383) Message: Builder (94b35b19-71b8-46d1-813c-f612105b40f0) changed percent complete from 50 to 100
2011-12-11 15:35:12,139 DEBUG imgfac.BuildJob.BuildJob pid(9383) Message: Builder (94b35b19-71b8-46d1-813c-f612105b40f0) changed status from BUILDING to COMPLETED

Comment 8 Joe Vlcek 2011-12-12 14:08:43 UTC

Just an FYI:

I believe the issue is a timing thing and unrelated to TDL changes.
Prior to applying the provided patch I was able to produce successful
and failed builds using the same TDL.

Comment 9 James Laska 2011-12-14 16:34:13 UTC

Appears the fix (and pull request) from comment#6 was absorbed into master.

Comment 10 James Laska 2011-12-14 16:35:36 UTC

Moving to POST based on comment#6 and comment#9

Comment 11 wes hayutin 2011-12-15 16:10:44 UTC

moving back to modified...
we need a git hash of the commit and the repo name before its moved to post

Comment 12 wes hayutin 2011-12-15 16:13:30 UTC

sry.. meant on_dev

Comment 13 Ian McLeod 2012-01-03 14:46:10 UTC

So, we believe this particular error is resolve by the Oz fix here:

https://github.com/aeolusproject/oz/commit/8c71a05b8791ad57c99bcaf8d2cf48aa72f94b00

This has yet to be brewed but I've tested it out of git and have never seen the "double check in" error with this patch applied.

Changing to ON_QA.

Comment 14 Ian McLeod 2012-01-03 15:17:28 UTC

This is now brewed out of the aeolusproject github fork of Oz.

It is 0.7.9-6 in brew.

Comment 15 Martin Kočí 2012-01-11 12:27:13 UTC

Image successfully built on RHEL62, F15 and F16. I have tested it twice and always it was built successfully without errors. Move bug to VERIFIED then. 
RHEL62
#rpm -qa|grep 'aeolus\|imagefactory-\|oz-\|iwhd'
rubygem-imagefactory-console-0.5.0-4.20110824113238gitd9debef.el6.noarch
aeolus-configure-2.6.0-0.20120105171403gitf0043e8.el6.noarch
aeolus-conductor-daemons-0.9.0-0.20120105223209git5e068fe.el6.noarch
rubygem-aeolus-cli-0.4.0-0.20120105171410git2c6b457.el6.noarch
aeolus-conductor-0.9.0-0.20120105223209git5e068fe.el6.noarch
imagefactory-jeosconf-ec2-rhel-1.0.0rc2.1-1.el6.noarch
rubygem-arel-2.0.10-0.aeolus.el6.noarch
rubygem-ZenTest-4.3.3-2.aeolus.el6.noarch
aeolus-conductor-doc-0.9.0-0.20120105223209git5e068fe.el6.noarch
oz-0.8.0-0.20111219203204git5775e9d.el6.noarch
aeolus-all-0.9.0-0.20120105223209git5e068fe.el6.noarch
iwhd-1.2-3.el6.x86_64
imagefactory-jeosconf-ec2-fedora-1.0.0rc2.1-1.el6.noarch
imagefactory-1.0.0rc2.1-1.el6.noarch
rubygem-aeolus-image-0.4.0-0.20120105171419git8108b42.el6.noarch
F16
#  rpm -qa|grep 'aeolus\|imagefactory-\|oz-\|iwhd'
rubygem-aeolus-cli-0.4.0-0.20120105171410git2c6b457.fc16.noarch
aeolus-conductor-0.9.0-0.20120105223209git5e068fe.fc16.noarch
imagefactory-1.0.0rc2_6_gb08eb85-1.fc16.noarch
iwhd-1.2-1.fc16.x86_64
aeolus-configure-2.6.0-0.20120105171403gitf0043e8.fc16.noarch
imagefactory-jeosconf-ec2-fedora-1.0.0rc2_6_gb08eb85-1.fc16.noarch
rubygem-imagefactory-console-0.4.0-6.fc16.noarch
aeolus-conductor-daemons-0.9.0-0.20120105223209git5e068fe.fc16.noarch
imagefactory-jeosconf-ec2-rhel-1.0.0rc2_6_gb08eb85-1.fc16.noarch
rubygem-aeolus-image-0.4.0-0.20120105171419git8108b42.fc16.noarch
aeolus-all-0.9.0-0.20120105223209git5e068fe.fc16.noarch
aeolus-conductor-doc-0.9.0-0.20120105223209git5e068fe.fc16.noarch
oz-0.8.0-0.20111219203204git5775e9d.fc16.noarch
F15
# rpm -qa|grep 'aeolus\|imagefactory-\|oz-\|iwhd'
rubygem-aeolus-image-0.4.0-0.20120105171419git8108b42.fc15.noarch
aeolus-conductor-daemons-0.9.0-0.20120105223209git5e068fe.fc15.noarch
rubygem-imagefactory-console-0.5.0-4.20110824113238gitd9debef.fc15.noarch
aeolus-all-0.9.0-0.20120105223209git5e068fe.fc15.noarch
aeolus-configure-2.6.0-0.20120105171403gitf0043e8.fc15.noarch
imagefactory-jeosconf-ec2-rhel-1.0.0rc1-1.fc15.noarch
imagefactory-jeosconf-ec2-fedora-1.0.0rc1-1.fc15.noarch
oz-0.8.0-0.20111219203204git5775e9d.fc15.noarch
aeolus-conductor-0.9.0-0.20120105223209git5e068fe.fc15.noarch
iwhd-1.1-1.fc15.x86_64
rubygem-aeolus-cli-0.4.0-0.20120105171410git2c6b457.fc15.noarch
imagefactory-1.0.0rc1-1.fc15.noarch
aeolus-conductor-doc-0.9.0-0.20120105223209git5e068fe.fc15.noarch

Comment 16 wes hayutin 2012-01-12 16:18:09 UTC

bugs in verified or on_qa moving off tracker

Note You need to log in before you can comment on or make changes to this bug.