Prying Open The Black Box

RailsConf 2015

by Godfrey Chan

In his talk at RailsConf 2015, Godfrey Chan explores the often mysterious and complex inner workings of Ruby on Rails, emphasizing the importance of debugging skills for developers. He begins by welcoming attendees and sharing his personal journey within the Rails community, including his contributions to the Rails core team. The theme of the talk is to demystify Rails and provide practical debugging strategies for developers facing unexpected issues.

Key points discussed include:

Understanding the 'black box' of Rails: Chan explains that many developers perceive Rails as magical, but with the right understanding, it’s just a framework with conventions and sensible defaults.
Initial debugging steps: He encourages developers to check documentation, ensure they are using the latest version of Rails, and emphasizes the importance of understanding the stack trace when an error occurs.
Utilizing the stack trace: The stack trace is introduced as a powerful debugging tool; Chan explains how to interpret the stack trace to track where errors originated.
Advanced debugging techniques: Chan discusses various methods, including using 'put' statements for debugging, raising custom errors to track code execution, and leveraging the debugger provided with Rails, such as 'byebug.'
Examining Rails code: He suggests opening up gems and the Rails codebase using 'bundle open' to investigate the source of issues, noting that understanding the code can often lead to identifying the problem.
Reproducing bugs: Chan advises creating a new Rails app or using simplified examples to replicate issues. This can help determine if a problem lies within Rails itself or in the additional gems used.
Engagement with the community: He encourages participation in community events like office hours for collaborative troubleshooting and contributions to Rails.

The conclusion emphasizes that debugging is a crucial skill for any developer working with Rails, positioning it as an ongoing learning process rather than a one-off challenge. Chan reminds attendees that the conference offers resources and community support for further engagement and learning opportunities. Throughout the talk, Chan's passion for the Rails framework and its community is evident, aiming to empower developers to tackle the inevitable challenges they face in their coding endeavors.

00:00:11.920 Good morning! I'm very honored to be the person to kick off this conference. As you probably know from all the banners we have around downtown, the theme of this year's conference is 'One Industry, One Stage.' The last few years have been exceptionally great for our industry, and with all of us here at one stage, our industry is stronger than ever. So, ladies and gentlemen, welcome to RailsConf 2015, the biggest trade show for the laundry and dry cleaning industry. Just kidding! If you're here from the dry cleaning industry, unfortunately, your conference actually ended two days ago. You should probably stick around anyway because, as you will find out, our community is also very obsessed with keeping things dry and clean. All right, let's try this again: welcome to RailsConf 2015, everyone!

00:00:37.120 I'm Godfrey Chan, and you can find me on the internet as 'Chain Can Code.' I love coming to RailsConf; this is actually my fourth RailsConf, and it has a lot of sentimental value for me personally. Four years ago, I was at RailsConf as part of the scholarship program, and it was my first tech conference ever. I came back the following year, went to the Rails core office hour, and had my request merged. Since then, I've been making regular contributions to Rails, and shortly after RailsConf last year, I was accepted into the Rails core team. A year later, here I am speaking at RailsConf for the first time! I would like to thank the community for supporting me in what I do. If you were in Austin four years ago, I would personally like to thank you for contributing to my ticket, and I hope that was a worthwhile investment for you.

00:01:20.560 If you're here for the first time, or if you've recently picked up Rails, welcome on behalf of the Ruby and Rails community. I promise that you'll have a good time here. In fact, I had such a great time at RailsConf last year that I took one of the signs with me and traveled around the country with it! As you can see, we have been through a lot. We went to Hollywood, appeared on the Conan Show together, sat at a poker table, and even made it to Canada after spending a few days on a big boat. By the way, if you’re thinking about doing this, please don’t steal a RailsConf sign—at least not until the conference is over.

