Bug 712308 - Template creation shows completed status in logs but stays in Queued state in UI for Fedora
Summary: Template creation shows completed status in logs but stays in Queued state in...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: CloudForms Cloud Engine
Classification: Retired
Component: aeolus-conductor
Version: 0.3.1
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: beta
Assignee: Tomas Sedovic
QA Contact: wes hayutin
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-06-10 09:09 UTC by Shveta
Modified: 2012-01-26 12:27 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-06-23 13:31:02 UTC

Attachments (Terms of Use)
Add an attachment (proposed patch, testcase, etc.)

Description Shveta 2011-06-10 09:09:50 UTC 
Description of problem:


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


How reproducible:


Steps to Reproduce:
1. Add a provider account
2. Build a template on F-14
3. On UI it stays in queued state where as in logs it shows completed state

http://pastebin.test.redhat.com/52269
  
Actual results:


Expected results:


Additional info:

tail -f /var/log/imagefactory.log 
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: MAC: 52:54:00:d0:46:01, distro: Fedora
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: update: 14, arch: x86_64, diskimage: /var/tmp/try_east.dsk
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: host IP: 192.168.122.1, nicmodel: virtio, clockoffset: utc
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: mousetype: ps2, disk_bus: virtio, disk_dev: vda
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: icicletmp: /var/lib/oz/icicletmp/try_east, listen_port: 33285
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Cache original media?: True
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Original ISO path: /var/lib/oz/isos/Fedora14x86_64-url.iso
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Modified ISO cache: /var/lib/oz/isos/Fedora14x86_64-url-oz.iso
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Output ISO path: /var/tmp/try_east-url-oz.iso
2011-06-10 12:43:52,840 DEBUG oz.Guest.FedoraGuest pid(29679) Message: ISO content path: /var/lib/oz/isocontent/try_east-url
2011-06-10 12:44:02,678 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Original URL http://download.fedoraproject.org/pub/fedora/linux/releases/14/Fedora/x86_64/os/ resolved to http://download.eng.pnq.redhat.com/pub/fedora/linux/releases/14/Fedora/x86_64/os/
2011-06-10 12:44:02,678 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: build() called on FedoraBuilder...
2011-06-10 12:44:02,678 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Building for target ec2 with warehouse config http://localhost:9090/
2011-06-10 12:44:02,679 DEBUG imagefactory.qmfagent.BuildAdaptor.BuildAdaptor pid(29679) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed status from NEW to BUILDING
2011-06-10 12:44:02,679 INFO oz.Guest.FedoraGuest pid(29679) Message: Cleaning up guest named try_east
2011-06-10 12:44:02,711 INFO oz.Guest.FedoraGuest pid(29679) Message: Generating install media
2011-06-10 12:44:02,745 INFO oz.Guest.FedoraGuest pid(29679) Message: Fetching the original media
2011-06-10 12:44:02,747 INFO oz.Guest.FedoraGuest pid(29679) Message: Original install media available, using cached version
2011-06-10 12:44:02,747 INFO oz.Guest.FedoraGuest pid(29679) Message: Copying ISO contents for modification
2011-06-10 12:44:02,747 INFO oz.Guest.FedoraGuest pid(29679) Message: Setting up guestfs handle for try_east
2011-06-10 12:44:02,747 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Adding ISO image /var/lib/oz/isos/Fedora14x86_64-url.iso
2011-06-10 12:44:02,755 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Launching guestfs
2011-06-10 12:44:07,470 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Mounting ISO
2011-06-10 12:44:07,493 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Checking if there is enough space on the filesystem
2011-06-10 12:44:07,494 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Extracting ISO contents
2011-06-10 12:44:10,119 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Putting the kickstart in place
2011-06-10 12:44:10,162 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Modifying the boot options
2011-06-10 12:44:10,163 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Generating new ISO
2011-06-10 12:44:10,541 INFO oz.Guest.FedoraGuest pid(29679) Message: Cleaning up old ISO data
2011-06-10 12:44:10,824 DEBUG imagefactory.qmfagent.BuildAdaptor.BuildAdaptor pid(29679) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed percent complete from 0 to 10
2011-06-10 12:44:10,824 INFO oz.Guest.FedoraGuest pid(29679) Message: Generating 10GB diskimage with fake partition for try_east
2011-06-10 12:44:10,825 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Doing base install via Oz
2011-06-10 12:44:10,825 INFO oz.Guest.FedoraGuest pid(29679) Message: Running install for try_east
2011-06-10 12:44:10,825 INFO oz.Guest.FedoraGuest pid(29679) Message: Generate XML for guest try_east with bootdev cdrom
2011-06-10 12:44:10,825 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Generated XML:
<?xml version="1.0"?>
<domain type="kvm">
  <name>try_east</name>
  <memory>1048576</memory>
  <currentMemory>1048576</currentMemory>
  <uuid>d146ea20-3c82-4125-9893-25f382258fa9</uuid>
  <clock offset="utc"/>
  <vcpu>1</vcpu>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <os>
    <type>hvm</type>
    <boot dev="cdrom"/>
  </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:d0:46:01"/>
      <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/tmp/base-image-6b4ab1be-85c0-4929-accd-3366667d2fe5.dsk"/>
    </disk>
    <disk type="file" device="cdrom">
      <source file="/var/tmp/try_east-url-oz.iso"/>
      <target dev="hdc"/>
    </disk>
  </devices>
