Tail Wagging Googlebot

I discovered an interesting and somewhat elusive bug in my user validation stuff last night. With a little more sleep and some forethought I might have arrived at the solution a little earlier that I did, but I got there eventually.

I noticed, of the handfall of users that have signed up for my Timeline Project, not all had validated their accounts. I wondered about the reason why and decided to do a bit of testing. I follow a pretty standard model for account validation:

• User enters their new details.
• I add the details to the database and generate a random key.
• I send an email to the specified address with a URL back passing the key as a param.
• User clicks on the URL in the email and I match it to the database key I stored earlier. Then I erase the key in the user's database entry. I only need to do this once and I use the key for other stuff (password resets).
• If everything matches up, I set a valid flag on the user account.

So pretty straightforward? When I originally wrote the code, I tested with a couple of accounts, assumed everything was fine and moved on. I assumed wrong.

Re-testing this stuff, I created a whole pile of accounts and checked that they could be successfully validated. To my chagrin, I found that when I clicked on the validation URL, for a handful of them, I generated an error message saying that the key didn't match. This was something of a gumption trap, a random intermittent fail with a system that should be trivial.

I fell back on that mainstay of programming, debug writes. I already have a decent logging system, so I added a few more log messages when the validation URL gets fired. The results I found were puzzling to say the least:

For this log example, the validation succeeded (validate_pass), but the message immediately after it was extremely suspicious. An attempt to validate that user id from some obscure IP address that I hadn't seen in my logs before. My "it is always your fault" programmer instincts failed me and I jumped from one irrational and outlandish conclusion to the next. Eventually I came to my senses and decided to do a traceroute on the IP address:

When my activation email arrived in my Gmail inbox, that enthusiastic, tongue lolling, tail wagging Labrador of a GoogleBot immediately jumped on my validation URL and bounded off to get it. So if the GoogleBot hit the URL first, then the key would get reset and the subsequent real user request would fail. It is pretty satisfying when a classic intermittent and quite random race condition has a very simple solution. "It is ALWAYS your fault". I gotta remember that one.

Adding a few lines to my robots.txt file, which up until that point had been empty, ensured that the GoogleBot would refrain from hitting those fragile URLs. Bug Fixed.

Permalink - Tags: Development,Google