Bug 726203
Summary: | Using Beta candidate -failure when cleaning up temp instance & security group for RHEL6.1 image | ||
---|---|---|---|
Product: | [Retired] CloudForms Cloud Engine | Reporter: | Steve Reichard <sreichar> |
Component: | imagefactory | Assignee: | Steve Loranz <sloranz> |
Status: | CLOSED CURRENTRELEASE | QA Contact: | Aziza Karol <akarol> |
Severity: | unspecified | Docs Contact: | |
Priority: | unspecified | ||
Version: | 0.3.1 | CC: | akarol, dajohnso, deltacloud-maint, dowoods, hbrock, nobody, scollier, sloranz, ssachdev, vvaldez, whayutin |
Target Milestone: | rc | ||
Target Release: | --- | ||
Hardware: | Unspecified | ||
OS: | Unspecified | ||
Whiteboard: | |||
Fixed In Version: | Doc Type: | Bug Fix | |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | Type: | --- | |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: | |||
Bug Depends On: | |||
Bug Blocks: | 709348 |
Description
Steve Reichard
2011-07-27 20:10:09 UTC
I re-issued the push and had no problems this time. Need to wrap the security group deletion with a check that the instance has been terminated. So I hadn't seen this in my testing from today. I cleaned up or installed three machines tonight and ran builds/pushes to both east and west. Out of a total of 9 attempts, I did hit this error twice. Re-running it was successful. I also observed this issue while trying to push for ec2. rails.log: 2011-07-28 07:13:20,746 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(10296) Message: Setting metadata ({'target_image': '9a3f6309-f6ee-471a-ac3d-939ad13d7920', 'uuid': 'c978e4ec-7b60-46c9-b87d-3cb676869810', 'icicle': 'f3f25854-d525-4872-b35c-478cc3b45cfc', 'target_identifier': 'ami-c1a563a8', 'object_type': 'provider_image', 'provider': 'ec2-us-east-1'}) for http://localhost:9090/provider_images/c978e4ec-7b60-46c9-b87d-3cb676869810 2011-07-28 07:13:20,948 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(10296) Message: Stopping EC2 instance and deleting temp security group 2011-07-28 07:13:22,546 ERROR boto pid(10296) Message: 400 Bad Request 2011-07-28 07:13:22,546 ERROR boto pid(10296) Message: <?xml version="1.0" encoding="UTF-8"?> <Response><Errors><Error><Code>InvalidGroup.InUse</Code><Message>There are active instances using security group 'imagefactory-c978e4ec-7b60-46c9-b87d-3cb676869810'</Message></Error></Errors><RequestID>4ae81430-6923-4c57-ac6c-119a9edef026</RequestID></Response> 2011-07-28 07:13:22,546 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(10296) Message: Exception caught in ImageFactory 2011-07-28 07:13:22,630 DEBUG imagefactory.builders.BaseBuilder.FedoraBuilder pid(10296) Message: Traceback (most recent call last): File "/usr/lib/python2.6/site-packages/imagefactory/builders/FedoraBuilder.py", line 499, in push_image self.push_image_snapshot(target_image_id, provider, credentials) File "/usr/lib/python2.6/site-packages/imagefactory/builders/FedoraBuilder.py", line 511, in push_image_snapshot self.push_image_snapshot_ec2(target_image_id, provider, credentials) File "/usr/lib/python2.6/site-packages/imagefactory/builders/FedoraBuilder.py", line 856, in push_image_snapshot_ec2 factory_security_group.delete() File "/usr/lib/python2.6/site-packages/boto/ec2/securitygroup.py", line 72, in delete return self.connection.delete_security_group(self.name) File "/usr/lib/python2.6/site-packages/boto/ec2/connection.py", line 1291, in delete_security_group return self.get_status('DeleteSecurityGroup', params) File "/usr/lib/python2.6/site-packages/boto/connection.py", line 648, in get_status raise self.ResponseError(response.status, response.reason, body) EC2ResponseError: EC2ResponseError: 400 Bad Request <?xml version="1.0" encoding="UTF-8"?> <Response><Errors><Error><Code>InvalidGroup.InUse</Code><Message>There are active instances using security group 'imagefactory-c978e4ec-7b60-46c9-b87d-3cb676869810'</Message></Error></Errors><RequestID>4ae81430-6923-4c57-ac6c-119a9edef026</RequestID></Response> 2011-07-28 07:13:22,630 DEBUG imagefactory.BuildJob.BuildAdaptor pid(10296) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed status from PUSHING to FAILED [root@dell-pe860-01 deltacloud-rhevm]# rpm -qa | grep aeolus aeolus-conductor-doc-0.3.0-3.el6.noarch aeolus-conductor-0.3.0-3.el6.noarch rubygem-aeolus-image-0.0.1-3.el6.noarch aeolus-all-0.3.0-2.el6.noarch aeolus-conductor-daemons-0.3.0-3.el6.noarch aeolus-configure-2.0.1-2.el6.noarch Does the push actually fail with this error? If so, yes, I would like to try to fix it for beta. If not -- if it's just an ugly error message but the push succeeds anyway -- then I say we rel-note it and forge ahead. Thoughts? --Hugh I agree w/ Hugh in Comment #5 I think Dave and Shveta are trying to determine why pushes to ec2 are failing for her. If we can not recreate push failures on other installs, lets just make a rel-note. In reply to number 5, The push reported that it failed, however the image did make it out to EC2 and was registered with EC2. I did not try launching it. If I see it happen again, I will. So the issue is still coming intermittently while pushing image for ec2 but image can still be launched with image id and build id both in deployable xml This is fixed in: https://github.com/aeolusproject/image_factory/commit/b6ffd11b0941b2d2e4d5996be109f15588e19f97 --- relevant part of the log from my test run --- 2011-07-28 16:24:07,978 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Extracted AMI ID: ami-51b47238 2011-07-28 16:24:07,980 INFO imagefactory.ImageWarehouse.ImageWarehouse pid(4083) Message: Creating a bucket returned status 500. 2011-07-28 16:24:07,986 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(4083) Message: Setting metadata ({'object_type': 'icicle', 'uuid': '69bdc8b3-5179-4730-aa19-038420518de0'}) for http://localhost:9090/icicles/69bdc8b3-5179-4730-aa19-038420518de0 2011-07-28 16:24:07,992 INFO imagefactory.ImageWarehouse.ImageWarehouse pid(4083) Message: Creating a bucket returned status 500. 2011-07-28 16:24:08,007 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(4083) Message: Setting metadata ({'target_image': '684e8dab-3ec3-4f5e-a684-09eeaeb51564', 'uuid': 'e9e5e615-5f37-41df-959f-f1dba2b25310', 'icicle': '69bdc8b3-5179-4730-aa19-038420518de0', 'target_identifier': 'ami-51b47238', 'object_type': 'provider_image', 'provider': 'ec2-us-east-1'}) for http://localhost:9090/provider_images/e9e5e615-5f37-41df-959f-f1dba2b25310 2011-07-28 16:24:08,022 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Stopping EC2 instance and deleting temp security group 2011-07-28 16:24:10,331 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:10,331 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Instance status (shutting-down) - waiting for 'terminated'. [0 of 300 seconds elapsed] 2011-07-28 16:24:15,485 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:15,486 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Instance status (shutting-down) - waiting for 'terminated'. [5 of 300 seconds elapsed] 2011-07-28 16:24:20,671 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:20,671 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Instance status (shutting-down) - waiting for 'terminated'. [10 of 300 seconds elapsed] 2011-07-28 16:24:27,094 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:27,095 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Instance status (shutting-down) - waiting for 'terminated'. [15 of 300 seconds elapsed] 2011-07-28 16:24:32,231 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:32,232 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Instance status (shutting-down) - waiting for 'terminated'. [20 of 300 seconds elapsed] 2011-07-28 16:24:37,387 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:37,387 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Instance status (shutting-down) - waiting for 'terminated'. [25 of 300 seconds elapsed] 2011-07-28 16:24:42,582 WARNING boto pid(4083) Message: Error converting code (Client.UserInitiatedShutdown) to int 2011-07-28 16:24:42,848 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: Removed temporary security group (imagefactory-e9e5e615-5f37-41df-959f-f1dba2b25310) 2011-07-28 16:24:42,848 DEBUG imagefactory.builders.BaseBuilder.RHEL6Builder pid(4083) Message: FedoraBuilder instance 40059664 pushed image with uuid 684e8dab-3ec3-4f5e-a684-09eeaeb51564 to provider_image UUID (e9e5e615-5f37-41df-959f-f1dba2b25310) and set metadata: {'target_image': '684e8dab-3ec3-4f5e-a684-09eeaeb51564', 'target_identifier': 'ami-51b47238', 'icicle': '69bdc8b3-5179-4730-aa19-038420518de0', 'provider': 'ec2-us-east-1'} 2011-07-28 16:24:42,849 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(4083) Message: Setting metadata ({'latest_build': 'd0ee2767-b68a-409d-981f-d19746c5ccf1'}) for http://localhost:9090/images/58ebc55d-d3cc-4317-9a52-972bee228841 2011-07-28 16:24:42,853 DEBUG imagefactory.ImageWarehouse.ImageWarehouse pid(4083) Message: Setting metadata ({'latest_unpushed': None}) for http://localhost:9090/images/58ebc55d-d3cc-4317-9a52-972bee228841 --- QE is requesting a hotfix/errata for this issue to patch the 0.3.0 release :) Ian Mcleod chatted this earlier today: http://repos.fedorapeople.org/repos/aeolus/imagefactory/testing/packages/fedora-14/source/imagefactory-0.4.1-2.fc14.src.rpm http://repos.fedorapeople.org/repos/aeolus/imagefactory/testing/packages/fedora-14/noarch/imagefactory-0.4.1-2.fc14.noarch.rpm I believe that this is now in brew. this works fine using the fedora15 testing repo http://repos.fedorapeople.org/repos/aeolus/conductor/testing/fedora-aeolus-testing.repo *** Bug 726428 has been marked as a duplicate of this bug. *** Aziza please verify these bugs.. Thank you! 2011-09-21 20:43:17,593 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(4586) Message: Getting metadata (['latest_unpushed']) from http://localhost:9090/images/45d12315-d7e7-4d91-b263-dab43e261027 2011-09-21 20:43:17,594 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(4586) Message: Getting metadata (['latest_build']) from http://localhost:9090/images/45d12315-d7e7-4d91-b263-dab43e261027 2011-09-21 20:43:17,596 DEBUG imgfac.ImageWarehouse.ImageWarehouse pid(4586) Message: Setting metadata ({'latest_unpushed': '5deb4516-724a-43a2-9c8d-c1e745997416'}) for http://localhost:9090/images/45d12315-d7e7-4d91-b263-dab43e261027 2011-09-21 20:43:17,598 DEBUG imgfac.BuildJob.BuildAdaptor pid(4586) Message: Raising event with agent handler (<ImageFactoryAgent(Thread-1, initial)>), changed status from NEW to COMPLETED 2011-09-21 20:43:17,599 DEBUG imgfac.builders.BaseBuilder.RHEL6_ec2_Builder pid(4586) Message: Completed placeholder warehouse object for linux non-upload image... [root@unused ~]# rpm -qa | grep aeolus aeolus-conductor-doc-0.4.0-0.20110922165939git5b371be.fc15.noarch aeolus-conductor-0.4.0-0.20110922165939git5b371be.fc15.noarch aeolus-conductor-daemons-0.4.0-0.20110922165939git5b371be.fc15.noarch aeolus-all-0.4.0-0.20110922165939git5b371be.fc15.noarch aeolus-conductor-devel-0.4.0-0.20110922165939git5b371be.fc15.noarch aeolus-configure-2.0.2-4.20110921102958gitcaa9608.fc15.noarch rubygem-aeolus-image-0.1.0-3.20110922120732gita0b9a44.fc15.noarch *** Bug 736490 has been marked as a duplicate of this bug. *** perm close closing out old bugs |