Debugging Rails with Custom Instrumentation

Part 9 in the series A Comprehensive Guide To Debugging Rails {: .series-highlight}

Our Custom Instrumentation

• debugging_id: Within the HTML on some web-pages (product page, sample page) we place invisible code indicating the database ID of the object that page is based off, which you can use to quickly find the record within the Rails console during debugging sessions. This beats typing multi-parameter string-based searches. Deaden your doubts about the value of this techniques by comparing the short Product.find(313) with the clunky Product.where(permalink: "medicine", year:2011, institution: "University of Oxford" ). To see these debugging IDs open up a relevant page, enable the web-inspector, search (Command-F) for "debugging" and read the ID within the source code. Within the admin side of the website, where the placement of a visible debugging ID poses no risk of alienating customers, we often include the debugging ID within the page's viewable HTML, obviating the need for inspect element.

• Explanatory exception messages: Improve exception messages by including information helpful for investigation or debugging. For example the pictured exception message returns the IDs you'll need to refer to in the console.

• Exception Reports: Whenever an unrescued exception is raised, the "exception_notifier" gem emails an exception report to the IT team. These contain an exception message, a backtrace and other information about the state of the software when the exception was raised. I often find the default information provided inadequate for debugging, so I insert a "rescue" statement, manually trigger the exception notifier with additional data, then re-raise the exception so that the code flow continues as if we had never interfered. For example:

• Archived Exception Reports: Exception reports, having arrived into our Gmail account, are searchable through the Gmail interface. We used Gmail filters to label all incoming exception emails within Gmail as "exceptions", meaning that we can do searches such as "ProductGenerator label:exceptions after:2014-3-17" to find all exceptions after 17th of March that mention the ProductGenerator class. (This assumes you archive exception emails instead of deleting them outright). I particularly like this approach for data-integrity issues, by which I mean cleaning database records following faulty SQL caused by a bug. Case in point: I received exception reports after running an erroneous Rake command and I wanted to see how many exceptions affected the product with ID 252, so I searched Gmail for "Spree::Product 252 label:exceptions after:2014-3-17", and Gmail found all the archived exception reports containing both Spree::Product and the number 252. For this approach to work it assumes that you archive instead of delete your messages in Gmail/the desktop/phone applications you use to access Gmail. I mention multiple clients because, as I learned the hard way, each one might need to be configured separately.

• Previous Debugging Records: This one is highly specific to the Oxbridge Notes process for debugging, whereby even if no-one else will ever read the report, we record every thought about the bug, every experiment or fix tried, and every ruled out hypothesis into a file within the folder documentation/bugs. Before fixing a new bug search through this folder using the ack utility to find various identifying information pieces (such as the ExceptionName, part of the exception message, or the user_id in question). Often our previous bug reports will provide important clues on how to fix the current bug or on dead alleys down which we previously squandered our time.

• MailView: Quickly verify that all our emails compile and proof-read their contents by visiting /mail_view from development mode. This feature relies on the mail_view gem. For every new email our software is supposed to send, you must add a corresponding entry to the app/mailers/mail_preview.rb file for that email to appear in this previewer.

• Logging in as a particular user: Sometimes you have to walk a mile in a user's shoes to understand why your software broke. To do this download the production database freshly to your development machine (so as to take into account recent changes that might influence the bug), find the user experiencing bugs in the Rails console user = User.find_by_email "something@hotmail.com", then reset that user's password to something generic (we have a custom method to do just that: user.default). This method will print out a new password for that user, and you can use this to log in as that user in development mode. This new password does not affect the user's production account, which retains the password as the user originally set it. (And yes, logging in as a user is acceptable in our business since this debugging technique is outlined within our website's privacy policy and the most sensitive information you'd see by doing this is a customers purchase history, information that was already readily available in our standard Admin area.)

• Failed Delayed Jobs: We use the "delayed_job" gem to queue up background tasks, but by default this does not alert you whenever a background task fails. Thats a lot of important missing information therefore thanks to a custom modification we made to DelayedJob (gist here), an email is sent every time an exception is raised during a background job with heaps of useful debugging information.

• Undeleted Failed Delayed Jobs: The exception notification system for DelayedJobs outlined above has been known to fail in the past, and in such cases you want to refer to the DelayedJob database items in production for further debugging. Check for the presence of jobs with errors in production by typing our custom DelayedJob scope Delayed::Job.with_errors. If any results appear then view the error backtrace for an individual failed job with puts failed_job.last_error. Read the calling function that caused the error, alongside its inputs with puts failed_job.handler (we use puts in both cases because it displays the yaml output in a readable manner). Example output (Ill explain below)

Notice that the above output shows the caller's object type (Email), the method called on it (sendzipfile), the arguments to the method, such as the email address for the emails from field, would have been below, but I removed them from the screengrab to protect the identity of my customers.

• S3 files and folders Access your s3 account either through AWS web application dashboard or through third party desktop software such as s3Hub. Once in, inspect various folders to insure that the right files were uploaded/deleted in the right directories, and appear with the right filenames and with the correct headers and permissions. If you're not sure what folder a particular model saves its data to, refer to that model's source code and look at the first argument to has_attached_file. For example has_attached_file :data, means you want to browse to the /datas folder on s3.

• Never Swallow an Error: Some errors and failures are so routine that they can hardly be called exceptional. For example, certain document conversion operations we carry out at Oxbridge Notes have a failure rate. The nicest possible solution would be to fix the root cause once and for all. Absent a year-long study of the .docx file format and the C# programming language, that aint going to happen. The next best thing is to accept the failure within our normal code flow, but save that information within the database for later, in case we want to retry the operation, use an alternative algorithm, or simply control user-flow based on this information. I use the [FlagShihTzu gem for this purpose because it enables me to add an ever-increasing number of true/false attributes with names of my choosing to a single column in my models database table, by default on the column flags. This means that as the list of possible errors increase, I can add the capacity to record these errors without needing to modify the database. When it comes to debugging, I can quickly ascertain that this particular record had experienced issues, say with image_extraction.