00:02:09.920 As I mentioned earlier, I’m on the Rails core team, and I also work on a newsletter called 'This Week in Rails.' If you would like to keep up with the latest changes in Rails, this would be a pretty good way to do it. You can subscribe to the newsletter at that URL or, if you’re interested in writing for it, we should chat afterward. I work for a small agency in Vancouver, Canada, called Brew House. Speaking of Canada, if you have never been there and would like to experience it for yourself, I wrote a gem for that. You can run 'gem install canada,' and all you need to do is require Canada, and you'll be able to program like a Canadian! However, if you actually want to experience Canada, we're organizing a Ruby conference in Vancouver later this year. The details are a little sparse right now, but if you’re interested in coming, you can follow the Vancouver Ruby Twitter account to stay in the loop.

00:03:03.040 Now let’s actually get on to the real talk. Like many of you, I watched David's keynote last year and stopped calling myself an engineer; instead, I became a software writer. After carrying this job title around for a year, I realized that it doesn't fully capture what I do for work. When I work on clients' projects, I get to work on some pretty complex Rails apps, and for these apps, I spend most of my time fixing things rather than making my code look pretty. Either I’m fixing an existing bug in the app or writing new code that somehow broke the app in unexpected ways, and I have to figure out why.

00:04:01.760 This is something I take a lot of pride in, and you can see that I take myself very seriously. But of course, in reality, what I actually do is pretty boring. All I do is dig into the code, figure out what’s wrong, and fix it—rinse and repeat. By the way, that's my co-worker, Horace Kincaid; if you see him around the conference, please do not be alarmed. As boring as my job may seem, because I work on the Rails codebase, sometimes people think I’m doing something special for them. In fact, you may have heard it said before: this Rails thing is basically magic, and while it might be cool for a while, as soon as things stop working the way you expect, magic becomes black magic—and black magic is obviously bad because you can’t understand it. The only way out is to hire a wizard to fix your code.

00:05:08.560 Recently, one of the Rails core team members tweeted about this topic. It turns out that there’s actually no magic in Rails; it has some sane defaults and conventions, and all you need to do is read the documentation and learn about these things yourself. One tweet sparked a conversation on Twitter, and one of the replies summed it up eloquently: perhaps Rails works a little too well out of the box. You can be incredibly productive without spending much time studying the documentation, and it almost feels like it can read your mind. The key takeaway here is that the cost of learning Rails is not powered up front. You do not need to invest substantial time learning before you can start writing code.

00:06:00.000 With that lens, perhaps Rails is not really magic at all. Perhaps we just treat it as a black box because we don’t truly understand what’s inside that black box. Today, we're going to pry open the black box together, so you don't have to be afraid of it anymore. You’ve probably experienced this before: you wrote some code in a Rails app, and it blew up on you unexpectedly. When that happens, the first thing you need to do is—don’t panic! Take a deep breath; it's not too bad. What actually happened is that you wrote some code, ran it, expected it to do something, and that didn’t happen. Perhaps it could do something else, nothing happened, or maybe you received an exception.

00:07:00.479 The good news is you have some solid advantages here. First of all, you wrote the code, so presumably, you understand it. Because you have access to the code, you can run it, modify it, and do whatever you want with it. Additionally, because you wrote the code, you understand what went wrong here. You might not know why or how it went wrong yet, but you do know that you expected one thing to happen, and something else did. Lastly, because there’s no magic involved, your bug is not going anywhere; it’s not going to magically disappear on you, so you have time to fix it. With that in mind, let's look at some of the weapons you have to figure these things out when they don’t work as expected.

00:08:06.960 This might be a little obvious, but as Jeffrey pointed out on Twitter, you should probably start by checking the documentation. Surprisingly, not a lot of people know where to find Rails documentation. This is not an API for Rails that spits out JSON; this is actually the official documentation. This is where you can get the documentation for the latest stable release. And if you’re not using the latest stable release, that's not a problem! You can find the docs for any version from the same website. If you’re on the bleeding edge, such as running Edge Rails or using beta or RC, you can visit 'edgeapi.rubyonrails.org,' and you will find the latest documentation for what is on master.

00:08:40.560 There’s also something called Rails Guides, which consists of more detailed and hands-on articles about specific topics. Similarly to the API, you can access both the tech version or the edge version. Another seemingly obvious point is that you should probably be using the latest version of Rails, as the problem you’re experiencing might have already been fixed. However, determining which version is the latest might not be very obvious, especially if you're new to this. The Rails versioning scheme may not work the way you expect. The first digit in the version is the major version number, the second is the minor version number, and the last one is the patch version. The major and minor versions don’t matter as much because the first two digits together make up the release series. As long as you stay on the same release series, it should be compatible with what you're using.

