Puts Debuggerer finally goes version 1.0.0, and it now has a very helpful new feature: printing the class name and method name as part of `pd` printouts. For those unfamiliar with Puts Debuggerer, the project was inspired by a blog post by Aaron Patterson titled "I am a puts debuggerer", which jokingly borrows from the wording of the comedy movie Dumb and Dumberer, turning debugger to "debuggerer". The Puts Debuggerer Ruby gem aimed at automating most of the suggestions in that blog post. The project README intro is included below for your information. Happy Puts Debuggerering (make sure to ⭐️ the project on GitHub)!!!
Puts Debuggerer 1.0.0
(credit to Aaron Patterson for partial inspiration: https://tenderlovemaking.com/2016/02/05/i-am-a-puts-debuggerer.html)
If you like Awesome_Print (or Amazing_Print), you will love Puts Debuggerer (which builds upon them)!
Debuggers are great! They help us troubleshoot complicated programming problems by inspecting values produced by code, line by line. They are invaluable when trying to understand what is going on in a large application composed of thousands or millions of lines of code.
In day-to-day test-driven development and simple app debugging though, a puts statement can be a lot quicker in revealing what is going on than halting execution completely just to inspect a single value or a few. This is certainly true when writing the simplest possible code that could possibly work, and running a test every few seconds or minutes. Still, there are a number of problems with puts debugging, like difficulty in locating puts statements in a large output log, knowing which files, line numbers, and methods the puts statements were invoked from, identifying which variables were printed, and seeing the content of structured hashes and arrays in an understandable format.
Enter puts_debuggerer! A guilt-free puts debugging Ruby gem FTW that prints file names, line numbers, class names, method names, code statements, headers, footers, and stack traces; and formats output nicely courtesy of awesome_print (or amazing_print if you prefer).
puts_debuggerer automates tips mentioned in this blog post by Aaron Patterson using the pd method available everywhere after requiring the gem.
Basic Example:
# /Users/User/trivia_app.rb # line 1
require 'pd' # line 2
class TriviaApp # line 3
def question # line 4
bug_or_band = 'Beatles' # line 5
pd bug_or_band # line 6
end # line 7
end # line 8
TriviaApp.new.question # line 9Output:
[PD] /Users/User/trivia_app.rb:6 in TriviaApp.question
> pd bug_or_band # line 6
=> "Beatles"pd revealed that the variable contains the band name "Beatles" not the bug "Beetle", in addition to revealing the printed code statement pd bug_or_band, the file name /Users/User/trivia_app.rb, the line number 6, the class name TriviaApp, and the method name question.
It can be quite frustrating to lose puts statements in a large output or log file. One way to help find them is add an announcer (e.g. puts "The Order Total") or a header (e.g. puts '>'*80) before every puts statement. Unfortunately, that leads to repetitive wasteful effort that adds up quickly over many work sessions and interrupts thinking flow while solving problems.
puts_debuggerer automates that work via the short and simple pd command, automatically printing meaningful headers for output and accelerating problem solving work due to ease of typing.
Example without pd:
puts order_totalOutput:
195.50
Which gets lost in a logging stream such as:
(2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
195.50
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
Here is a simple example using pd instead, which provides everything the puts statements above provide in addition to deducing the file name, line number, class name, and method name automatically for dead-easy debugging:
pd order_totalOutput:
(2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
[PD] /Users/User/ordering/order.rb:39 in Order.calculate_order_total
> pd order_total
=> 195.50
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
This is not only easy to locate in a logging stream such as the one below, but also announces the order_total variable with [PD] for easy findability among other pd statements (you may always enter [PD] or variable name order_total using the CMD+F Quick Find to instantly jump to that line in the log):
pd order_total
pd order_summary
pd order_detailsOutput:
(2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
[PD] /Users/User/ordering/order.rb:39 in Order.calculate_order_total
> pd order_total
=> 195.50
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
[PD] /Users/User/ordering/order.rb:40 in Order.calculate_order_total
> pd order_summary
=> "Pragmatic Ruby Book"
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
[PD] /Users/User/ordering/order.rb:41 in Order.calculate_order_total
> pd order_details
=> "[Hard Cover] Pragmatic Ruby Book - English Version"
What if you would like to add a header for faster findability of groups of related pd statements? Just use the header option:
pd order_total, header: true
pd order_summary
pd order_detailsOr the h shortcut:
pd order_total, h: :t
pd order_summary
pd order_detailsOutput:
(2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
[PD] /Users/User/ordering/order.rb:39 in Order.calculate_order_total
> pd order_total, header: true
=> 195.50
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
[PD] /Users/User/ordering/order.rb:40 in Order.calculate_order_total
> pd order_summary
=> "Pragmatic Ruby Book"
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
[PD] /Users/User/ordering/order.rb:41 in Order.calculate_order_total
> pd order_details
=> "[Hard Cover] Pragmatic Ruby Book - English Version"
Wanna add a footer too? No problem!
pd order_total, header: true
pd order_summary
pd order_details, footer: trueOr use the f shortcut:
pd order_total, h: :t
pd order_summary
pd order_details, f: :tOutput:
(2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
################################################################################
[PD] /Users/User/ordering/order.rb:39 in Order.calculate_order_total
> pd order_total, header: '>'*80
=> 195.50
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
[PD] /Users/User/ordering/order.rb:40 in Order.calculate_order_total
> pd order_summary
=> "Pragmatic Ruby Book"
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
[PD] /Users/User/ordering/order.rb:41 in Order.calculate_order_total
> pd order_details, footer: '<'*80
=> "[Hard Cover] Pragmatic Ruby Book - English Version"
################################################################################
Need a quick stack trace? Just use the caller option (you may surround with header and footer too via wrapper).
pd order_total, caller: true, wrapper: true
pd order_summary
pd order_detailsOr use the c and w shortcuts:
pd order_total, c: :t, w: :t
pd order_summary
pd order_detailsOutput:
(2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
********************************************************************************
[PD] /Users/User/ordering/order.rb:39 in Order.calculate_order_total
> pd order_total, caller: true, wrapper: true
=> 195.50
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `block in require_with_bootsnap_lfi'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/loaded_features_index.rb:92:in `register'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22:in `require_with_bootsnap_lfi'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31:in `require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/activesupport-5.2.4.3/lib/active_support/dependencies.rb:291:in `block in require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/activesupport-5.2.4.3/lib/active_support/dependencies.rb:257:in `load_dependency'
/Users/User/.rvm/gems/ruby-2.7.1/gems/activesupport-5.2.4.3/lib/active_support/dependencies.rb:291:in `require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/railties-5.2.4.3/lib/rails/commands/server/server_command.rb:145:in `block in perform'
/Users/User/.rvm/gems/ruby-2.7.1/gems/railties-5.2.4.3/lib/rails/commands/server/server_command.rb:142:in `tap'
/Users/User/.rvm/gems/ruby-2.7.1/gems/railties-5.2.4.3/lib/rails/commands/server/server_command.rb:142:in `perform'
/Users/User/.rvm/gems/ruby-2.7.1/gems/thor-1.0.1/lib/thor/command.rb:27:in `run'
/Users/User/.rvm/gems/ruby-2.7.1/gems/thor-1.0.1/lib/thor/invocation.rb:127:in `invoke_command'
/Users/User/.rvm/gems/ruby-2.7.1/gems/thor-1.0.1/lib/thor.rb:392:in `dispatch'
/Users/User/.rvm/gems/ruby-2.7.1/gems/railties-5.2.4.3/lib/rails/command/base.rb:69:in `perform'
/Users/User/.rvm/gems/ruby-2.7.1/gems/railties-5.2.4.3/lib/rails/command.rb:46:in `invoke'
/Users/User/.rvm/gems/ruby-2.7.1/gems/railties-5.2.4.3/lib/rails/commands.rb:18:in `<main>'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `block in require_with_bootsnap_lfi'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/loaded_features_index.rb:92:in `register'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22:in `require_with_bootsnap_lfi'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31:in `require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/activesupport-5.2.4.3/lib/active_support/dependencies.rb:291:in `block in require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/activesupport-5.2.4.3/lib/active_support/dependencies.rb:257:in `load_dependency'
/Users/User/.rvm/gems/ruby-2.7.1/gems/activesupport-5.2.4.3/lib/active_support/dependencies.rb:291:in `require'
/Users/User/code/sample-glimmer-dsl-opal-rails5-app/bin/rails:9:in `<top (required)>'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/lib/spring/client/rails.rb:28:in `load'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/lib/spring/client/rails.rb:28:in `call'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/lib/spring/client/command.rb:7:in `call'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/lib/spring/client.rb:30:in `run'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/bin/spring:49:in `<top (required)>'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/lib/spring/binstub.rb:11:in `load'
/Users/User/.rvm/gems/ruby-2.7.1/gems/spring-2.1.0/lib/spring/binstub.rb:11:in `<top (required)>'
/Users/User/code/sample-glimmer-dsl-opal-rails5-app/bin/spring:15:in `require'
/Users/User/code/sample-glimmer-dsl-opal-rails5-app/bin/spring:15:in `<top (required)>'
bin/rails:3:in `load'
bin/rails:3:in `<main>'
********************************************************************************
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
[PD] /Users/User/ordering/order.rb:40 in Order.calculate_order_total
> pd order_summary
=> "Pragmatic Ruby Book"
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
[PD] /Users/User/ordering/order.rb:41 in Order.calculate_order_total
> pd order_details
=> "[Hard Cover] Pragmatic Ruby Book - English Version"
Is the stack trace too long? Shorten it by passing number of lines to display to caller option.
pd order_total, caller: 3, wrapper: true
pd order_summary
pd order_detailsOr use shortcut syntax:
pd order_total, c: 3, w: :t
pd order_summary
pd order_details (2.7ms) CREATE TABLE "ar_internal_metadata" ("key" character varying PRIMARY KEY, "value" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
ActiveRecord::InternalMetadata Load (0.4ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
********************************************************************************
[PD] /Users/User/ordering/order.rb:39 in Order.calculate_order_total
> pd order_total, caller: 3, wrapper: true
=> 195.50
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `require'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `block in require_with_bootsnap_lfi'
/Users/User/.rvm/gems/ruby-2.7.1/gems/bootsnap-1.4.6/lib/bootsnap/load_path_cache/loaded_features_index.rb:92:in `register'
********************************************************************************
(0.2ms) BEGIN
SQL (0.3ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "key" [["key", "environment"], ["value", "development"], ["created_at", 2017-08-24 22:56:52 UTC], ["updated_at", 2017-08-24 22:56:52 UTC]]
(0.3ms) COMMIT
[PD] /Users/User/ordering/order.rb:40 in Order.calculate_order_total
> pd order_summary
=> "Pragmatic Ruby Book"
ActiveRecord::InternalMetadata Load (0.3ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 LIMIT $2 [["key", :environment], ["LIMIT", 1]]
(0.2ms) BEGIN
(0.2ms) COMMIT
[PD] /Users/User/ordering/order.rb:41 in Order.calculate_order_total
> pd order_details
=> "[Hard Cover] Pragmatic Ruby Book - English Version"
Learn about many more options and features at the Puts Debuggerer GitHub project page.
2 comments:
That's really nice, but instance methods should follow the #-notation.
Yes, I realize that. At the moment, the library does not distinguish between instance methods and class methods, which is why it was decided to just display a '.' between the class and method. It is good enough as a start.
But, there is a project TODO item to explore adding the functionality of distinguishing instance methods from class methods, and showing '#' as the separator for instance methods and '::' as the separator for class methods (or '.' if it looked more programmer friendly). If that were implemented in the future, it would get announced on this blog (you are welcome to look into it yourself too and submit a Pull Request if you want this feature earlier).
Post a Comment