The Elixir 1.14 release added Kernel.dbg/2 to improve the developer experience for Elixir and Phoenix. You’re probably familiar with using IO.inspect/2 to debug your code. dbg is a new macro that’s somewhat similar to IO.inspect/2, but is specifically tailored for debugging. It prints the value of whatever you pass to it, plus the code and location of what you are debugging. Plus it has amazing features to help debug a function pipeline. Check out how you can use dbg to replace IO.inspect/2 in your debugging workflow.
Overview
We’re going to go learn about the dbg/2 macro and how we can use it to replace IO.inspect/2 as our primary tool to debug code.
- Create new Phoenix app
- Debugging a test with IO.inspect/2
- Debugging a test with dbg
- Advanced debugging with dbg, IEx, and pry
- Conclusion
Prerequisites
To follow this guide, make sure you have at least the following applications installed on your machine. In the brackets are the versions with which this guide was written.
- Elixir (1.14.0-otp-25)
- Erlang (OTP 25.0.4)
- Phoenix (v1.6.12)
- Node.js with npm (15.14.0)
Create New Phoenix App
We are going to create a simple project called HelloDbg. Use the command line to update your Phoenix version and create a new application.
$ mix archive.install hex phx_new
$ mix phx.new hello_dbg
Change into the project directory, create your database and start your server.
$ cd hello_dbg
$ mix ecto.create
$ mix phx.server
Now visit http://localhost:4000 and you should see the Welcome to Phoenix! page.
Add users
Now we want to add users to the project with the phx.gen html task. We’ll use the user update function as an example to see how dbg improves our debugging experience.
$ mix phx.gen.html Accounts User users name:string email:string \
bio:string number_of_pets:integer
Follow the directions to add the resource to the router.ex file and migrate the database with mix ecto.migrate.
Now start your server with mix phx.server and visit http://localhost:4000/users on your local machine to see the index of users. Add a new user to test out the database. We’ll update the user a little later.
Debug code with a test using IO.inspect/2
First we are going to look at how we might debug our Accounts.update_user/2 function using IO.inspect/2. Then we’ll look at how dbg makes debugging much easier.
IO.inspect/2 is useful for debugging because it returns the item argument passed to it without affecting the behavior of the original code. Let’s imagine we are getting an unexpected error while updating our user.
Open the HelloDbg.Accounts module at lib/hello_dbg/accounts.ex. We can add IO.inspect at the end of the Accounts.update_user/2 function to see what it returns.
def update_user(%User{} = user, attrs) do
user
|> User.changeset(attrs)
|> Repo.update()
|> IO.inspect()
end
We’ll run the test for this function to see what info is printed for debugging. The test is located in the test/hello_dbg/accounts_test.exs file.
# starts at line 37
test "update_user/2 with valid data updates the user" do
user = user_fixture()
update_attrs = %{bio: "some updated bio", email: "some updated email", name: "some updated name", number_of_pets: 43}
assert {:ok, %User{} = user} = Accounts.update_user(user, update_attrs)
assert user.bio == "some updated bio"
assert user.email == "some updated email"
assert user.name == "some updated name"
assert user.number_of_pets == 43
end
We can run just this test from our terminal.
$ mix test test/hello_dbg/accounts_test.exs:37
# test output
{:ok,
%HelloDbg.Accounts.User{
__meta__: #Ecto.Schema.Metadata<:loaded, "users">,
id: 2,
bio: "some updated bio",
email: "some updated email",
name: "some updated name",
number_of_pets: 43,
inserted_at: ~N[2022-09-12 03:00:03],
updated_at: ~N[2022-09-12 03:00:03]
}}
.
Finished in 0.06 seconds (0.00s async, 0.06s sync)
8 tests, 0 failures, 7 excluded
IO.inspect/2 prints the return value, a tuple with :ok and the updated user.
Since IO.inpect/2 returns what you pass in, you can insert it throughout the pipeline. You can even use the label option to keep track of what is printed.
def update_user(%User{} = user, attrs) do
user
|> IO.inspect(label: "User")
|> User.changeset(attrs)
|> IO.inspect(label: "Changeset")
|> Repo.update()
|> IO.inspect(label: "Updated")
end
However, this can get tedious and that is where dbg takes debugging to the next level.
Debug code in a test with dbg
Kernel.dbg/2 was added in the Elixir 1.14.0 release. It is a new macro that’s somewhat similar to IO.inspect/2, but is specifically tailored for debugging.
It prints the value of whatever you pass to it, plus the debugged code itself and its location. Let’s try it out in our Accounts.update_user/2 function. Update the following line:
def update_user(%User{} = user, attrs) do
user
|> User.changeset(attrs)
|> Repo.update()
|> dbg() # Update
end
Now run your test again.
$ mix test test/hello_dbg/accounts_test.exs:37
[lib/hello_dbg/accounts.ex:74: HelloDbg.Accounts.update_user/2]
user #=> %HelloDbg.Accounts.User{
__meta__: #Ecto.Schema.Metadata<:loaded, "users">,
id: 3,
bio: "some bio",
email: "some email",
name: "some name",
number_of_pets: 42,
inserted_at: ~N[2022-09-12 03:02:39],
updated_at: ~N[2022-09-12 03:02:39]
}
|> User.changeset(attrs) #=> #Ecto.Changeset<
action: nil,
changes: %{
bio: "some updated bio",
email: "some updated email",
name: "some updated name",
number_of_pets: 43
},
errors: [],
data: #HelloDbg.Accounts.User<>,
valid?: true
>
|> Repo.update() #=> {:ok,
%HelloDbg.Accounts.User{
__meta__: #Ecto.Schema.Metadata<:loaded, "users">,
id: 3,
bio: "some updated bio",
email: "some updated email",
name: "some updated name",
number_of_pets: 43,
inserted_at: ~N[2022-09-12 03:02:39],
updated_at: ~N[2022-09-12 03:02:39]
}}
.
Finished in 0.05 seconds (0.00s async, 0.05s sync)
8 tests, 0 failures, 7 excluded
First you get the file name, line number, and function name. Then the magic happens.
dbg/2 is a macro, so it understands Elixir code. You can see that when you pass a series of |> pipes to it dbg/2 will print the return value and the value for every step of the pipeline!
Advanced debugging with dbg, IEx, and pry
dbg/2 supports configurable backends. IEx automatically replaces the default
backend by one that halts the code execution with IEx.Pry, giving developers
the option to access local variables, imports, and more. IEx can be useful for debugging from a remote shell in production.
This also works with pipelines: if you pass a series of |> pipe calls to dbg (or pipe into it at the
end, like |> dbg()), you’ll be able to step through every line in the pipeline.
Let’s try it out!
Update user
Make sure you still have dbg/2 at the end of your Accounts.update_user/2 function.
def update_user(%User{} = user, attrs) do
user
|> User.changeset(attrs)
|> Repo.update()
|> dbg()
end
Then run IEx and your server with iex -S mix phx.server.
Go to your existing user and update some of the attributes.
You’ll notice when you click Save, the button will remain gray in an inactive state. Switch over to your interactive shell and you should see the IEx session ask if you want to pry.
Using pry in IEx
pry/0 is useful for debugging a particular chunk of code when executed by a particular process. If accepted, we will be able to access all variables, as well as imports and aliases from the code, directly From IEx. While pry is running, the code execution stops, until you call next or continue. Read more about pry/0 in the IEx docs.
You’ll notice the user is highlighted, letting you know where you are at in the code execution flow.
Let’s answer with a Y and give it a try.
↳ HelloDbgWeb.UserController.update/2, at: lib/hello_dbg_web/controllers/user_controller.ex:41
Request to pry #PID<0.912.0> at HelloDbg.Accounts.update_user/2 (lib/hello_dbg/accounts.ex:71)
68:
69: """
70: def update_user(%User{} = user, attrs) do
71: user # here
72: |> User.changeset(attrs)
73: |> Repo.update()
74: |> dbg()
Allow? [Yn] Y
Now that we are prying, we can access all variables. We can use binding/0 to print variables.
Interactive Elixir (1.14.0) - press Ctrl+C to exit (type h() ENTER for help)
pry(1)> binding()
[
attrs: %{
"bio" => "Updated bio",
"email" => "[email protected]",
"name" => "User",
"number_of_pets" => "2"
},
user: %HelloDbg.Accounts.User{
__meta__: #Ecto.Schema.Metadata<:loaded, "users">,
id: 3,
bio: "My bio",
email: "[email protected]",
name: "User",
number_of_pets: 1,
inserted_at: ~N[2022-09-12 04:52:16],
updated_at: ~N[2022-09-12 04:52:16]
}
]
You can see the values for both the updated attrs and the user. Now type next to move to the next function in the code flow.
pry(2)> next
iex(1)> user #=> %HelloDbg.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 3, bio: "My bio", email: "[email protected]", name: "User", number_of_pets: 1, inserted_at: ~N[2022-09-12 04:52:16], updated_at: ~N[2022-09-12 04:52:16]}
Break reached: HelloDbg.Accounts.update_user/2 (lib/hello_dbg/accounts.ex:72)
69: """
70: def update_user(%User{} = user, attrs) do
71: user
72: |> User.changeset(attrs) # here
73: |> Repo.update()
74: |> dbg()
75: end
It prints the user data and indicates that we have stopped at the User.changeset/2 function. Type next again.
pry(1)> next
iex(1)> |> User.changeset(attrs) #=> #Ecto.Changeset<action: nil, changes: %{bio: "Updated bio", number_of_pets: 2}, errors: [], data: #HelloDbg.Accounts.User<>, valid?: true>
Break reached: HelloDbg.Accounts.update_user/2 (lib/hello_dbg/accounts.ex:73)
70: def update_user(%User{} = user, attrs) do
71: user
72: |> User.changeset(attrs)
73: |> Repo.update() # here
74: |> dbg()
75: end
76:
It prints the result of the User.changeset/2 function and shows we are at the Repo.update/1 function. Type next again.
pry(1)> next
iex(1)> [debug] QUERY OK db=1.8ms queue=2.0ms idle=436.5ms
UPDATE "users" SET "bio" = $1, "number_of_pets" = $2, "updated_at" = $3 WHERE "id" = $4 ["Updated bio", 2, ~N[2022-09-12 04:52:44], 3]
↳ HelloDbg.Accounts.update_user/2, at: lib/hello_dbg/accounts.ex:73
|> Repo.update() #=> {:ok, %HelloDbg.Accounts.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, id: 3, bio: "Updated bio", email: "[email protected]", name: "User", number_of_pets: 2, inserted_at: ~N[2022-09-12 04:52:16], updated_at: ~N[2022-09-12 04:52:44]}}
It prints the [debug] logging data you would normally see. But it also prints the results of the Repo.update/1 function.
At this point, it may return only an :ok atom which will crash your program, but you were able to step through all of the piped functions and see the result of each one.
Conclusion
Now that you’ve seen how dbg works, you can start relearning to use it to debug your Elixir Phoenix code once you upgrade to Elixir 1.14. You can use it to print the value of whatever you pass to it and the code and location of the source code your area debugging. Plus, we saw how it helps debug a function pipeline. Finally, we saw haw we can use it in an IEx function to pry into your code. If you thought this post was helpful, check out the Phoenix Deployment Handbook, a guide on how to deploy your Phoenix application with the best tools for Elixir.