</domain>

2011-06-10 12:44:11,783 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3600/3600
2011-06-10 12:44:21,800 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3590/3600
2011-06-10 12:44:31,816 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3580/3600
2011-06-10 12:44:41,833 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3570/3600
2011-06-10 12:44:51,850 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3560/3600
2011-06-10 12:45:01,865 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3550/3600
2011-06-10 12:45:11,880 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3540/3600
2011-06-10 12:45:21,896 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3530/3600
2011-06-10 12:45:31,914 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3520/3600
2011-06-10 12:45:41,933 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3510/3600
2011-06-10 12:45:51,950 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3500/3600
2011-06-10 12:46:01,966 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3490/3600
2011-06-10 12:46:11,983 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3480/3600
2011-06-10 12:46:21,999 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3470/3600
2011-06-10 12:46:32,014 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3460/3600
2011-06-10 12:46:42,030 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3450/3600
2011-06-10 12:46:52,047 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3440/3600
2011-06-10 12:47:02,064 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3430/3600
2011-06-10 12:47:12,080 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3420/3600
2011-06-10 12:47:22,099 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3410/3600
2011-06-10 12:47:32,116 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3400/3600
2011-06-10 12:47:42,134 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3390/3600
2011-06-10 12:47:52,152 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Waiting for try_east to finish installing, 3380/3600
2011-06-10 12:47:56,545 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Libvirt Domain Info Failed:
2011-06-10 12:47:56,545 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  code is 9
2011-06-10 12:47:56,545 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  domain is 10
2011-06-10 12:47:56,545 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  message is operation failed: could not query memory balloon allocation
2011-06-10 12:47:56,545 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  level is 2
2011-06-10 12:47:56,545 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  str1 is operation failed: %s
2011-06-10 12:47:56,546 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  str2 is could not query memory balloon allocation
2011-06-10 12:47:56,546 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  str3 is None
2011-06-10 12:47:56,546 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  int1 is -1
2011-06-10 12:47:56,546 DEBUG oz.Guest.FedoraGuest pid(29679) Message:  int2 is -1
2011-06-10 12:47:56,546 INFO oz.Guest.FedoraGuest pid(29679) Message: Install of try_east succeeded
2011-06-10 12:47:56,546 INFO oz.Guest.FedoraGuest pid(29679) Message: Generate XML for guest try_east with bootdev hd
2011-06-10 12:47:56,546 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Generated XML:
<?xml version="1.0"?>
<domain type="kvm">
  <name>try_east</name>
  <memory>1048576</memory>
  <currentMemory>1048576</currentMemory>
  <uuid>d146ea20-3c82-4125-9893-25f382258fa9</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:d0:46:01"/>
      <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/tmp/base-image-6b4ab1be-85c0-4929-accd-3366667d2fe5.dsk"/>
    </disk>
  </devices>
</domain>

