Anatomy of a Bug

Anatomy of a Bug

I tend to spend a lot of time tracking down and fixing bugs on our websites. After doing this for a while, I developed some tricks to quickly diagnose the problem. I'm going to walk you through a recent bug report and fix that I had to do and how I fixed it. Unfortunately most bug fixing involves reading code though so if you aren't a programmer, you might get a little lost. Last Thursday we had a bug report come in that the coupons on the website weren't working and that it appeared all the coupons had disappeared from the site. The first step to fixing any bug is figuring out a way to reliably replicate it. If you can't replicate it, you can't fix it. This bug had a very obvious way it was being manifested and that was on the Coupons page, nothing was showing up. To verify the bug, I made a copy of our live environment and opened up the database and took a peek at the uc_coupons table. There were 8 entries in the table so the Coupons admin page should have showed 8 entries. Now I have to figure out why the coupons aren't showing up. The next thing is to check and make sure this is the latest version of the module so I check the project page to see if there are any updates. I'm one minor point behind but I update anyways just in case this was causing the problem. It doesn't fix the problem. I also checked the issue queue for any similar bugs and nothing comes up. Often times I find the bug already reported and a patch to try out to see if it will fix the problem. This time though there were no bugs even close. While some might be tempted to report the bug right away, I'd like to dig in a little deeper and see if this isn't a result of something we've done since we have a fair amount of custom modules and a fairly complex site. My next step usually involves finding the code that is being run for a page. One trick I like to use is the menu_router table. When I go to the admin page where the coupons show up, I see the url is "admin/store/coupons." By opening up the menu_router table and finding the row for the path "admin/store/coupons," I can see what function is the page callback. In this case I can see that the function is uc_coupon_display() in the file "sites/all/modules/contrib/uc_coupon/uc_coupon.admin.inc" Now I need to see what is actually going on during the callback so I open up my text editor and open the uc_coupon.admin.inc file and look for the uc_coupon_display() function. Right near the top of the function is a pager_query that should return a result. $result = pager_query('SELECT cid, name, value, code, type, created, valid_from, valid_until, bulk FROM {uc_coupons} WHERE status = %d'. tablesort_sql($header), 20, 0, NULL, $view_type == 'inactive' ? 0 : 1); $rows = array(); while ($row = db_fetch_object($result)) { $rows[] = array( theme('uc_coupon_actions', $row), check_plain($row->name), check_plain($row->code) . ($row->bulk ? '* '. t('(bulk)') : ''), $row->type == 'percentage' ? ((float)$row->value . '%') : uc_currency_format($row->value), format_date($row->created, 'custom', variable_get('uc_date_format_default', 'm/d/Y'), 0), $row->valid_from ? format_date($row->valid_from, 'custom', variable_get('uc_date_format_default', 'm/d/Y'), 0) : '-', $row->valid_until ? format_date($row->valid_until, 'custom', variable_get('uc_date_format_default', 'm/d/Y'), 0) : '-', ); } I wonder if anything is getting returned so I make sure the devel module is enabled and add dpm($rows)l after the while loop to see what value it has right now. (In this case I used dpm but if it got any more involved I would probably hook up xdebug so I could trace the functions and variables and get a better sense of what was going on.) After refreshing the page I see that the variable is an empty array so clearly nothing was being returned. Hmm... that is odd. I could look in watchdog and see what the error message is but in this case the SQL query is fairly simple and doesn't take any variables except if it should return active or inactive coupons. To test it out I copy and past the query into my SQL browser and remove the brackets from the table names and set status = 1. When I run the query, I get the error "Unknown column 'valid_from' in 'field list'." So now I know that the SQL query is not currently working because the column "valid_from" is not there. I do a quick inspection of the uc_coupons table and sure enough, the column doesn't exist. Maybe something is wrong with our schema. I open up the uc_coupon.install file in my text editor and look at uc_coupon_schema() to see if it matches what we've got in the database. I immediately notice that there are several discrepancies, the largest of which is that the valid_from column exists in the schema but not in the table. (I could also have used the schema module to see if they were the same but, hey, I'm old school.) This usually means that the valid_from column was added somewhere in an update hook and wasn't in the original schema that we installed. Uc_coupons has 7 update hooks and the third (uc_coupon_update_6002) has the code where the valid_from column was added. When I check the following update hooks it appears they also haven't been run. I run a database update just to be sure but it says everything is up to date. I even check the system table and it shows that uc_coupon is supposedly on schema 6006. At this point I realize that the updates haven't been run since 6001 so I reset the schema to 6001 and rerun the database updates. Sure enough, I didn't get any errors and everything seemed to work fine. (Please note that this was on my development copy, NOT on the live website. I replicated this on the live after I had fully tested everything.) Heading back to the coupons admin page everything now seemed to be working. Testing everything thoroughly showed that it was all fixed. I'm still not sure how we ended up in the state where the system table was marked as having the updates run but they weren't run. While I've got the website but fixed for now, we still need to track down how this happened and if someone is fiddling with the live database in ways that they shouldn't be. Now I need to go install the schema module and find out if anything else is out of sync. I hope this gives you some ideas on how to do bug tracking or at least gives you a glimpse into the world of web developers and what they go though when a bug is reported. What steps do you use to track down bugs? Photo Credit