Connecting to database specified by database.yml
[1m[36m (28.1ms)[0m [1mselect sqlite_version(*)[0m
[1m[35m (127.8ms)[0m CREATE TABLE "tim_base_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "description" varchar(255), "template_id" integer, "user_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "pool_family_id" integer)
[1m[36m (86.0ms)[0m [1mCREATE TABLE "tim_image_versions" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "base_image_id" integer, "template_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (120.5ms)[0m CREATE TABLE "tim_provider_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "target_image_id" integer, "provider" varchar(255), "external_image_id" varchar(255), "provider_account_id" varchar(255), "snapshot" boolean, "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (98.7ms)[0m [1mCREATE TABLE "tim_target_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "image_version_id" integer, "target" varchar(255), "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "provider_type_id" integer) [0m
[1m[35m (167.5ms)[0m CREATE TABLE "tim_templates" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "xml" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (105.1ms)[0m [1mCREATE TABLE "pool_families" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (90.4ms)[0m CREATE TABLE "provider_accounts" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (119.7ms)[0m [1mCREATE TABLE "provider_types" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (111.4ms)[0m CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (90.8ms)[0m [1mCREATE TABLE "schema_migrations" ("version" varchar(255) NOT NULL) [0m
[1m[35m (0.1ms)[0m PRAGMA index_list("schema_migrations")
[1m[36m (124.3ms)[0m [1mCREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")[0m
[1m[35m (0.1ms)[0m SELECT version FROM "schema_migrations"
[1m[36m (91.2ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120423123114264114')[0m
[1m[35m (91.3ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120326103723532622')
[1m[36m (91.5ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911203222')[0m
[1m[35m (91.5ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911182850')
[1m[36m (91.5ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911205431')[0m
[1m[35m (91.5ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911202845')
[1m[36m (126.7ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120906180351')[0m
[1m[35m (89.6ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120906210106')
[1m[36m (83.2ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911202321')[0m
[1m[35m (83.2ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911204329')
[1m[36m (74.8ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120910175233')[0m
[1m[35m (0.1ms)[0m SELECT "schema_migrations"."version" FROM "schema_migrations"
Connecting to database specified by database.yml
[1m[36m (0.1ms)[0m [1mSELECT "schema_migrations"."version" FROM "schema_migrations" [0m
[1m[35m (0.3ms)[0m select sqlite_version(*)
[1m[36m (150.6ms)[0m [1mCREATE TABLE "tim_base_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "description" varchar(255), "template_id" integer, "user_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "pool_family_id" integer) [0m
[1m[35m (95.9ms)[0m CREATE TABLE "tim_image_versions" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "base_image_id" integer, "template_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (95.1ms)[0m [1mCREATE TABLE "tim_provider_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "target_image_id" integer, "provider" varchar(255), "external_image_id" varchar(255), "provider_account_id" varchar(255), "snapshot" boolean, "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (111.0ms)[0m CREATE TABLE "tim_target_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "image_version_id" integer, "target" varchar(255), "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "provider_type_id" integer)
[1m[36m (113.4ms)[0m [1mCREATE TABLE "tim_templates" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "xml" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (84.7ms)[0m CREATE TABLE "pool_families" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (74.2ms)[0m [1mCREATE TABLE "provider_accounts" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (100.5ms)[0m CREATE TABLE "provider_types" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (89.2ms)[0m [1mCREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (82.9ms)[0m CREATE TABLE "schema_migrations" ("version" varchar(255) NOT NULL)
[1m[36m (0.0ms)[0m [1mPRAGMA index_list("schema_migrations")[0m
[1m[35m (103.5ms)[0m CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")
[1m[36m (0.0ms)[0m [1mSELECT version FROM "schema_migrations"[0m
[1m[35m (87.3ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120423123114264114')
[1m[36m (74.9ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120326103723532622')[0m
[1m[35m (74.9ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911203222')
[1m[36m (74.9ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911182850')[0m
[1m[35m (108.3ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911205431')
[1m[36m (83.1ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911202845')[0m
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:37:24 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MySecondBaseImage", "description"=>"This is my very second base image"}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35mSQL (53.4ms)[0m INSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?) [["created_at", Tue, 09 Oct 2012 15:37:27 UTC +00:00], ["description", "This is my very second base image"], ["name", "MySecondBaseImage"], ["pool_family_id", nil], ["template_id", nil], ["updated_at", Tue, 09 Oct 2012 15:37:27 UTC +00:00], ["user_id", nil]]
[1m[36m (117.6ms)[0m [1mcommit transaction[0m
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 1
Rendered tim/base_images/_custom.xml.haml (1.2ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (117.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (129.3ms)
Completed 201 Created in 392ms (Views: 131.2ms | ActiveRecord: 0.5ms)
Started GET "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:41:12 -0400
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.2ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (1.5ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (3.9ms)
Completed 200 OK in 9ms (Views: 6.7ms | ActiveRecord: 0.2ms)
Connecting to database specified by database.yml
Started DELETE "/tim/base_images/1" for 127.0.0.1 at 2012-10-09 11:43:40 -0400
Processing by Tim::BaseImagesController#destroy as XML
Parameters: {"id"=>"1"}
WARNING: Can't verify CSRF token authenticity
[1m[36mTim::BaseImage Load (0.2ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = ? LIMIT 1[0m [["id", "1"]]
[1m[35m (0.0ms)[0m begin transaction
[1m[36mSQL (3.2ms)[0m [1mDELETE FROM "tim_base_images" WHERE "tim_base_images"."id" = ?[0m [["id", 1]]
[1m[35m (93.5ms)[0m commit transaction
Completed 204 No Content in 148ms (ActiveRecord: 0.0ms)
Started GET "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:43:52 -0400
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.2ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (1.7ms)
Completed 200 OK in 6ms (Views: 4.6ms | ActiveRecord: 0.2ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:44:09 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MySecondBaseImage", "description"=>"This is my very second base image"}}
WARNING: Can't verify CSRF token authenticity
[1m[35m (0.1ms)[0m begin transaction
[1m[36mSQL (1.4ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Tue, 09 Oct 2012 15:44:09 UTC +00:00], ["description", "This is my very second base image"], ["name", "MySecondBaseImage"], ["pool_family_id", nil], ["template_id", nil], ["updated_at", Tue, 09 Oct 2012 15:44:09 UTC +00:00], ["user_id", nil]]
[1m[35m (123.4ms)[0m commit transaction
[1m[36mTim::ImageVersion Load (0.1ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 2[0m
Rendered tim/base_images/_custom.xml.haml (1.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (85.9ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (90.8ms)
Completed 201 Created in 225ms (Views: 92.9ms | ActiveRecord: 0.5ms)
Started GET "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:44:19 -0400
Processing by Tim::BaseImagesController#index as XML
[1m[35mTim::BaseImage Load (0.3ms)[0m SELECT "tim_base_images".* FROM "tim_base_images"
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (1.5ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (2.4ms)
Completed 200 OK in 7ms (Views: 5.3ms | ActiveRecord: 0.3ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:44:22 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MySecondBaseImage", "description"=>"This is my very second base image"}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.1ms)[0m [1mbegin transaction[0m
[1m[35mSQL (0.5ms)[0m INSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?) [["created_at", Tue, 09 Oct 2012 15:44:22 UTC +00:00], ["description", "This is my very second base image"], ["name", "MySecondBaseImage"], ["pool_family_id", nil], ["template_id", nil], ["updated_at", Tue, 09 Oct 2012 15:44:22 UTC +00:00], ["user_id", nil]]
[1m[36m (107.1ms)[0m [1mcommit transaction[0m
[1m[35mTim::ImageVersion Load (0.2ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 3
Rendered tim/base_images/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (3.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (4.0ms)
Completed 201 Created in 119ms (Views: 6.4ms | ActiveRecord: 0.2ms)
Started GET "/tim/base_images" for 127.0.0.1 at 2012-10-09 11:44:58 -0400
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.2ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.6ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (2.2ms)
Completed 200 OK in 5ms (Views: 4.3ms | ActiveRecord: 0.2ms)
Started GET "/tim/base_images/3" for 127.0.0.1 at 2012-10-09 11:45:11 -0400
Processing by Tim::BaseImagesController#show as XML
Parameters: {"id"=>"3"}
[1m[35mTim::BaseImage Load (0.1ms)[0m SELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = ? LIMIT 1 [["id", "3"]]
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 3[0m
Rendered tim/base_images/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (2.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (3.2ms)
Completed 200 OK in 7ms (Views: 5.1ms | ActiveRecord: 0.3ms)
Connecting to database specified by database.yml
Started GET "/tim" for 127.0.0.1 at 2012-10-09 14:09:32 -0400
Connecting to database specified by database.yml
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (3.5ms)
Completed 200 OK in 37ms (Views: 36.4ms | ActiveRecord: 0.0ms)
Started GET "/tim/api" for 127.0.0.1 at 2012-10-09 14:09:49 -0400
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (1.6ms)
Completed 200 OK in 5ms (Views: 4.4ms | ActiveRecord: 0.0ms)
Started GET "/tim/api" for 127.0.0.1 at 2012-10-09 14:14:35 -0400
Connecting to database specified by database.yml
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (3.5ms)
Completed 200 OK in 37ms (Views: 36.2ms | ActiveRecord: 0.0ms)
Started GET "/tim" for 127.0.0.1 at 2012-10-09 14:14:47 -0400
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (1.6ms)
Completed 200 OK in 5ms (Views: 4.3ms | ActiveRecord: 0.0ms)
Connecting to database specified by database.yml
Started GET "/tim/" for 127.0.0.1 at 2012-10-09 16:05:09 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.1ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (1.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (6.5ms)
Completed 200 OK in 52ms (Views: 41.9ms | ActiveRecord: 0.3ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-09 16:05:52 -0400
Connecting to database specified by database.yml
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (3.6ms)
Completed 200 OK in 37ms (Views: 36.2ms | ActiveRecord: 0.0ms)
Started GET "/tim/templates" for 127.0.0.1 at 2012-10-09 16:06:04 -0400
Processing by Tim::TemplatesController#index as XML
[1m[36mTim::Template Load (0.1ms)[0m [1mSELECT "tim_templates".* FROM "tim_templates" [0m
Rendered tim/templates/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template.xml.haml (3.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/index.xml.haml (6.9ms)
Completed 200 OK in 15ms (Views: 9.4ms | ActiveRecord: 0.2ms)
Started GET "/tim/templates/1" for 127.0.0.1 at 2012-10-09 16:06:31 -0400
Processing by Tim::TemplatesController#show as XML
Parameters: {"id"=>"1"}
[1m[35mTim::Template Load (0.3ms)[0m SELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = ? LIMIT 1 [["id", "1"]]
Rendered tim/templates/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template.xml.haml (1.6ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/show.xml.haml (3.4ms)
Completed 200 OK in 9ms (Views: 6.2ms | ActiveRecord: 0.3ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-09 16:06:41 -0400
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (1.5ms)
Completed 200 OK in 5ms (Views: 4.3ms | ActiveRecord: 0.0ms)
Started GET "/tim/base_images" for 127.0.0.1 at 2012-10-09 16:06:51 -0400
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.1ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (1.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (4.2ms)
Completed 200 OK in 43ms (Views: 6.8ms | ActiveRecord: 0.2ms)
Started GET "/tim/base_images/2" for 127.0.0.1 at 2012-10-09 16:06:58 -0400
Processing by Tim::BaseImagesController#show as XML
Parameters: {"id"=>"2"}
[1m[35mTim::BaseImage Load (0.3ms)[0m SELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = ? LIMIT 1 [["id", "2"]]
[1m[36mTim::Template Load (0.2ms)[0m [1mSELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = 1 LIMIT 1[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.5ms)
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 2
Rendered tim/base_images/_custom.xml.haml (1.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (91.5ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (93.3ms)
Completed 200 OK in 98ms (Views: 95.4ms | ActiveRecord: 0.9ms)
Started POST "/tim/image_versions" for 127.0.0.1 at 2012-10-09 16:16:02 -0400
Processing by Tim::ImageVersionsController#create as XML
Parameters: {"image_version"=>{"base_image"=>{"id"=>"2"}}}
WARNING: Can't verify CSRF token authenticity
Rendered text template (0.0ms)
Completed 404 Not Found in 35ms (Views: 28.9ms | ActiveRecord: 0.0ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-09 16:16:27 -0400
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (1.3ms)
Completed 200 OK in 4ms (Views: 3.6ms | ActiveRecord: 0.0ms)
Started GET "/tim/image_versions" for 127.0.0.1 at 2012-10-09 16:21:33 -0400
Processing by Tim::ImageVersionsController#index as XML
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/index.xml.haml (1.4ms)
Completed 200 OK in 6ms (Views: 4.2ms | ActiveRecord: 0.2ms)
Started POST "/tim/image_versions" for 127.0.0.1 at 2012-10-09 16:22:17 -0400
Processing by Tim::ImageVersionsController#create as XML
Parameters: {"image_version"=>{"base_image"=>{"id"=>"2"}}}
WARNING: Can't verify CSRF token authenticity
Rendered text template (0.0ms)
Completed 404 Not Found in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)
Started GET "/tim/templates" for 127.0.0.1 at 2012-10-09 16:23:15 -0400
Processing by Tim::TemplatesController#index as XML
[1m[35mTim::Template Load (0.2ms)[0m SELECT "tim_templates".* FROM "tim_templates"
Rendered tim/templates/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template.xml.haml (1.6ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/index.xml.haml (2.6ms)
Completed 200 OK in 6ms (Views: 5.1ms | ActiveRecord: 0.2ms)
Started GET "/tim/templates/1" for 127.0.0.1 at 2012-10-09 16:23:27 -0400
Processing by Tim::TemplatesController#show as XML
Parameters: {"id"=>"1"}
[1m[36mTim::Template Load (0.1ms)[0m [1mSELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = ? LIMIT 1[0m [["id", "1"]]
Rendered tim/templates/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template.xml.haml (1.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/show.xml.haml (2.2ms)
Completed 200 OK in 6ms (Views: 4.5ms | ActiveRecord: 0.1ms)
Connecting to database specified by database.yml
Started POST "/tim/image_versions" for 127.0.0.1 at 2012-10-09 16:37:51 -0400
Processing by Tim::ImageVersionsController#create as XML
Parameters: {"image_version"=>{"base_image"=>{"name"=>"Barney", "description"=>"Wow, this is one cool base image"}}}
WARNING: Can't verify CSRF token authenticity
[1m[35m (0.1ms)[0m begin transaction
[1m[36mSQL (4.0ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Tue, 09 Oct 2012 20:37:51 UTC +00:00], ["description", "Wow, this is one cool base image"], ["name", "Barney"], ["pool_family_id", nil], ["template_id", nil], ["updated_at", Tue, 09 Oct 2012 20:37:51 UTC +00:00], ["user_id", nil]]
[1m[35mSQL (0.2ms)[0m INSERT INTO "tim_image_versions" ("base_image_id", "created_at", "template_id", "updated_at") VALUES (?, ?, ?, ?) [["base_image_id", 4], ["created_at", Tue, 09 Oct 2012 20:37:51 UTC +00:00], ["template_id", nil], ["updated_at", Tue, 09 Oct 2012 20:37:51 UTC +00:00]]
[1m[36m (92.0ms)[0m [1mcommit transaction[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
[1m[35mTim::TargetImage Load (0.1ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."image_version_id" = 1
Rendered tim/image_versions/_custom.xml.haml (0.8ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version.xml.haml (13.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/show.xml.haml (15.3ms)
Completed 201 Created in 122ms (Views: 17.4ms | ActiveRecord: 0.4ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-10 13:38:50 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.2ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (1.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (7.4ms)
Completed 200 OK in 53ms (Views: 42.8ms | ActiveRecord: 0.3ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-10 13:44:26 -0400
Processing by Tim::BaseImagesController#index as XML
[1m[35mTim::BaseImage Load (0.3ms)[0m SELECT "tim_base_images".* FROM "tim_base_images"
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (3.6ms)
Completed 200 OK in 8ms (Views: 6.4ms | ActiveRecord: 0.3ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-10 13:44:58 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"ThisIsABaseImage", "template"=>{"name"=>"mock", "os"=>{"name"=>"RHEL-6", "version"=>"1", "arch"=>"x86_64", "install"=>{"type"=>"iso", "iso"=>"http://mockhost/RHELMock1-x86_64-DVD.iso"}, "rootpw"=>"password"}, "description"=>"Mock Template"}, "image_versions"=>[{"target_images"=>[{"target"=>"MockSphere"}]}]}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35mSQL (33.7ms)[0m INSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?) [["created_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00], ["updated_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00], ["xml", "\n mock\n \n RHEL-6\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n "]]
[1m[36mSQL (0.3ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00], ["description", "ThisIsABaseImage"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 2], ["updated_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00], ["user_id", nil]]
[1m[35mSQL (0.2ms)[0m INSERT INTO "tim_image_versions" ("base_image_id", "created_at", "template_id", "updated_at") VALUES (?, ?, ?, ?) [["base_image_id", 5], ["created_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00], ["template_id", nil], ["updated_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_target_images" ("created_at", "factory_id", "image_version_id", "progress", "provider_type_id", "status", "status_detail", "target", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00], ["factory_id", nil], ["image_version_id", 2], ["progress", nil], ["provider_type_id", nil], ["status", nil], ["status_detail", nil], ["target", "MockSphere"], ["updated_at", Wed, 10 Oct 2012 17:44:58 UTC +00:00]]
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 2 LIMIT 1
[1m[36mTim::BaseImage Load (0.1ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = 5 LIMIT 1[0m
[1m[35mTim::Template Load (0.1ms)[0m SELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = 2 LIMIT 1
[1m[36m (0.4ms)[0m [1mUPDATE "tim_target_images" SET "target" = 'MockSphere', "image_version_id" = 2, "created_at" = '2012-10-10 17:44:58.971657', "updated_at" = '2012-10-10 17:44:58.971657', "status" = 'NEW', "factory_id" = '8c8916a4-1dfb-4d96-9372-d3deae5e9d4d', "status_detail" = 'Initializing image prior to Cloud/OS customization', "progress" = 0 WHERE "tim_target_images"."id" = 1[0m
[1m[35m (109.7ms)[0m commit transaction
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.1ms)
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 5[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (1.1ms)
Rendered tim/base_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (8.6ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (10.2ms)
Completed 201 Created in 11573ms (Views: 12.0ms | ActiveRecord: 0.2ms)
Started PUT "/tim/target_images//1" for 127.0.0.1 at 2012-10-10 13:45:13 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"base_image"=>{"status"=>"FAILED", "_type"=>"BaseImage", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//1"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Generating JEOS install media"}, "template"=>"\n mock\n \n RHEL-6\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"f54835b3-847e-4ed6-8968-52b8624c6944"}, "id"=>"1", "target_image"=>{}}
WARNING: Can't verify CSRF token authenticity
[1m[35mTim::TargetImage Load (0.3ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "1"]]
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35m (0.0ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/1
Completed 302 Found in 51ms (ActiveRecord: 0.0ms)
Started PUT "/tim/target_images//1" for 127.0.0.1 at 2012-10-10 13:45:13 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"target_image"=>{"status"=>"FAILED", "_type"=>"TargetImage", "target"=>"MockSphere", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//1"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHEL-6\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"8c8916a4-1dfb-4d96-9372-d3deae5e9d4d"}, "id"=>"1"}
WARNING: Can't verify CSRF token authenticity
[1m[36mTim::TargetImage Load (0.1ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1[0m [["id", "1"]]
[1m[35m (0.1ms)[0m begin transaction
[1m[36m (0.3ms)[0m [1mUPDATE "tim_target_images" SET "progress" = 0, "status" = 'FAILED', "updated_at" = '2012-10-10 17:45:13.614194' WHERE "tim_target_images"."id" = 1[0m
[1m[35m (90.4ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/1
Completed 302 Found in 98ms (ActiveRecord: 0.0ms)
Started GET "/tim/image_versions/2" for 127.0.0.1 at 2012-10-10 13:46:37 -0400
Processing by Tim::ImageVersionsController#show as XML
Parameters: {"id"=>"2"}
[1m[36mTim::ImageVersion Load (0.3ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = ? LIMIT 1[0m [["id", "2"]]
[1m[35mTim::BaseImage Load (0.1ms)[0m SELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = 5 LIMIT 1
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
[1m[36mTim::TargetImage Load (0.1ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."image_version_id" = 2[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image_minimal.xml.haml (1.1ms)
Rendered tim/image_versions/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version.xml.haml (8.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/show.xml.haml (9.6ms)
Completed 200 OK in 14ms (Views: 11.9ms | ActiveRecord: 0.5ms)
Started GET "/tim/target_images/1" for 127.0.0.1 at 2012-10-10 13:47:00 -0400
Processing by Tim::TargetImagesController#show as XML
Parameters: {"id"=>"1"}
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "1"]]
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 2 LIMIT 1[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (0.3ms)
Rendered tim/target_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image.xml.haml (6.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/show.xml.haml (7.9ms)
Completed 200 OK in 12ms (Views: 10.5ms | ActiveRecord: 0.3ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-10 13:57:49 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"ThisIsABaseImage", "template"=>{"name"=>"mock", "os"=>{"name"=>"RHELMock", "version"=>"1", "arch"=>"x86_64", "install"=>{"type"=>"iso", "iso"=>"http://mockhost/RHELMock1-x86_64-DVD.iso"}, "rootpw"=>"password"}, "description"=>"Mock Template"}, "image_versions"=>[{"target_images"=>[{"target"=>"MockSphere"}]}]}}
WARNING: Can't verify CSRF token authenticity
[1m[35m (0.1ms)[0m begin transaction
[1m[36m (0.0ms)[0m [1mrollback transaction[0m
Completed 422 Unprocessable Entity in 21ms (Views: 15.5ms | ActiveRecord: 0.1ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-10 14:11:38 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"ThisIsABaseImage", "template"=>{"name"=>"mock", "os"=>{"name"=>"RHELMock", "version"=>"1", "arch"=>"x86_64", "install"=>{"type"=>"iso", "iso"=>"http://mockhost/RHELMock1-x86_64-DVD.iso"}, "rootpw"=>"password"}, "description"=>"Mock Template"}, "image_versions"=>[{"target_images"=>[{"target"=>"MockSphere"}]}]}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35m (0.1ms)[0m rollback transaction
Completed 500 Internal Server Error in 182ms
Nokogiri::XML::SyntaxError (xmlRelaxNGParse: schemas is empty):
nokogiri (1.5.5) lib/nokogiri/xml/schema.rb:37:in `from_document'
nokogiri (1.5.5) lib/nokogiri/xml/schema.rb:37:in `new'
nokogiri (1.5.5) lib/nokogiri/xml/relax_ng.rb:8:in `RelaxNG'
/home/jay/projects/aeolus/tim/app/validators/template_validator.rb:7:in `validate'
activesupport (3.2.8) lib/active_support/callbacks.rb:310:in `_callback_before_81'
activesupport (3.2.8) lib/active_support/callbacks.rb:407:in `_run__2625047927881804411__validate__1558958144043740305__callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_validate_callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
activemodel (3.2.8) lib/active_model/validations.rb:227:in `run_validations!'
activemodel (3.2.8) lib/active_model/validations/callbacks.rb:53:in `block in run_validations!'
activesupport (3.2.8) lib/active_support/callbacks.rb:403:in `_run__2625047927881804411__validation__1558958144043740305__callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_validation_callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
activemodel (3.2.8) lib/active_model/validations/callbacks.rb:53:in `run_validations!'
activemodel (3.2.8) lib/active_model/validations.rb:194:in `valid?'
activerecord (3.2.8) lib/active_record/validations.rb:69:in `valid?'
activerecord (3.2.8) lib/active_record/autosave_association.rb:300:in `association_valid?'
activerecord (3.2.8) lib/active_record/autosave_association.rb:280:in `validate_single_association'
activerecord (3.2.8) lib/active_record/autosave_association.rb:217:in `block in add_autosave_association_callbacks'
activerecord (3.2.8) lib/active_record/autosave_association.rb:161:in `instance_eval'
activerecord (3.2.8) lib/active_record/autosave_association.rb:161:in `block in define_non_cyclic_method'
activesupport (3.2.8) lib/active_support/callbacks.rb:418:in `_run__1605225500616527971__validate__1558958144043740305__callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_validate_callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
activemodel (3.2.8) lib/active_model/validations.rb:227:in `run_validations!'
activemodel (3.2.8) lib/active_model/validations/callbacks.rb:53:in `block in run_validations!'
activesupport (3.2.8) lib/active_support/callbacks.rb:403:in `_run__1605225500616527971__validation__1558958144043740305__callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_validation_callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
activemodel (3.2.8) lib/active_model/validations/callbacks.rb:53:in `run_validations!'
activemodel (3.2.8) lib/active_model/validations.rb:194:in `valid?'
activerecord (3.2.8) lib/active_record/validations.rb:69:in `valid?'
activerecord (3.2.8) lib/active_record/validations.rb:77:in `perform_validations'
activerecord (3.2.8) lib/active_record/validations.rb:50:in `save'
activerecord (3.2.8) lib/active_record/attribute_methods/dirty.rb:22:in `save'
activerecord (3.2.8) lib/active_record/transactions.rb:241:in `block (2 levels) in save'
activerecord (3.2.8) lib/active_record/transactions.rb:295:in `block in with_transaction_returning_status'
activerecord (3.2.8) lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
activerecord (3.2.8) lib/active_record/transactions.rb:208:in `transaction'
activerecord (3.2.8) lib/active_record/transactions.rb:293:in `with_transaction_returning_status'
activerecord (3.2.8) lib/active_record/transactions.rb:241:in `block in save'
activerecord (3.2.8) lib/active_record/transactions.rb:252:in `rollback_active_record_state!'
activerecord (3.2.8) lib/active_record/transactions.rb:240:in `save'
/home/jay/projects/aeolus/tim/app/controllers/tim/base_images_controller.rb:29:in `create'
actionpack (3.2.8) lib/action_controller/metal/implicit_render.rb:4:in `send_action'
actionpack (3.2.8) lib/abstract_controller/base.rb:167:in `process_action'
actionpack (3.2.8) lib/action_controller/metal/rendering.rb:10:in `process_action'
actionpack (3.2.8) lib/abstract_controller/callbacks.rb:18:in `block in process_action'
activesupport (3.2.8) lib/active_support/callbacks.rb:436:in `_run__1928484600686217726__process_action__1087077879857957708__callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
actionpack (3.2.8) lib/abstract_controller/callbacks.rb:17:in `process_action'
actionpack (3.2.8) lib/action_controller/metal/rescue.rb:29:in `process_action'
actionpack (3.2.8) lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
activesupport (3.2.8) lib/active_support/notifications.rb:123:in `block in instrument'
activesupport (3.2.8) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
activesupport (3.2.8) lib/active_support/notifications.rb:123:in `instrument'
actionpack (3.2.8) lib/action_controller/metal/instrumentation.rb:29:in `process_action'
actionpack (3.2.8) lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
activerecord (3.2.8) lib/active_record/railties/controller_runtime.rb:18:in `process_action'
actionpack (3.2.8) lib/abstract_controller/base.rb:121:in `process'
actionpack (3.2.8) lib/abstract_controller/rendering.rb:45:in `process'
actionpack (3.2.8) lib/action_controller/metal.rb:203:in `dispatch'
actionpack (3.2.8) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
actionpack (3.2.8) lib/action_controller/metal.rb:246:in `block in action'
actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:73:in `call'
actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:36:in `call'
journey (1.0.4) lib/journey/router.rb:68:in `block in call'
journey (1.0.4) lib/journey/router.rb:56:in `each'
journey (1.0.4) lib/journey/router.rb:56:in `call'
actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:600:in `call'
railties (3.2.8) lib/rails/engine.rb:479:in `call'
railties (3.2.8) lib/rails/railtie/configurable.rb:30:in `method_missing'
journey (1.0.4) lib/journey/router.rb:68:in `block in call'
journey (1.0.4) lib/journey/router.rb:56:in `each'
journey (1.0.4) lib/journey/router.rb:56:in `call'
actionpack (3.2.8) lib/action_dispatch/routing/route_set.rb:600:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
rack (1.4.1) lib/rack/etag.rb:23:in `call'
rack (1.4.1) lib/rack/conditionalget.rb:35:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/head.rb:14:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/params_parser.rb:21:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/flash.rb:242:in `call'
rack (1.4.1) lib/rack/session/abstract/id.rb:205:in `context'
rack (1.4.1) lib/rack/session/abstract/id.rb:200:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/cookies.rb:339:in `call'
activerecord (3.2.8) lib/active_record/query_cache.rb:64:in `call'
activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `_run__1214831014544490869__call__1558958144043740305__callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
actionpack (3.2.8) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/reloader.rb:65:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
railties (3.2.8) lib/rails/rack/logger.rb:26:in `call_app'
railties (3.2.8) lib/rails/rack/logger.rb:16:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/request_id.rb:22:in `call'
rack (1.4.1) lib/rack/methodoverride.rb:21:in `call'
rack (1.4.1) lib/rack/runtime.rb:17:in `call'
activesupport (3.2.8) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
rack (1.4.1) lib/rack/lock.rb:15:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/static.rb:62:in `call'
railties (3.2.8) lib/rails/engine.rb:479:in `call'
railties (3.2.8) lib/rails/application.rb:223:in `call'
rack (1.4.1) lib/rack/content_length.rb:14:in `call'
railties (3.2.8) lib/rails/rack/log_tailer.rb:17:in `call'
rack (1.4.1) lib/rack/handler/webrick.rb:59:in `service'
/home/jay/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service'
/home/jay/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run'
/home/jay/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread'
Rendered /home/jay/.rvm/gems/ruby-1.9.3-p194@tim/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/_trace.erb (1.3ms)
Rendered /home/jay/.rvm/gems/ruby-1.9.3-p194@tim/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb (1.0ms)
Rendered /home/jay/.rvm/gems/ruby-1.9.3-p194@tim/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (8.5ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-10 14:14:04 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"ThisIsABaseImage", "template"=>{"name"=>"mock", "os"=>{"name"=>"RHELMock", "version"=>"1", "arch"=>"x86_64", "install"=>{"type"=>"iso", "iso"=>"http://mockhost/RHELMock1-x86_64-DVD.iso"}, "rootpw"=>"password"}, "description"=>"Mock Template"}, "image_versions"=>[{"target_images"=>[{"target"=>"MockSphere"}]}]}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35mSQL (4.2ms)[0m INSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?) [["created_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00], ["updated_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00], ["xml", "\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n "]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00], ["description", "ThisIsABaseImage"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 3], ["updated_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00], ["user_id", nil]]
[1m[35mSQL (0.2ms)[0m INSERT INTO "tim_image_versions" ("base_image_id", "created_at", "template_id", "updated_at") VALUES (?, ?, ?, ?) [["base_image_id", 6], ["created_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00], ["template_id", nil], ["updated_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_target_images" ("created_at", "factory_id", "image_version_id", "progress", "provider_type_id", "status", "status_detail", "target", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00], ["factory_id", nil], ["image_version_id", 3], ["progress", nil], ["provider_type_id", nil], ["status", nil], ["status_detail", nil], ["target", "MockSphere"], ["updated_at", Wed, 10 Oct 2012 18:14:06 UTC +00:00]]
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 3 LIMIT 1
[1m[36mTim::BaseImage Load (0.1ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = 6 LIMIT 1[0m
[1m[35mTim::Template Load (0.1ms)[0m SELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = 3 LIMIT 1
[1m[36m (0.6ms)[0m [1mUPDATE "tim_target_images" SET "target" = 'MockSphere', "image_version_id" = 3, "created_at" = '2012-10-10 18:14:06.784824', "updated_at" = '2012-10-10 18:14:06.784824', "status" = 'NEW', "factory_id" = '66bdde40-5484-422c-a44a-e83cdc54b318', "status_detail" = 'Initializing image prior to Cloud/OS customization', "progress" = 0 WHERE "tim_target_images"."id" = 2[0m
[1m[35m (105.7ms)[0m commit transaction
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.1ms)
[1m[36mTim::ImageVersion Load (0.3ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 6[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (1.2ms)
Rendered tim/base_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (9.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (13.5ms)
Completed 201 Created in 394ms (Views: 17.0ms | ActiveRecord: 0.3ms)
Started PUT "/tim/target_images//2" for 127.0.0.1 at 2012-10-10 14:14:07 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"base_image"=>{"status"=>"COMPLETE", "_type"=>"BaseImage", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//2"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"fe30d4ea-7e16-402a-9fc4-5bc71f30c2c3"}, "id"=>"2", "target_image"=>{}}
WARNING: Can't verify CSRF token authenticity
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "2"]]
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35m (0.0ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/2
Completed 302 Found in 13ms (ActiveRecord: 0.0ms)
Started PUT "/tim/target_images//2" for 127.0.0.1 at 2012-10-10 14:14:16 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"target_image"=>{"status"=>"COMPLETE", "_type"=>"TargetImage", "target"=>"MockSphere", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//2"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"66bdde40-5484-422c-a44a-e83cdc54b318"}, "id"=>"2"}
WARNING: Can't verify CSRF token authenticity
[1m[36mTim::TargetImage Load (0.1ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1[0m [["id", "2"]]
[1m[35m (0.1ms)[0m begin transaction
[1m[36m (0.3ms)[0m [1mUPDATE "tim_target_images" SET "progress" = 0, "status" = 'COMPLETE', "updated_at" = '2012-10-10 18:14:16.665057' WHERE "tim_target_images"."id" = 2[0m
[1m[35m (114.8ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/2
Completed 302 Found in 121ms (ActiveRecord: 0.0ms)
Started GET "/tim/target_images" for 127.0.0.1 at 2012-10-10 14:15:19 -0400
Processing by Tim::TargetImagesController#index as XML
[1m[36mTim::TargetImage Load (0.2ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image_minimal.xml.haml (1.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/index.xml.haml (5.0ms)
Completed 200 OK in 9ms (Views: 7.7ms | ActiveRecord: 0.2ms)
Started GET "/tim/target_images/2" for 127.0.0.1 at 2012-10-10 14:15:27 -0400
Processing by Tim::TargetImagesController#show as XML
Parameters: {"id"=>"2"}
[1m[35mTim::TargetImage Load (0.1ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "2"]]
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 3 LIMIT 1[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (0.3ms)
Rendered tim/target_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image.xml.haml (5.8ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/show.xml.haml (7.5ms)
Completed 200 OK in 11ms (Views: 9.6ms | ActiveRecord: 0.3ms)
Connecting to database specified by database.yml
Started PUT "/tim/provider_images//2" for 127.0.0.1 at 2012-10-10 16:31:26 -0400
Connecting to database specified by database.yml
Processing by Tim::ProviderImagesController#update as HTML
Parameters: {"provider_image"=>{"status"=>"COMPLETE", "_type"=>"ProviderImage", "parameters"=>nil, "identifier_on_provider"=>nil, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "provider_account_identifier"=>nil, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "provider"=>"MockSphere", "percent_complete"=>0, "id"=>"2be7a961-2929-475e-a2ee-ab4d159f6417"}, "id"=>"2"}
WARNING: Can't verify CSRF token authenticity
Filter chain halted as Tim::UserKeysFilter rendered or redirected
Completed 422 Unprocessable Entity in 1ms (ActiveRecord: 0.0ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-11 09:46:30 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#index as XML
[1m[36mTim::BaseImage Load (0.2ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" [0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (1.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/index.xml.haml (31.1ms)
Completed 200 OK in 124ms (Views: 113.6ms | ActiveRecord: 0.3ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-11 09:47:06 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"This is my very first base image", "template"=>{"name"=>"Fedora 15", "description"=>"desc", "os"=>{"rootpw"=>"password", "name"=>"Fedora", "arch"=>"x86_64", "version"=>"15", "install"=>{"type"=>"url", "url"=>"http://download.fedoraproject.org/pub/fedora/linux/releases/15/Fedora/x86_64/os/"}}, "repositories"=>{"repository"=>{"name"=>"custom", "url"=>"http://repos.fedorapeople.org/repos/aeolus/demo/webapp/", "signed"=>"false"}}}}}
WARNING: Can't verify CSRF token authenticity
[1m[35m (0.1ms)[0m begin transaction
[1m[36mSQL (27.8ms)[0m [1mINSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 13:47:06 UTC +00:00], ["updated_at", Thu, 11 Oct 2012 13:47:06 UTC +00:00], ["xml", "\n Fedora 15\n desc\n \n password\n Fedora\n x86_64\n 15\n \n http://download.fedoraproject.org/pub/fedora/linux/releases/15/Fedora/x86_64/os/\n \n \n \n \n http://repos.fedorapeople.org/repos/aeolus/demo/webapp/\n false\n \n \n "]]
[1m[35mSQL (0.2ms)[0m INSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?) [["created_at", Thu, 11 Oct 2012 13:47:06 UTC +00:00], ["description", "This is my very first base image"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 4], ["updated_at", Thu, 11 Oct 2012 13:47:06 UTC +00:00], ["user_id", nil]]
[1m[36m (81.4ms)[0m [1mcommit transaction[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.4ms)
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 7
Rendered tim/base_images/_custom.xml.haml (1.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (80.9ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (89.5ms)
Completed 201 Created in 320ms (Views: 106.9ms | ActiveRecord: 0.4ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-11 10:07:05 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"This is my very first base image", "template"=>{"name"=>"Fedora 15", "description"=>"desc", "os"=>{"rootpw"=>"password", "name"=>"Fedora", "arch"=>"x86_64", "version"=>"15", "install"=>{"type"=>"url", "url"=>"http://download.fedoraproject.org/pub/fedora/linux/releases/15/Fedora/x86_64/os/"}}, "repositories"=>{"repository"=>{"name"=>"custom", "url"=>"http://repos.fedorapeople.org/repos/aeolus/demo/webapp/", "signed"=>"false"}}}}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.1ms)[0m [1mbegin transaction[0m
[1m[35mSQL (0.5ms)[0m INSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?) [["created_at", Thu, 11 Oct 2012 14:07:05 UTC +00:00], ["updated_at", Thu, 11 Oct 2012 14:07:05 UTC +00:00], ["xml", "\n Fedora 15\n desc\n \n password\n Fedora\n x86_64\n 15\n \n http://download.fedoraproject.org/pub/fedora/linux/releases/15/Fedora/x86_64/os/\n \n \n \n \n http://repos.fedorapeople.org/repos/aeolus/demo/webapp/\n false\n \n \n "]]
[1m[36mSQL (0.1ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:07:05 UTC +00:00], ["description", "This is my very first base image"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 5], ["updated_at", Thu, 11 Oct 2012 14:07:05 UTC +00:00], ["user_id", nil]]
[1m[35m (97.5ms)[0m commit transaction
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (0.3ms)
[1m[36mTim::ImageVersion Load (0.1ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 8[0m
Rendered tim/base_images/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (3.5ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (4.6ms)
Completed 201 Created in 112ms (Views: 7.2ms | ActiveRecord: 0.1ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-11 10:11:14 -0400
Connecting to database specified by database.yml
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (3.5ms)
Completed 200 OK in 38ms (Views: 37.3ms | ActiveRecord: 0.0ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-11 10:11:29 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"This is my very first base image", "template"=>{"name"=>"Fedora 15", "description"=>"desc", "os"=>{"rootpw"=>"password", "name"=>"Fedora", "arch"=>"x86_64", "version"=>"15", "install"=>{"type"=>"url", "url"=>"http://download.fedoraproject.org/pub/fedora/linux/releases/15/Fedora/x86_64/os/"}}, "repositories"=>{"repository"=>{"name"=>"custom", "url"=>"http://repos.fedorapeople.org/repos/aeolus/demo/webapp/", "signed"=>"false"}}}}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.1ms)[0m [1mbegin transaction[0m
[1m[35mSQL (4.0ms)[0m INSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?) [["created_at", Thu, 11 Oct 2012 14:11:30 UTC +00:00], ["updated_at", Thu, 11 Oct 2012 14:11:30 UTC +00:00], ["xml", "\n Fedora 15\n desc\n \n password\n Fedora\n x86_64\n 15\n \n http://download.fedoraproject.org/pub/fedora/linux/releases/15/Fedora/x86_64/os/\n \n \n \n \n http://repos.fedorapeople.org/repos/aeolus/demo/webapp/\n false\n \n \n "]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:11:30 UTC +00:00], ["description", "This is my very first base image"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 6], ["updated_at", Thu, 11 Oct 2012 14:11:30 UTC +00:00], ["user_id", nil]]
[1m[35m (123.6ms)[0m commit transaction
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.1ms)
[1m[36mTim::ImageVersion Load (0.1ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 9[0m
Rendered tim/base_images/_custom.xml.haml (0.9ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (23.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (55.3ms)
Completed 201 Created in 281ms (Views: 57.0ms | ActiveRecord: 0.4ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-11 10:28:58 -0400
Connecting to database specified by database.yml
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"ThisIsABaseImage", "template"=>{"name"=>"mock", "os"=>{"name"=>"RHELMock", "version"=>"1", "arch"=>"x86_64", "install"=>{"type"=>"iso", "iso"=>"http://mockhost/RHELMock1-x86_64-DVD.iso"}, "rootpw"=>"password"}, "description"=>"Mock Template"}, "image_versions"=>[{"target_images"=>[{"target"=>"MockSphere"}]}]}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35mSQL (4.1ms)[0m INSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?) [["created_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00], ["updated_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00], ["xml", "\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n "]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00], ["description", "ThisIsABaseImage"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 7], ["updated_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00], ["user_id", nil]]
[1m[35mSQL (0.2ms)[0m INSERT INTO "tim_image_versions" ("base_image_id", "created_at", "template_id", "updated_at") VALUES (?, ?, ?, ?) [["base_image_id", 10], ["created_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00], ["template_id", nil], ["updated_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_target_images" ("created_at", "factory_id", "image_version_id", "progress", "provider_type_id", "status", "status_detail", "target", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00], ["factory_id", nil], ["image_version_id", 4], ["progress", nil], ["provider_type_id", nil], ["status", nil], ["status_detail", nil], ["target", "MockSphere"], ["updated_at", Thu, 11 Oct 2012 14:29:00 UTC +00:00]]
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 4 LIMIT 1
[1m[36mTim::BaseImage Load (0.1ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = 10 LIMIT 1[0m
[1m[35mTim::Template Load (0.1ms)[0m SELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = 7 LIMIT 1
[1m[36m (0.5ms)[0m [1mUPDATE "tim_target_images" SET "target" = 'MockSphere', "image_version_id" = 4, "created_at" = '2012-10-11 14:29:00.442782', "updated_at" = '2012-10-11 14:29:00.442782', "status" = 'NEW', "factory_id" = '5f51cd21-4ea6-4b66-a0a2-9ddd7d7ca6d4', "status_detail" = 'Initializing image prior to Cloud/OS customization', "progress" = 0 WHERE "tim_target_images"."id" = 3[0m
[1m[35m (137.4ms)[0m commit transaction
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.1ms)
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 10[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (1.5ms)
Rendered tim/base_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (33.5ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (37.6ms)
Completed 201 Created in 10312ms (Views: 39.7ms | ActiveRecord: 0.2ms)
Started PUT "/tim/target_images//3" for 127.0.0.1 at 2012-10-11 10:29:10 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"base_image"=>{"status"=>"COMPLETE", "_type"=>"BaseImage", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//3"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"aa73ada6-6b61-476c-9286-6a563f449a7c"}, "id"=>"3", "target_image"=>{}}
WARNING: Can't verify CSRF token authenticity
[1m[35mTim::TargetImage Load (0.3ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "3"]]
[1m[36m (0.1ms)[0m [1mbegin transaction[0m
[1m[35m (0.0ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/3
Completed 302 Found in 24ms (ActiveRecord: 0.0ms)
Started PUT "/tim/target_images//3" for 127.0.0.1 at 2012-10-11 10:29:10 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"target_image"=>{"status"=>"COMPLETE", "_type"=>"TargetImage", "target"=>"MockSphere", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//3"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"5f51cd21-4ea6-4b66-a0a2-9ddd7d7ca6d4"}, "id"=>"3"}
WARNING: Can't verify CSRF token authenticity
[1m[36mTim::TargetImage Load (0.2ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1[0m [["id", "3"]]
[1m[35m (0.1ms)[0m begin transaction
[1m[36m (0.3ms)[0m [1mUPDATE "tim_target_images" SET "progress" = 0, "status" = 'COMPLETE', "updated_at" = '2012-10-11 14:29:10.661931' WHERE "tim_target_images"."id" = 3[0m
[1m[35m (80.9ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/3
Completed 302 Found in 89ms (ActiveRecord: 0.0ms)
Started GET "/tim/target_images/3" for 127.0.0.1 at 2012-10-11 10:30:37 -0400
Processing by Tim::TargetImagesController#show as XML
Parameters: {"id"=>"3"}
[1m[36mTim::TargetImage Load (0.2ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1[0m [["id", "3"]]
[1m[35mTim::ImageVersion Load (0.2ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 4 LIMIT 1
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (0.3ms)
Rendered tim/target_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image.xml.haml (14.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/show.xml.haml (26.8ms)
Completed 200 OK in 45ms (Views: 43.1ms | ActiveRecord: 0.3ms)
Started PUT "/tim/target_images" for 127.0.0.1 at 2012-10-11 10:36:21 -0400
Connecting to database specified by database.yml
ActionController::RoutingError (No route matches [PUT] "/tim/target_images"):
actionpack (3.2.8) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
railties (3.2.8) lib/rails/rack/logger.rb:26:in `call_app'
railties (3.2.8) lib/rails/rack/logger.rb:16:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/request_id.rb:22:in `call'
rack (1.4.1) lib/rack/methodoverride.rb:21:in `call'
rack (1.4.1) lib/rack/runtime.rb:17:in `call'
activesupport (3.2.8) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
rack (1.4.1) lib/rack/lock.rb:15:in `call'
actionpack (3.2.8) lib/action_dispatch/middleware/static.rb:62:in `call'
railties (3.2.8) lib/rails/engine.rb:479:in `call'
railties (3.2.8) lib/rails/application.rb:223:in `call'
rack (1.4.1) lib/rack/content_length.rb:14:in `call'
railties (3.2.8) lib/rails/rack/log_tailer.rb:17:in `call'
rack (1.4.1) lib/rack/handler/webrick.rb:59:in `service'
/home/jay/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service'
/home/jay/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run'
/home/jay/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread'
Rendered /home/jay/.rvm/gems/ruby-1.9.3-p194@tim/gems/actionpack-3.2.8/lib/action_dispatch/middleware/templates/rescues/routing_error.erb within rescues/layout (0.8ms)
Started PUT "/tim/target_images/3" for 127.0.0.1 at 2012-10-11 10:36:56 -0400
Processing by Tim::TargetImagesController#update as XML
Parameters: {"target_image"=>{"id"=>"3", "provider_images"=>[{"provider"=>"MockSphere", "credentials"=>nil}]}, "id"=>"3"}
WARNING: Can't verify CSRF token authenticity
[1m[36mTim::TargetImage Load (0.2ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1[0m [["id", "3"]]
[1m[35m (0.0ms)[0m begin transaction
[1m[36mSQL (31.4ms)[0m [1mINSERT INTO "tim_provider_images" ("created_at", "external_image_id", "factory_id", "progress", "provider", "provider_account_id", "snapshot", "status", "status_detail", "target_image_id", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:36:56 UTC +00:00], ["external_image_id", nil], ["factory_id", nil], ["progress", nil], ["provider", "MockSphere"], ["provider_account_id", nil], ["snapshot", nil], ["status", nil], ["status_detail", nil], ["target_image_id", 3], ["updated_at", Thu, 11 Oct 2012 14:36:56 UTC +00:00]]
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = 3 LIMIT 1
[1m[36m (0.4ms)[0m [1mUPDATE "tim_provider_images" SET "provider" = 'MockSphere', "target_image_id" = 3, "created_at" = '2012-10-11 14:36:56.479678', "updated_at" = '2012-10-11 14:36:56.479678', "status" = 'NEW', "factory_id" = '787125c9-e5b9-458b-90c7-d1dfec93c7fd', "status_detail" = 'Initializing image prior to Cloud/OS customization', "progress" = 0 WHERE "tim_provider_images"."id" = 3[0m
[1m[35m (131.0ms)[0m commit transaction
[1m[36mTim::ImageVersion Load (0.1ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 4 LIMIT 1[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (1.4ms)
Rendered tim/target_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image.xml.haml (21.6ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/show.xml.haml (57.4ms)
Completed 200 OK in 364ms (Views: 59.7ms | ActiveRecord: 0.4ms)
Started PUT "/tim/provider_images//3" for 127.0.0.1 at 2012-10-11 10:36:56 -0400
Processing by Tim::ProviderImagesController#update as HTML
Parameters: {"provider_image"=>{"status"=>"COMPLETE", "_type"=>"ProviderImage", "parameters"=>nil, "identifier_on_provider"=>nil, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "provider_account_identifier"=>nil, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "provider"=>"MockSphere", "percent_complete"=>0, "id"=>"787125c9-e5b9-458b-90c7-d1dfec93c7fd"}, "id"=>"3"}
WARNING: Can't verify CSRF token authenticity
[1m[35mTim::ProviderImage Load (0.3ms)[0m SELECT "tim_provider_images".* FROM "tim_provider_images" WHERE "tim_provider_images"."id" = ? LIMIT 1 [["id", "3"]]
[1m[36m (0.1ms)[0m [1mbegin transaction[0m
[1m[35m (0.3ms)[0m UPDATE "tim_provider_images" SET "progress" = 0, "status" = 'COMPLETE', "updated_at" = '2012-10-11 14:36:56.760849' WHERE "tim_provider_images"."id" = 3
[1m[36m (85.7ms)[0m [1mcommit transaction[0m
Redirected to http://localhost:3000/tim/provider_images/3
Completed 302 Found in 100ms (ActiveRecord: 0.0ms)
Started GET "/tim/target_images/3" for 127.0.0.1 at 2012-10-11 10:37:43 -0400
Processing by Tim::TargetImagesController#show as XML
Parameters: {"id"=>"3"}
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "3"]]
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 4 LIMIT 1[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (0.3ms)
Rendered tim/target_images/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image.xml.haml (3.4ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/show.xml.haml (4.2ms)
Completed 200 OK in 8ms (Views: 6.2ms | ActiveRecord: 0.3ms)
Started GET "/tim/provider_images/" for 127.0.0.1 at 2012-10-11 10:37:57 -0400
Processing by Tim::ProviderImagesController#index as XML
[1m[35mTim::ProviderImage Load (0.2ms)[0m SELECT "tim_provider_images".* FROM "tim_provider_images"
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/_provider_image_minimal.xml.haml (1.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/_provider_image_minimal.xml.haml (0.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/index.xml.haml (4.3ms)
Completed 200 OK in 31ms (Views: 29.3ms | ActiveRecord: 0.2ms)
Started GET "/tim/provider_images/3" for 127.0.0.1 at 2012-10-11 10:39:44 -0400
Processing by Tim::ProviderImagesController#show as XML
Parameters: {"id"=>"3"}
[1m[36mTim::ProviderImage Load (0.1ms)[0m [1mSELECT "tim_provider_images".* FROM "tim_provider_images" WHERE "tim_provider_images"."id" = ? LIMIT 1[0m [["id", "3"]]
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = 3 LIMIT 1
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image_minimal.xml.haml (1.1ms)
Rendered tim/provider_images/_custom.xml.haml (0.8ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/_provider_image.xml.haml (12.0ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/show.xml.haml (17.7ms)
Completed 200 OK in 27ms (Views: 25.6ms | ActiveRecord: 0.3ms)
Started GET "/tim/provider_images/2" for 127.0.0.1 at 2012-10-11 10:40:03 -0400
Processing by Tim::ProviderImagesController#show as XML
Parameters: {"id"=>"2"}
[1m[36mTim::ProviderImage Load (0.2ms)[0m [1mSELECT "tim_provider_images".* FROM "tim_provider_images" WHERE "tim_provider_images"."id" = ? LIMIT 1[0m [["id", "2"]]
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = 2 LIMIT 1
Rendered /home/jay/projects/aeolus/tim/app/views/tim/target_images/_target_image_minimal.xml.haml (0.4ms)
Rendered tim/provider_images/_custom.xml.haml (0.1ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/_provider_image.xml.haml (4.2ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/provider_images/show.xml.haml (5.3ms)
Completed 200 OK in 10ms (Views: 7.8ms | ActiveRecord: 0.4ms)
Started GET "/tim/" for 127.0.0.1 at 2012-10-11 10:56:13 -0400
Connecting to database specified by database.yml
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (3.5ms)
Completed 200 OK in 37ms (Views: 37.0ms | ActiveRecord: 0.0ms)
Started POST "/tim/base_images" for 127.0.0.1 at 2012-10-11 10:56:36 -0400
Processing by Tim::BaseImagesController#create as XML
Parameters: {"base_image"=>{"name"=>"MyFirstBaseImage", "description"=>"ThisIsABaseImage", "template"=>{"name"=>"mock", "os"=>{"name"=>"RHELMock", "version"=>"1", "arch"=>"x86_64", "install"=>{"type"=>"iso", "iso"=>"http://mockhost/RHELMock1-x86_64-DVD.iso"}, "rootpw"=>"password"}, "description"=>"Mock Template"}, "image_versions"=>[{"target_images"=>[{"target"=>"MockSphere"}]}]}}
WARNING: Can't verify CSRF token authenticity
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35mSQL (4.6ms)[0m INSERT INTO "tim_templates" ("created_at", "updated_at", "xml") VALUES (?, ?, ?) [["created_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00], ["updated_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00], ["xml", "\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n "]]
[1m[36mSQL (0.2ms)[0m [1mINSERT INTO "tim_base_images" ("created_at", "description", "name", "pool_family_id", "template_id", "updated_at", "user_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00], ["description", "ThisIsABaseImage"], ["name", "MyFirstBaseImage"], ["pool_family_id", nil], ["template_id", 8], ["updated_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00], ["user_id", nil]]
[1m[35mSQL (0.2ms)[0m INSERT INTO "tim_image_versions" ("base_image_id", "created_at", "template_id", "updated_at") VALUES (?, ?, ?, ?) [["base_image_id", 11], ["created_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00], ["template_id", nil], ["updated_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00]]
[1m[36mSQL (0.4ms)[0m [1mINSERT INTO "tim_target_images" ("created_at", "factory_id", "image_version_id", "progress", "provider_type_id", "status", "status_detail", "target", "updated_at") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)[0m [["created_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00], ["factory_id", nil], ["image_version_id", 5], ["progress", nil], ["provider_type_id", nil], ["status", nil], ["status_detail", nil], ["target", "MockSphere"], ["updated_at", Thu, 11 Oct 2012 14:56:37 UTC +00:00]]
[1m[35mTim::ImageVersion Load (0.1ms)[0m SELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."id" = 5 LIMIT 1
[1m[36mTim::BaseImage Load (0.1ms)[0m [1mSELECT "tim_base_images".* FROM "tim_base_images" WHERE "tim_base_images"."id" = 11 LIMIT 1[0m
[1m[35mTim::Template Load (0.1ms)[0m SELECT "tim_templates".* FROM "tim_templates" WHERE "tim_templates"."id" = 8 LIMIT 1
[1m[36m (0.5ms)[0m [1mUPDATE "tim_target_images" SET "target" = 'MockSphere', "image_version_id" = 5, "created_at" = '2012-10-11 14:56:37.578961', "updated_at" = '2012-10-11 14:56:37.578961', "status" = 'NEW', "factory_id" = '3cb88dc1-a14e-4ba0-911a-e3d2e471e3ee', "status_detail" = 'Initializing image prior to Cloud/OS customization', "progress" = 0 WHERE "tim_target_images"."id" = 4[0m
[1m[35m (106.8ms)[0m commit transaction
Rendered /home/jay/projects/aeolus/tim/app/views/tim/templates/_template_minimal.xml.haml (1.1ms)
[1m[36mTim::ImageVersion Load (0.2ms)[0m [1mSELECT "tim_image_versions".* FROM "tim_image_versions" WHERE "tim_image_versions"."base_image_id" = 11[0m
Rendered /home/jay/projects/aeolus/tim/app/views/tim/image_versions/_image_version_minimal.xml.haml (1.1ms)
Rendered tim/base_images/_custom.xml.haml (0.7ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/_base_image.xml.haml (10.3ms)
Rendered /home/jay/projects/aeolus/tim/app/views/tim/base_images/show.xml.haml (15.4ms)
Completed 201 Created in 361ms (Views: 18.0ms | ActiveRecord: 0.2ms)
Started PUT "/tim/target_images//4" for 127.0.0.1 at 2012-10-11 10:56:37 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"base_image"=>{"status"=>"COMPLETE", "_type"=>"BaseImage", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//4"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"aa6cd135-7d51-4a73-8ff9-28c313be5f84"}, "id"=>"4", "target_image"=>{}}
WARNING: Can't verify CSRF token authenticity
[1m[35mTim::TargetImage Load (0.2ms)[0m SELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1 [["id", "4"]]
[1m[36m (0.0ms)[0m [1mbegin transaction[0m
[1m[35m (0.0ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/4
Completed 302 Found in 42ms (ActiveRecord: 0.0ms)
Started PUT "/tim/target_images//4" for 127.0.0.1 at 2012-10-11 10:56:47 -0400
Processing by Tim::TargetImagesController#update as HTML
Parameters: {"target_image"=>{"status"=>"COMPLETE", "_type"=>"TargetImage", "target"=>"MockSphere", "parameters"=>{"callbacks"=>["http://localhost:3000/tim/target_images//4"]}, "icicle"=>nil, "status_detail"=>{"error"=>nil, "activity"=>"Initializing image prior to Cloud/OS customization"}, "template"=>"\n mock\n \n RHELMock\n 1\n x86_64\n \n http://mockhost/RHELMock1-x86_64-DVD.iso\n \n password\n \n Mock Template\n ", "percent_complete"=>0, "id"=>"3cb88dc1-a14e-4ba0-911a-e3d2e471e3ee"}, "id"=>"4"}
WARNING: Can't verify CSRF token authenticity
[1m[36mTim::TargetImage Load (0.2ms)[0m [1mSELECT "tim_target_images".* FROM "tim_target_images" WHERE "tim_target_images"."id" = ? LIMIT 1[0m [["id", "4"]]
[1m[35m (0.1ms)[0m begin transaction
[1m[36m (0.4ms)[0m [1mUPDATE "tim_target_images" SET "progress" = 0, "status" = 'COMPLETE', "updated_at" = '2012-10-11 14:56:47.374117' WHERE "tim_target_images"."id" = 4[0m
[1m[35m (72.8ms)[0m commit transaction
Redirected to http://localhost:3000/tim/target_images/4
Completed 302 Found in 80ms (ActiveRecord: 0.0ms)
Connecting to database specified by database.yml
[1m[36m (1.7ms)[0m [1mselect sqlite_version(*)[0m
[1m[35m (106.1ms)[0m CREATE TABLE "tim_base_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "description" varchar(255), "template_id" integer, "user_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "pool_family_id" integer)
[1m[36m (91.8ms)[0m [1mCREATE TABLE "tim_image_versions" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "base_image_id" integer, "template_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (106.1ms)[0m CREATE TABLE "tim_provider_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "target_image_id" integer, "provider" varchar(255), "external_image_id" varchar(255), "provider_account_id" varchar(255), "snapshot" boolean, "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (90.4ms)[0m [1mCREATE TABLE "tim_target_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "image_version_id" integer, "target" varchar(255), "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "provider_type_id" integer) [0m
[1m[35m (108.0ms)[0m CREATE TABLE "tim_templates" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "xml" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (82.5ms)[0m [1mCREATE TABLE "pool_families" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (73.7ms)[0m CREATE TABLE "provider_accounts" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (100.3ms)[0m [1mCREATE TABLE "provider_types" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (97.2ms)[0m CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (74.1ms)[0m [1mCREATE TABLE "schema_migrations" ("version" varchar(255) NOT NULL) [0m
[1m[35m (0.1ms)[0m PRAGMA index_list("schema_migrations")
[1m[36m (102.9ms)[0m [1mCREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")[0m
[1m[35m (0.1ms)[0m SELECT version FROM "schema_migrations"
[1m[36m (77.4ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120423123114264114')[0m
[1m[35m (66.4ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120326103723532622')
[1m[36m (91.3ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911203222')[0m
[1m[35m (58.1ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911182850')
[1m[36m (49.9ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911205431')[0m
[1m[35m (58.2ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911202845')
[1m[36m (58.3ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120906180351')[0m
[1m[35m (58.1ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120906210106')
[1m[36m (66.6ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911202321')[0m
[1m[35m (66.5ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911204329')
[1m[36m (49.8ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120910175233')[0m
[1m[35m (0.1ms)[0m SELECT "schema_migrations"."version" FROM "schema_migrations"
Started GET "/tim/" for 127.0.0.1 at 2012-10-11 11:15:08 -0400
Connecting to database specified by database.yml
Processing by Tim::EntrypointController#index as XML
Rendered /home/jay/projects/aeolus/tim/app/views/tim/entrypoint/index.xml.haml (3.5ms)
Completed 200 OK in 37ms (Views: 36.4ms | ActiveRecord: 0.0ms)
Connecting to database specified by database.yml
[1m[36m (1.9ms)[0m [1mselect sqlite_version(*)[0m
[1m[35m (94.8ms)[0m DROP TABLE "tim_base_images"
[1m[36m (124.7ms)[0m [1mCREATE TABLE "tim_base_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "description" varchar(255), "template_id" integer, "user_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "pool_family_id" integer) [0m
[1m[35m (90.1ms)[0m DROP TABLE "tim_image_versions"
[1m[36m (91.1ms)[0m [1mCREATE TABLE "tim_image_versions" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "base_image_id" integer, "template_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (90.5ms)[0m DROP TABLE "tim_provider_images"
[1m[36m (82.5ms)[0m [1mCREATE TABLE "tim_provider_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "target_image_id" integer, "provider" varchar(255), "external_image_id" varchar(255), "provider_account_id" varchar(255), "snapshot" boolean, "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (82.2ms)[0m DROP TABLE "tim_target_images"
[1m[36m (91.0ms)[0m [1mCREATE TABLE "tim_target_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "image_version_id" integer, "target" varchar(255), "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "provider_type_id" integer) [0m
[1m[35m (82.4ms)[0m DROP TABLE "tim_templates"
[1m[36m (82.8ms)[0m [1mCREATE TABLE "tim_templates" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "xml" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (90.8ms)[0m DROP TABLE "pool_families"
[1m[36m (99.6ms)[0m [1mCREATE TABLE "pool_families" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (90.8ms)[0m DROP TABLE "provider_accounts"
[1m[36m (99.6ms)[0m [1mCREATE TABLE "provider_accounts" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (90.8ms)[0m DROP TABLE "provider_types"
[1m[36m (89.9ms)[0m [1mCREATE TABLE "provider_types" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (74.2ms)[0m DROP TABLE "users"
[1m[36m (74.6ms)[0m [1mCREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (0.1ms)[0m SELECT version FROM "schema_migrations"
[1m[36m (0.1ms)[0m [1mSELECT "schema_migrations"."version" FROM "schema_migrations" [0m
Connecting to database specified by database.yml
[1m[36m (0.1ms)[0m [1mSELECT "schema_migrations"."version" FROM "schema_migrations" [0m
[1m[35m (0.3ms)[0m select sqlite_version(*)
[1m[36m (100.3ms)[0m [1mCREATE TABLE "tim_base_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "description" varchar(255), "template_id" integer, "user_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "pool_family_id" integer) [0m
[1m[35m (80.3ms)[0m CREATE TABLE "tim_image_versions" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "base_image_id" integer, "template_id" integer, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (101.9ms)[0m [1mCREATE TABLE "tim_provider_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "target_image_id" integer, "provider" varchar(255), "external_image_id" varchar(255), "provider_account_id" varchar(255), "snapshot" boolean, "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (85.5ms)[0m CREATE TABLE "tim_target_images" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "factory_id" varchar(255), "image_version_id" integer, "target" varchar(255), "status" varchar(255), "status_detail" varchar(255), "progress" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL, "provider_type_id" integer)
[1m[36m (105.5ms)[0m [1mCREATE TABLE "tim_templates" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "xml" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (78.3ms)[0m CREATE TABLE "pool_families" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (56.9ms)[0m [1mCREATE TABLE "provider_accounts" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (89.0ms)[0m CREATE TABLE "provider_types" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
[1m[36m (74.5ms)[0m [1mCREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) [0m
[1m[35m (66.3ms)[0m CREATE TABLE "schema_migrations" ("version" varchar(255) NOT NULL)
[1m[36m (0.0ms)[0m [1mPRAGMA index_list("schema_migrations")[0m
[1m[35m (101.3ms)[0m CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")
[1m[36m (0.1ms)[0m [1mSELECT version FROM "schema_migrations"[0m
[1m[35m (89.4ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120423123114264114')
[1m[36m (74.9ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120326103723532622')[0m
[1m[35m (74.9ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911203222')
[1m[36m (74.9ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911182850')[0m
[1m[35m (74.9ms)[0m INSERT INTO "schema_migrations" (version) VALUES ('20120911205431')
[1m[36m (74.9ms)[0m [1mINSERT INTO "schema_migrations" (version) VALUES ('20120911202845')[0m