00:09:39.839 In other words, you should try to stay on the last patch version of the release series that you’re using. When bugs are fixed in a particular version, they are backported to what’s called the 'stable branches' for the release series; therefore, if you see someone fixed a bug on GitHub, and the pull request was merged but a released patch version is not available yet, you can change your Gemfile to point to the corresponding stable branch range, and you will get the fix instantly. So, regarding the basics: read the documentation and ensure you are using the latest version. If you’re still having the same problem, it’s time to get serious, dig in, and really understand the bottom of the issue.

00:10:56.320 The first and most powerful weapon you have is called the stack trace. You’ve probably seen it before; you get one whenever you encounter an error in your app. The first line tells you what the error was, and the rest of them is basically the stack trace—a breadcrumb trail of your code. It’s arranged chronologically; the bottom is the oldest code that ran, and the top is the most recent one executed. There are talks about possibly reversing this order in Rails for Ruby 2.3. If you visualize it a little better, what the stack trace is really telling you is that at some point, this 'create' method in your Posts controller was executed.

00:11:37.040 The 'create' method ultimately calls the respond_to block, which then executes 'post.save'. This eventually triggers callbacks with 'ensure_author_before_save', which results in an exception being raised somewhere within that process. Essentially, what the stack trace provides is just a snapshot of the breadcrumb trail that led to the point where things began to go awry. If you recall Atlanta, no offense intended, something is not right here. Someone must have called the Posts controller's 'create' method, as it cannot just call itself out of thin air. If you consider the stack trace, we didn’t call the before_create or before_save callback directly; all we called was the '.save' method, and yet somehow that initiated the 'ensure_author' callback without appearing directly in the stack trace. This makes me think that Rails isn't being completely transparent here.

00:12:40.560 As it turns out, Rails has something called the backtrace cleaner, which by default only shows you the application stack frames and removes everything else. If you look in your initializers folder, you will likely see a file explaining how to customize the backtrace cleaner. At the bottom of that file, there's a line you can uncomment which enables Rails to provide you the full stack trace. The stack trace will then show you everything that is actually happening. While it may not fit on the screen anymore, you can adjust the font size to improve readability, allowing you to see all the details without losing crucial information. Ultimately, Rails is just Ruby code being executed on your computer; it's trying very hard to stay out of your way.

00:13:30.000 This approach is very reasonable because when something goes wrong, it’s most likely in your application code. By having the backtrace cleaner, Rails helps you focus on what is most likely to be wrong. However, if you suspect that Rails is responsible for a problem, you need to see everything to understand the full picture. Now that we've learned how to read the stack traces, you might start to appreciate just how useful they can be. However, stack traces only appear when there is an error—what if your code silently fails, or your app executes some code, and you have no idea how it got there? In such cases, consider raising your own errors. This might look simple, but it is a very useful debugging technique.

00:14:36.560 For instance, let’s say you have no idea how the 'ensure_permission' method is executed; you can raise an error there, and boom—you’ll get a stack trace, revealing how that code was executed. However, stack traces sometimes don’t provide enough information about the root of the problem. A stack trace is merely a snapshot of the system’s state right before the exception. In reality, a lot of other events likely occurred before then, and the root cause of your issue could be anywhere in that history. For example, if you encounter a NoMethodError while trying to call 'current_user.name,' this occurs because 'current_user' is nil, leading to a failed method call on nil. While you can see the stack trace indicating this, it doesn't show you why 'current_user' is nil to start with.

00:15:52.160 To determine why 'current_user' is nil, we can employ a very advanced debugging method called the 'put' statement. This is likely the first thing you learned when you started learning Ruby, but it can also accomplish significant tasks for debugging. For instance, you can put a debugging statement in the code you want to investigate, and whenever that code executes, it will help track execution. You can print out key variables or important data to learn more about what is happening in the execution, which aids you significantly in understanding the problem. Another debugging method is to use the 'caller' method, which provides a stack trace without throwing exceptions, allowing your code to continue running.

