Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Started GET "/" for 127.0.0.1 at 2013-09-26 16:49:23 -0600 Connecting to database specified by database.yml Processing by WelcomeController#index as HTML Rendered text template (0.0ms) Filter chain halted as :require_lti_launch rendered or redirected Completed 200 OK in 11ms (Views: 10.7ms | ActiveRecord: 0.0ms) Started GET "/favicon.ico" for 127.0.0.1 at 2013-09-26 16:49:24 -0600 ActionController::RoutingError (No route matches [GET] "/favicon.ico"): actionpack (3.2.14) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' railties (3.2.14) lib/rails/rack/logger.rb:32:in `call_app' railties (3.2.14) lib/rails/rack/logger.rb:16:in `block in call' activesupport (3.2.14) lib/active_support/tagged_logging.rb:22:in `tagged' railties (3.2.14) lib/rails/rack/logger.rb:16:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/request_id.rb:22:in `call' rack (1.4.5) lib/rack/methodoverride.rb:21:in `call' rack (1.4.5) lib/rack/runtime.rb:17:in `call' activesupport (3.2.14) lib/active_support/cache/strategy/local_cache.rb:72:in `call' rack (1.4.5) lib/rack/lock.rb:15:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/static.rb:63:in `call' railties (3.2.14) lib/rails/engine.rb:484:in `call' railties (3.2.14) lib/rails/application.rb:231:in `call' rack (1.4.5) lib/rack/content_length.rb:14:in `call' railties (3.2.14) lib/rails/rack/log_tailer.rb:17:in `call' rack (1.4.5) lib/rack/handler/webrick.rb:59:in `service' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread' Rendered /Users/simonista/Instructure/lti_provider_engine/.bundle/gems/ruby/1.9.1/gems/actionpack-3.2.14/lib/action_dispatch/middleware/templates/rescues/routing_error.erb within rescues/layout (7.6ms) Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Started GET "/" for 127.0.0.1 at 2013-09-26 16:51:37 -0600 Connecting to database specified by database.yml Processing by WelcomeController#index as HTML Rendered text template (0.0ms) Filter chain halted as :require_lti_launch rendered or redirected Completed 200 OK in 8ms (Views: 7.6ms | ActiveRecord: 0.0ms) Started GET "/configure.xml" for 127.0.0.1 at 2013-09-26 16:52:19 -0600 ActionController::RoutingError (No route matches [GET] "/configure.xml"): actionpack (3.2.14) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' railties (3.2.14) lib/rails/rack/logger.rb:32:in `call_app' railties (3.2.14) lib/rails/rack/logger.rb:16:in `block in call' activesupport (3.2.14) lib/active_support/tagged_logging.rb:22:in `tagged' railties (3.2.14) lib/rails/rack/logger.rb:16:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/request_id.rb:22:in `call' rack (1.4.5) lib/rack/methodoverride.rb:21:in `call' rack (1.4.5) lib/rack/runtime.rb:17:in `call' activesupport (3.2.14) lib/active_support/cache/strategy/local_cache.rb:72:in `call' rack (1.4.5) lib/rack/lock.rb:15:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/static.rb:63:in `call' railties (3.2.14) lib/rails/engine.rb:484:in `call' railties (3.2.14) lib/rails/application.rb:231:in `call' rack (1.4.5) lib/rack/content_length.rb:14:in `call' railties (3.2.14) lib/rails/rack/log_tailer.rb:17:in `call' rack (1.4.5) lib/rack/handler/webrick.rb:59:in `service' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread' Rendered /Users/simonista/Instructure/lti_provider_engine/.bundle/gems/ruby/1.9.1/gems/actionpack-3.2.14/lib/action_dispatch/middleware/templates/rescues/routing_error.erb within rescues/layout (2.2ms) Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Started GET "/configure.xml" for 127.0.0.1 at 2013-09-26 16:54:03 -0600 Connecting to database specified by database.yml Processing by LtiProvider::LtiController#configure as XML Completed 200 OK in 6ms (Views: 0.1ms | ActiveRecord: 0.0ms) Started GET "/" for 127.0.0.1 at 2013-09-26 16:54:06 -0600 Processing by WelcomeController#index as HTML Rendered text template (0.0ms) Filter chain halted as :require_lti_launch rendered or redirected Completed 200 OK in 8ms (Views: 7.7ms | ActiveRecord: 0.0ms) Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Started GET "/configure.xml" for 127.0.0.1 at 2013-09-26 16:58:05 -0600 Connecting to database specified by database.yml Processing by LtiProvider::LtiController#configure as XML Completed 200 OK in 6ms (Views: 0.1ms | ActiveRecord: 0.0ms) Started GET "/configure.xml" for 127.0.0.1 at 2013-09-26 16:58:05 -0600 Processing by LtiProvider::LtiController#configure as XML Completed 200 OK in 1ms (Views: 0.1ms | ActiveRecord: 0.0ms) Started GET "/configure.xml" for 127.0.0.1 at 2013-09-26 16:58:06 -0600 Processing by LtiProvider::LtiController#configure as XML Completed 200 OK in 1ms (Views: 0.1ms | ActiveRecord: 0.0ms) Started GET "/configure.xml" for 127.0.0.1 at 2013-09-26 16:58:06 -0600 Processing by LtiProvider::LtiController#configure as XML Completed 200 OK in 2ms (Views: 0.1ms | ActiveRecord: 0.0ms) Started POST "/launch" for 127.0.0.1 at 2013-09-26 16:58:21 -0600 Processing by LtiProvider::LtiController#launch as HTML Parameters: {"oauth_consumer_key"=>"12345", "oauth_signature_method"=>"HMAC-SHA1", "oauth_timestamp"=>"1380236301", "oauth_nonce"=>"qlwqKi8SUQPVsmCT2JajtxlnbRqo5RZKIQxB10QOKjc", "oauth_version"=>"1.0", "context_id"=>"4029f7e861f63ccd8b8b604cccf5acc4fde74d8a", "context_label"=>"Testing", "context_title"=>"Testing Course", "custom_canvas_api_domain"=>"localhost", "custom_canvas_course_id"=>"2", "custom_canvas_enrollment_state"=>"active", "custom_canvas_user_id"=>"1", "custom_canvas_user_login_id"=>"simon@instructure.com", "launch_presentation_document_target"=>"iframe", "launch_presentation_height"=>"400", "launch_presentation_locale"=>"en", "launch_presentation_return_url"=>"http://localhost:3000/courses/2", "launch_presentation_width"=>"800", "lis_person_contact_email_primary"=>"simon@instructure.com", "lis_person_name_family"=>"", "lis_person_name_full"=>"simon@instructure.com", "lis_person_name_given"=>"simon@instructure.com", "lti_message_type"=>"basic-lti-launch-request", "lti_version"=>"LTI-1p0", "oauth_callback"=>"about:blank", "resource_link_id"=>"4029f7e861f63ccd8b8b604cccf5acc4fde74d8a", "resource_link_title"=>"LTI Provider", "roles"=>"Instructor,urn:lti:instrole:ims/lis/Administrator", "tool_consumer_info_product_family_code"=>"canvas", "tool_consumer_info_version"=>"cloud", "tool_consumer_instance_contact_email"=>"notifications@unknowndomain.example.com", "tool_consumer_instance_guid"=>"82ef4c4479c3a07a02d4396f95097507af448ed6.localhost:3000", "tool_consumer_instance_name"=>"Simon Development", "user_id"=>"5a6e3f44886dc7294b61ae391c216f9d16b7cda8", "user_image"=>"https://secure.gravatar.com/avatar/2284bced4cd86cf65cec3876a9021b5c?s=50&d=http%3A%2F%2Fcanvas.instructure.com%3A3000%2Fimages%2Fmessages%2Favatar-50.png", "oauth_signature"=>"YacWb4/XrJwobCLgz2w5e8koj0Y="} Completed 500 Internal Server Error in 35ms ActiveRecord::StatementInvalid (Could not find table 'lti_provider_launches'): activerecord (3.2.14) lib/active_record/connection_adapters/sqlite_adapter.rb:472:in `table_structure' activerecord (3.2.14) lib/active_record/connection_adapters/sqlite_adapter.rb:346:in `columns' activerecord (3.2.14) lib/active_record/connection_adapters/schema_cache.rb:12:in `block in initialize' activerecord (3.2.14) lib/active_record/model_schema.rb:229:in `yield' activerecord (3.2.14) lib/active_record/model_schema.rb:229:in `default' activerecord (3.2.14) lib/active_record/model_schema.rb:229:in `columns' activerecord (3.2.14) lib/active_record/model_schema.rb:244:in `column_defaults' activerecord (3.2.14) lib/active_record/base.rb:482:in `initialize' /Users/simonista/Instructure/lti_provider_engine/app/models/lti_provider/launch.rb:12:in `new' /Users/simonista/Instructure/lti_provider_engine/app/models/lti_provider/launch.rb:12:in `initialize_from_request' /Users/simonista/Instructure/lti_provider_engine/app/controllers/lti_provider/lti_controller.rb:9:in `launch' actionpack (3.2.14) lib/action_controller/metal/implicit_render.rb:4:in `send_action' actionpack (3.2.14) lib/abstract_controller/base.rb:167:in `process_action' actionpack (3.2.14) lib/action_controller/metal/rendering.rb:10:in `process_action' actionpack (3.2.14) lib/abstract_controller/callbacks.rb:18:in `block in process_action' activesupport (3.2.14) lib/active_support/callbacks.rb:403:in `_run__2020360029404163652__process_action__1422311094428903085__callbacks' activesupport (3.2.14) lib/active_support/callbacks.rb:405:in `__run_callback' activesupport (3.2.14) lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks' activesupport (3.2.14) lib/active_support/callbacks.rb:81:in `run_callbacks' actionpack (3.2.14) lib/abstract_controller/callbacks.rb:17:in `process_action' actionpack (3.2.14) lib/action_controller/metal/rescue.rb:29:in `process_action' actionpack (3.2.14) lib/action_controller/metal/instrumentation.rb:30:in `block in process_action' activesupport (3.2.14) lib/active_support/notifications.rb:123:in `block in instrument' activesupport (3.2.14) lib/active_support/notifications/instrumenter.rb:20:in `instrument' activesupport (3.2.14) lib/active_support/notifications.rb:123:in `instrument' actionpack (3.2.14) lib/action_controller/metal/instrumentation.rb:29:in `process_action' actionpack (3.2.14) lib/action_controller/metal/params_wrapper.rb:207:in `process_action' activerecord (3.2.14) lib/active_record/railties/controller_runtime.rb:18:in `process_action' actionpack (3.2.14) lib/abstract_controller/base.rb:121:in `process' actionpack (3.2.14) lib/abstract_controller/rendering.rb:45:in `process' actionpack (3.2.14) lib/action_controller/metal.rb:203:in `dispatch' actionpack (3.2.14) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch' actionpack (3.2.14) lib/action_controller/metal.rb:246:in `block in action' actionpack (3.2.14) lib/action_dispatch/routing/route_set.rb:73:in `call' actionpack (3.2.14) lib/action_dispatch/routing/route_set.rb:73:in `dispatch' actionpack (3.2.14) 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.14) lib/action_dispatch/routing/route_set.rb:608:in `call' railties (3.2.14) lib/rails/engine.rb:484:in `call' railties (3.2.14) 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.14) lib/action_dispatch/routing/route_set.rb:608:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/best_standards_support.rb:17:in `call' rack (1.4.5) lib/rack/etag.rb:23:in `call' rack (1.4.5) lib/rack/conditionalget.rb:35:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/head.rb:14:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/params_parser.rb:21:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/flash.rb:242:in `call' rack (1.4.5) lib/rack/session/abstract/id.rb:210:in `context' rack (1.4.5) lib/rack/session/abstract/id.rb:205:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/cookies.rb:341:in `call' activerecord (3.2.14) lib/active_record/query_cache.rb:64:in `call' activerecord (3.2.14) lib/active_record/connection_adapters/abstract/connection_pool.rb:479:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call' activesupport (3.2.14) lib/active_support/callbacks.rb:405:in `_run__2358984166821573666__call__534996777588375431__callbacks' activesupport (3.2.14) lib/active_support/callbacks.rb:405:in `__run_callback' activesupport (3.2.14) lib/active_support/callbacks.rb:385:in `_run_call_callbacks' activesupport (3.2.14) lib/active_support/callbacks.rb:81:in `run_callbacks' actionpack (3.2.14) lib/action_dispatch/middleware/callbacks.rb:27:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/reloader.rb:65:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/remote_ip.rb:31:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' railties (3.2.14) lib/rails/rack/logger.rb:32:in `call_app' railties (3.2.14) lib/rails/rack/logger.rb:16:in `block in call' activesupport (3.2.14) lib/active_support/tagged_logging.rb:22:in `tagged' railties (3.2.14) lib/rails/rack/logger.rb:16:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/request_id.rb:22:in `call' rack (1.4.5) lib/rack/methodoverride.rb:21:in `call' rack (1.4.5) lib/rack/runtime.rb:17:in `call' activesupport (3.2.14) lib/active_support/cache/strategy/local_cache.rb:72:in `call' rack (1.4.5) lib/rack/lock.rb:15:in `call' actionpack (3.2.14) lib/action_dispatch/middleware/static.rb:63:in `call' railties (3.2.14) lib/rails/engine.rb:484:in `call' railties (3.2.14) lib/rails/application.rb:231:in `call' rack (1.4.5) lib/rack/content_length.rb:14:in `call' railties (3.2.14) lib/rails/rack/log_tailer.rb:17:in `call' rack (1.4.5) lib/rack/handler/webrick.rb:59:in `service' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /Users/simonista/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread' Rendered /Users/simonista/Instructure/lti_provider_engine/.bundle/gems/ruby/1.9.1/gems/actionpack-3.2.14/lib/action_dispatch/middleware/templates/rescues/_trace.erb (2.1ms) Rendered /Users/simonista/Instructure/lti_provider_engine/.bundle/gems/ruby/1.9.1/gems/actionpack-3.2.14/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb (2.0ms) Rendered /Users/simonista/Instructure/lti_provider_engine/.bundle/gems/ruby/1.9.1/gems/actionpack-3.2.14/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (92.9ms) Connecting to database specified by database.yml Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml  (0.1ms) select sqlite_version(*)  (3.0ms) CREATE TABLE "schema_migrations" ("version" varchar(255) NOT NULL)  (1.6ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT "schema_migrations"."version" FROM "schema_migrations" Migrating to CreateLtiProviderLaunches (20130319050206)  (0.0ms) begin transaction  (0.3ms) CREATE TABLE "lti_provider_launches" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "canvas_url" varchar(255), "nonce" varchar(255), "provider_params" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)  (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES ('20130319050206')  (1.4ms) commit transaction  (0.1ms) SELECT "schema_migrations"."version" FROM "schema_migrations"  Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Started POST "/launch" for 127.0.0.1 at 2013-09-26 16:59:53 -0600 Connecting to database specified by database.yml Processing by LtiProvider::LtiController#launch as HTML Parameters: {"oauth_consumer_key"=>"12345", "oauth_signature_method"=>"HMAC-SHA1", "oauth_timestamp"=>"1380236392", "oauth_nonce"=>"9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A", "oauth_version"=>"1.0", "context_id"=>"4029f7e861f63ccd8b8b604cccf5acc4fde74d8a", "context_label"=>"Testing", "context_title"=>"Testing Course", "custom_canvas_api_domain"=>"localhost", "custom_canvas_course_id"=>"2", "custom_canvas_enrollment_state"=>"active", "custom_canvas_user_id"=>"1", "custom_canvas_user_login_id"=>"simon@instructure.com", "launch_presentation_document_target"=>"iframe", "launch_presentation_height"=>"400", "launch_presentation_locale"=>"en", "launch_presentation_return_url"=>"http://localhost:3000/courses/2", "launch_presentation_width"=>"800", "lis_person_contact_email_primary"=>"simon@instructure.com", "lis_person_name_family"=>"", "lis_person_name_full"=>"simon@instructure.com", "lis_person_name_given"=>"simon@instructure.com", "lti_message_type"=>"basic-lti-launch-request", "lti_version"=>"LTI-1p0", "oauth_callback"=>"about:blank", "resource_link_id"=>"4029f7e861f63ccd8b8b604cccf5acc4fde74d8a", "resource_link_title"=>"LTI Provider", "roles"=>"Instructor,urn:lti:instrole:ims/lis/Administrator", "tool_consumer_info_product_family_code"=>"canvas", "tool_consumer_info_version"=>"cloud", "tool_consumer_instance_contact_email"=>"notifications@unknowndomain.example.com", "tool_consumer_instance_guid"=>"82ef4c4479c3a07a02d4396f95097507af448ed6.localhost:3000", "tool_consumer_instance_name"=>"Simon Development", "user_id"=>"5a6e3f44886dc7294b61ae391c216f9d16b7cda8", "user_image"=>"https://secure.gravatar.com/avatar/2284bced4cd86cf65cec3876a9021b5c?s=50&d=http%3A%2F%2Fcanvas.instructure.com%3A3000%2Fimages%2Fmessages%2Favatar-50.png", "oauth_signature"=>"WRLybxwKbHD7N9nxnIxQrDGJ1pI="}  (0.0ms) begin transaction SQL (3.8ms) INSERT INTO "lti_provider_launches" ("canvas_url", "created_at", "nonce", "provider_params", "updated_at") VALUES (?, ?, ?, ?, ?) [["canvas_url", "http://localhost:3000"], ["created_at", Thu, 26 Sep 2013 22:59:53 UTC +00:00], ["nonce", "9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A"], ["provider_params", "---\ncontext_id: 4029f7e861f63ccd8b8b604cccf5acc4fde74d8a\ncontext_label: Testing\ncontext_title: Testing Course\nlaunch_presentation_document_target: iframe\nlaunch_presentation_height: '400'\nlaunch_presentation_locale: en\nlaunch_presentation_return_url: http://localhost:3000/courses/2\nlaunch_presentation_width: '800'\nlis_person_contact_email_primary: simon@instructure.com\nlis_person_name_family: ''\nlis_person_name_full: simon@instructure.com\nlis_person_name_given: simon@instructure.com\nlti_message_type: basic-lti-launch-request\nlti_version: LTI-1p0\noauth_callback: about:blank\noauth_consumer_key: '12345'\noauth_nonce: 9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A\noauth_signature: WRLybxwKbHD7N9nxnIxQrDGJ1pI=\noauth_signature_method: HMAC-SHA1\noauth_timestamp: '1380236392'\noauth_version: '1.0'\nresource_link_id: 4029f7e861f63ccd8b8b604cccf5acc4fde74d8a\nresource_link_title: LTI Provider\nroles: Instructor,Urn:lti:instrole:ims/lis/administrator\ntool_consumer_info_product_family_code: canvas\ntool_consumer_info_version: cloud\ntool_consumer_instance_contact_email: notifications@unknowndomain.example.com\ntool_consumer_instance_guid: 82ef4c4479c3a07a02d4396f95097507af448ed6.localhost:3000\ntool_consumer_instance_name: Simon Development\nuser_id: 5a6e3f44886dc7294b61ae391c216f9d16b7cda8\nuser_image: https://secure.gravatar.com/avatar/2284bced4cd86cf65cec3876a9021b5c?s=50&d=http%3A%2F%2Fcanvas.instructure.com%3A3000%2Fimages%2Fmessages%2Favatar-50.png\ncustom_canvas_api_domain: localhost\ncustom_canvas_course_id: '2'\ncustom_canvas_enrollment_state: active\ncustom_canvas_user_id: '1'\ncustom_canvas_user_login_id: simon@instructure.com\n"], ["updated_at", Thu, 26 Sep 2013 22:59:53 UTC +00:00]]  (2.1ms) commit transaction Redirected to http://localhost:3003/cookie_test?nonce=9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A Completed 302 Found in 56ms (ActiveRecord: 7.5ms) Started GET "/cookie_test?nonce=9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A" for 127.0.0.1 at 2013-09-26 16:59:53 -0600 Processing by LtiProvider::LtiController#cookie_test as HTML Parameters: {"nonce"=>"9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A"} LtiProvider::Launch Load (0.2ms) SELECT "lti_provider_launches".* FROM "lti_provider_launches" WHERE "lti_provider_launches"."nonce" = '9PriqXcKKPOP7cFUbjNkewYKlxAZLZ8rr6xrIE0i3A' AND (created_at > '2013-09-26 22:54:53.934606') LIMIT 1  (0.0ms) begin transaction SQL (0.3ms) DELETE FROM "lti_provider_launches" WHERE "lti_provider_launches"."id" = ? [["id", 1]]  (1.6ms) commit transaction Redirected to http://localhost:3003/ Completed 302 Found in 16ms (ActiveRecord: 2.1ms) Started GET "/" for 127.0.0.1 at 2013-09-26 16:59:53 -0600 Processing by WelcomeController#index as HTML Rendered text template (0.0ms) Completed 200 OK in 8ms (Views: 7.8ms | ActiveRecord: 0.0ms) Connecting to database specified by database.yml Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml  (0.1ms) select sqlite_version(*)  (1.4ms) CREATE TABLE "schema_migrations" ("version" varchar(255) NOT NULL)  (1.3ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT "schema_migrations"."version" FROM "schema_migrations" Migrating to CreateLtiProviderLaunches (20130319050206)  (0.0ms) begin transaction  (0.3ms) CREATE TABLE "lti_provider_launches" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "canvas_url" varchar(255), "nonce" varchar(255), "provider_params" text, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)  (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES ('20130319050206')  (1.4ms) commit transaction  (0.1ms) SELECT "schema_migrations"."version" FROM "schema_migrations"  Initializing LTI key and secret using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti.yml Initializing LTI XML config using configuration in /Users/simonista/Instructure/lti_provider_engine/spec/dummy/config/lti_xml.yml Connecting to database specified by database.yml