2011-06-10 12:47:56,547 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Base install complete - Doing customization
2011-06-10 12:47:56,547 DEBUG imagefactory.qmfagent.BuildAdaptor.BuildAdaptor pid(29679) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed percent complete from 10 to 30
2011-06-10 12:47:56,547 INFO oz.Guest.FedoraGuest pid(29679) Message: Customizing image
2011-06-10 12:47:56,547 INFO oz.Guest.FedoraGuest pid(29679) Message: No additional packages or files to install, skipping customization
2011-06-10 12:47:56,547 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Customization complete
2011-06-10 12:47:56,547 DEBUG imagefactory.qmfagent.BuildAdaptor.BuildAdaptor pid(29679) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed percent complete from 30 to 50
2011-06-10 12:47:56,548 INFO oz.Guest.FedoraGuest pid(29679) Message: Cleaning up after install
2011-06-10 12:47:56,573 DEBUG oz.Guest.FedoraGuest pid(29679) Message: Removed modified ISO
2011-06-10 12:47:56,573 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Generated disk image (/var/tmp/base-image-6b4ab1be-85c0-4929-accd-3366667d2fe5.dsk)
2011-06-10 12:47:56,573 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Transforming image for use on EC2
2011-06-10 12:47:56,573 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: init guestfs
2011-06-10 12:47:56,574 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: add input image
2011-06-10 12:47:56,574 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: creat target image
2011-06-10 12:47:56,574 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: creat tmp image
2011-06-10 12:47:56,763 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: launch guestfs
2011-06-10 12:48:04,467 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Making filesystems for EC2 transform
2011-06-10 12:48:08,610 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Done
2011-06-10 12:48:08,891 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Copying image contents to EC2 flat filesystem
2011-06-10 12:49:42,268 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Done
2011-06-10 12:49:48,488 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: distro: fedora - arch: x86_64 - major: 14 - minor 0
2011-06-10 12:49:48,537 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Modifying flat FS contents to be EC2 compatible
2011-06-10 12:49:48,537 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Creating cloud-info file for EC2
2011-06-10 12:49:48,577 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Disabling SELINUX
2011-06-10 12:49:48,585 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Making data directory
2011-06-10 12:49:48,605 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Modifying and uploading fstab
2011-06-10 12:49:48,606 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Enabling networking and uploading ifcfg-eth0
2011-06-10 12:49:48,931 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Updating rc.local for key injection
2011-06-10 12:49:49,028 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Modifying and updating menu.lst
2011-06-10 12:49:49,052 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Using kernel version: 2.6.35.6-45.fc14.x86_64
2011-06-10 12:49:49,195 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Fixing F14 EC2 bug
2011-06-10 12:49:50,592 INFO imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Done with EC2 filesystem modifications
2011-06-10 12:49:50,790 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Storing Fedora image at http://localhost:9090/...
2011-06-10 12:49:50,808 WARNING imagefactory.ImageWarehouse.ImageWarehouse pid(29679) Message: Creating a bucket returned status 500, maybe the bucket already exists?
2011-06-10 12:49:50,890 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(29679) Message: Setting metadata ({'object_type': 'template', 'uuid': '2c1522c8-9331-11e0-807f-bc305bd4a098'}) for http://localhost:9090/templates/2c1522c8-9331-11e0-807f-bc305bd4a098
2011-06-10 12:49:50,892 WARNING imagefactory.ImageWarehouse.ImageWarehouse pid(29679) Message: Creating a bucket returned status 500, maybe the bucket already exists?
2011-06-10 12:49:50,941 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(29679) Message: Setting metadata ({'object_type': 'icicle', 'uuid': 'd1aaeb23-f226-42fe-a614-8cd7baff89f2'}) for http://localhost:9090/icicles/d1aaeb23-f226-42fe-a614-8cd7baff89f2
2011-06-10 12:49:50,944 WARNING imagefactory.ImageWarehouse.ImageWarehouse pid(29679) Message: Creating a bucket returned status 500, maybe the bucket already exists?
2011-06-10 12:51:38,322 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(29679) Message: Setting metadata ({'icicle': UUID('d1aaeb23-f226-42fe-a614-8cd7baff89f2'), 'uuid': '6b4ab1be-85c0-4929-accd-3366667d2fe5', 'template': UUID('2c1522c8-9331-11e0-807f-bc305bd4a098'), 'target_parameters': 'No Target Paremeters Yet', 'object_type': 'image', 'target': 'ec2'}) for http://localhost:9090/images/6b4ab1be-85c0-4929-accd-3366667d2fe5
2011-06-10 12:51:38,396 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(29679) Message: Image warehouse storage complete
2011-06-10 12:51:38,396 DEBUG imagefactory.qmfagent.BuildAdaptor.BuildAdaptor pid(29679) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed percent complete from 50 to 100
2011-06-10 12:51:38,397 DEBUG imagefactory.qmfagent.BuildAdaptor.BuildAdaptor pid(29679) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed status from BUILDING to COMPLETED
Comment 1 Shveta 2011-06-10 09:10:57 UTC 
Tested on RHEL https://hp-xw6600-01.rhts.eng.bos.redhat.com/conductor/

Template shows completed state both in UI and Logs.
Comment 2 Shveta 2011-06-10 09:12:35 UTC 
Logs On Rhel:
http://pastebin.test.redhat.com/52268
Comment 3 wes hayutin 2011-06-23 13:31:02 UTC 
not supported in new ui
Comment 4 wes hayutin 2011-12-08 14:03:43 UTC 
perm close
Note You need to log in before you can comment on or make changes to this bug.