00:17:11.080 There’s also a tool in the standard library called 'pp,' which stands for pretty print. This tool provides more organized output for complex objects printed to the console. Additionally, Rails offers a method called 'instance_values,' which gives you a hash of all the instance variables for the current object, also useful while debugging. The drawback of some of these advanced debugging techniques—besides cluttering your logs with redundant messages—is that you need to know precisely what you want to find out beforehand. If you forgot to add a debug point for the 'session_user_id' variable, for example, you wouldn’t receive that information in your logs.

00:18:13.920 Fortunately, there’s a more effective debugging technique called the debugger. If you’re using Rails 4.2 or newer, you probably already have a debugger in your Gemfile called 'byebug.' If you don’t have it, you can add it yourself. To use it, simply replace your 'put' statements with 'byebug' calls. When the code reaches that line, you'll be able to execute arbitrary Ruby code in your console; you can check variables and instance outputs. There are also some byebug-specific commands that can assist in debugging further, which you can find in the documentation. Additionally, starting from Rails 4.2, you can add a console helper in your ERB templates, allowing you to perform similar actions right in the browser.

00:19:28.560 However, even this advanced debugging technique may not always provide enough information. When you look at a stack trace, the initial frames you want to investigate often lead to Rails code, which makes it difficult to pinpoint the exact issue. You may wonder if those names and line numbers in the stack trace correspond to Ruby files on your computer. If so, you can open those files in your text editor, modify them and save to see if that resolves your issue. And you're correct—many things you execute are simply plain text files on your computer, allowing you to modify them without recompiling them.

00:20:38.360 You can utilize the command 'bundle open' to make this process even easier. Since you’re probably using Bundler for your Rails app, just type 'bundle open gem_name' (for example, 'bundle open i18n') and this will open the gem in your favorite text editor, allowing you to experiment, add 'put' statements or debugger calls, or play around with your theories. You can go ahead and modify the gem without being overly cautious, as running 'gem pristine' afterward will restore any changes you made to the gem. Just remember that all gems are loaded when you start your Rails app, so anytime you make changes to Rails or other libraries, you’ll need to restart your Rails server to apply those modifications.

00:21:48.400 If you try running 'bundle open rails,' something strange might occur. Your text editor opens, and you're in the Rails gem, but the gem appears empty. The reason is that Rails is broken down into several smaller libraries; the Rails gem itself is essentially a meta-gem that requires all others. Some of these libraries you might be familiar with are Active Record and Active Support. You don’t even need to differentiate between each library because your stack trace indicates which library you’re looking at—so in this case, you would run 'bundle open active record.' Alternatively, if you have a local Rails checkout with you, instead of using 'bundle open,' you can modify your Gemfile to point to the directory of your local Rails checkout.

00:23:24.720 This is beneficial because your Rails checkout is a Git repository where you can employ Git commands as usual. You can stash things, reset changes, and clean things up afterward. You can even check out specific branches or tags—this is especially useful if you suspect a regression occurred between versions (for instance, between 4.2.0 and 4.2.1). Now let's revisit the stack trace. Once you figure out how to use 'bundle open,' and you successfully open the first file in the stack trace, you may find that it has 300 lines of complex code that aren’t immediately comprehensible. That's okay. Take a deep breath; it’s not as daunting as it seems.

00:24:41.760 Amidst all the complexity of the file, many parts won’t pertain to your current issue. Focus is vital; identify the method that's responsible for your issue and understand its context. When analyzing a method, ask yourself four fundamental questions: What is this method supposed to do? What are its inputs? This could take the form of method arguments, instance variables, or global variables. Given these inputs, what should the expected output be? Most importantly, does the actual output match your expectations? Let's follow the breadcrumbs together and analyze what happens in the method highlighted in the stack trace.

