Show me SQL generated by rake tasks

screenshot◎ Colorful verbose output of the 'rails db:migrate'

I was explaining what the rails db:migrate command does under the hood and I wanted to demonstrate what SQL queries the Rails generates.

And it would be nice for them to be colorful of course 😃

The “colorful” part can be done by adding the gem pry-rails

@@ -38,6 +38,7 @@ gem 'bootsnap', '>= 1.1.0', require: false
 group :development, :test do
   # Call 'byebug' anywhere in the code to stop execution and get a debugger console
   gem 'byebug', platforms: [:mri, :mingw, :x64_mingw]
+  gem 'pry-rails'
 end

Do not forget about the running of the bundle install command to actually get it installed.

And the “under the hood” part can be done in a common way by adding the log rake task.

Create the log.rake file in the lib/tasks folder and add the following to it

task :log => :environment do
  ActiveRecord::Base.logger = Logger.new(STDOUT)
end

That’s it. Now you can see what happens under the hood for any of the rake tasks 🎉

Just prefix any of your rake tasks with the log like this

rails log db:migrate
D, [2020-05-26T17:21:01.768098 #34442] DEBUG -- :    (0.2ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
I, [2020-05-26T17:21:01.768242 #34442]  INFO -- : Migrating to CreateUser (20200526154925)
D, [2020-05-26T17:21:01.769307 #34442] DEBUG -- :    (0.0ms)  begin transaction
== 20200526154925 CreateUser: migrating =======================================
-- create_table(:users)
D, [2020-05-26T17:21:01.770206 #34442] DEBUG -- :    (0.5ms)  SELECT sqlite_version(*)
D, [2020-05-26T17:21:01.770964 #34442] DEBUG -- :    (0.6ms)  CREATE TABLE "users" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)
   -> 0.0016s
== 20200526154925 CreateUser: migrated (0.0017s) ==============================

D, [2020-05-26T17:21:01.773149 #34442] DEBUG -- :   ActiveRecord::SchemaMigration Create (0.6ms)  INSERT INTO "schema_migrations" ("version") VALUES (?)  [["version", "20200526154925"]]
D, [2020-05-26T17:21:01.773894 #34442] DEBUG -- :    (0.6ms)  commit transaction
D, [2020-05-26T17:21:01.775636 #34442] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.4ms)  SELECT  "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", "environment"], ["LIMIT", 1]]
D, [2020-05-26T17:21:01.778797 #34442] DEBUG -- :    (0.0ms)  begin transaction
D, [2020-05-26T17:21:01.779282 #34442] DEBUG -- :    (0.0ms)  commit transaction
D, [2020-05-26T17:21:01.780075 #34442] DEBUG -- :    (0.1ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC

And here is the “bonus” part 😃

rails log db:rollback
D, [2020-05-26T17:23:08.987414 #34600] DEBUG -- :    (0.1ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
D, [2020-05-26T17:23:08.987785 #34600] DEBUG -- :    (0.0ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
D, [2020-05-26T17:23:08.988073 #34600] DEBUG -- :    (0.0ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
D, [2020-05-26T17:23:08.988628 #34600] DEBUG -- :    (0.0ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
I, [2020-05-26T17:23:08.988677 #34600]  INFO -- : Migrating to CreateUser (20200526154925)
D, [2020-05-26T17:23:08.991078 #34600] DEBUG -- :    (0.0ms)  begin transaction
== 20200526154925 CreateUser: reverting =======================================
-- drop_table(:users)
D, [2020-05-26T17:23:08.994696 #34600] DEBUG -- :    (1.3ms)  DROP TABLE "users"
   -> 0.0015s
== 20200526154925 CreateUser: reverted (0.0035s) ==============================

D, [2020-05-26T17:23:08.995986 #34600] DEBUG -- :   ActiveRecord::SchemaMigration Destroy (0.4ms)  DELETE FROM "schema_migrations" WHERE "schema_migrations"."version" = ?  [["version", "20200526154925"]]
D, [2020-05-26T17:23:08.996694 #34600] DEBUG -- :    (0.6ms)  commit transaction
D, [2020-05-26T17:23:08.997293 #34600] DEBUG -- :    (0.1ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC

All kudos go to Josh https://stackoverflow.com/a/8335695/3874570 👍