00:25:57.760 We find ourselves in the method called 'find_sdi_class.' We can quickly recognize that this is the probable point to examine since our stack trace indicates we're encountering a 'SubclassNotFound' error, specifically in this method that raises the error. However, it’s unclear why this code is generating the error. It turns out it’s rescuing a NameError and ignoring the original error while raising this subclass not found error. This shifts the focus back to where the NameError is generated; this indicates that somewhere within this method, something is not defined, leading to the raising of that NameError. Using the debugger, we can check the value of the variable or method in question.

00:26:49.760 At this point, we may need to check where the 'compute_type' method is defined. It could be within a variable or a method. Unfortunately, finding its location isn’t straightforward because Ruby allows for plenty of module inclusions. The first thing you might try is a project-wide search in your text editor, but this can yield too many results since often the same method is overridden multiple times. However, Ruby tracks where methods are defined, which you can leverage to gather more information. Placing a debugger setting beforehand allows you to call 'method'—the method which gives us useful metadata on where this method is located.

00:28:10.080 For example, you can request the source location—which tells you the precise file and line number where that method is defined. By adding ‘method_source’ gem to your Gemfile, you’ll have the capability to print out the method definition directly in your debugger, along with any comments preceding it. With that obtained information, even if the relevant method looks long, you can narrow your focus. Though you might still struggle with understanding a few lines, remember that originally, a fellow developer crafted this code with a clear intention. Reviewing the initial implementations and track changes over time can assist you in discern the logic. Utilizing 'git log' allows you to see all commits associated with that file.

00:29:23.000 You can also use 'git blame' to identify who last edited each line and check the related commits for context. This overview helps in grasping the rationale behind code changes. Yet, don’t forget the scenario where a commit you analyze is merely a refactor. In such cases, it can be less illustrative about the purpose behind a specific piece of code. To evaluate the second to last commit that touched a line of interest, run 'git blame' with the caret symbol after the commit hash. If you prefer using GitHub, a Chrome extension may simplify this process on the web. Hopefully, any bugs are fixed by the time you get a chance to try these features.

00:30:39.360 After all your investigative work, you should have a much better understanding of the issue being addressed. Yet, given the complexity and multitude of gems or libraries in your application, numerous variables could be responsible. Naturally, generating a new Rails app can help determine if the issue can be replicated there. If you manage to replicate the problem, it’s likely a Rails bug. If you can't, the fault is probably with the additional gems you’re utilizing. Keep in mind that you can generate a new app with the '--def' flag, setting it up to point to your local checkout, which makes the replication process easier.

00:32:05.120 Sometimes, you may not require a fully-fledged Rails app for testing. For example, if you're having an Active Record issue, setting up a model and connecting to the database could be sufficient. The Rails repository contains bug report templates located in the guides folder, which presents minimum boilerplate codes required for testing against the Rails libraries. With this process, you should have templates for Active Record, Action Pack, and even a generic template for testing everything else. By reproducing your problem in a fresh application or isolated test case, others can more smoothly assist you in troubleshooting.

00:33:27.440 Consistency in reproducing your issue will make it easier for others to investigate and possibly fix it for you. Armed with everything you've learned from this talk, you might even be able to pinpoint exactly where the issue arises and fix it on your own, allowing you to send a pull request for that. At this point, you might be thinking, ‘Wow, I already knew all of this! I didn’t learn anything new from this talk! I’ve been debugging my applications every day at work.’ And you are absolutely right—you probably know all of this already!

00:35:01.920 Ultimately, this Rails framework is simply Ruby. When problems arise in Ruby, they can often lead to debugging issues pertaining to Rails. Rails is essentially a robust legacy codebase, likely resembling many of the other codebases you work on. If you'd like to put this knowledge into practice or if you seek a refund because you tried these methods in your app and they didn’t work, we are hosting a Rails core community office hour on Wednesday during happy hour at Heroku Beach. You can bring your app for guidance and assistance with any issues you're facing. Additionally, Eileen, one of the Rails contributors, is running a lab later this afternoon focusing on contributing to Rails, covering many elements I couldn't fit into this talk.

00:36:55.200 That’s all I’ve prepared for today. Once again, you can find me on the internet as 'Chain Can Code.' Thank you very much, and enjoy the rest of the conference.