Time.to_s and the 19 million row scan 3

Posted by dburkes Tuesday, January 22, 2008 22:15:00

Lately we've been noticing slowness on Lingr's database. Some queries were taking a ridiculously long time to complete, even some COMMITs were taking half a minute or more. The slowdown seemed to be across the board, rather than isolated into a particular table or a particular query.

After much investigation, MySQL upgrades, etc, Kenn finally noticed something weird in the slow query logs.

We had many queries in there that referenced time ranges, like this:

SELECT * from events WHERE created_at >= '2008-01-21 00:00:00' ...

but occasionally, one would show up that looked just a little bit different, like this:

SELECT * from events WHERE created_at >= '2008-01-21 00:00:00 PST' ...
With the help of MySQL's EXPLAIN statement, Kenn quickly discovered that while the first type of query would use indexes, and scan only, say, 100,000 rows, the second type would scan all 20,000,000+ rows. Further examination of the output of EXPLAIN revealed that the second query issued 4 warnings. SHOW WARNINGS revealed the following:
Incorrect datetime value: '2008-01-21 00:00:00 PST' for column 'created_at' at row 1

YIKES! We misformatted a timestamp in a query, and as a result, MySQL was scanning the entire 20M+ row table every time.

I tracked this query down in our code to something like this:

UserMessage.find_all_by_room_id @room.id, :conditions => "created_at >= '#{@time.to_s}'..."

As it turns out, time.to_s renders the timezone by default. Rails has added a nice format specifier, so you can say time.to_s(:db), and we were doing this everywhere else, but had forgotten the (:db) in this one place.

MySQL was barfing on the timezone specifier, and silently falling back to scanning the entire table. To add insult to injury, this query occurred in the rendering of an RSS feed, so it was used not infrequently.

Lesson learned- be very careful in how you format queries involving datetime fields. Forget to use the :db format specifier, and you could suffer terrible consequences.

For the extra curious, I did manage to find a MySQL ticket that seemed somewhat related.

The Sun/MySQL Debacle 3

Posted by dburkes Wednesday, January 16, 2008 08:14:00

Got news this morning that Sun is acquring MySQL AB- what an unsettling way to start the day.

To me, this move by Sun signals their total desperation. Their hardware business has been decimated by the commoditization of high-performance computing, as well as by virtualization technology. Their software business has been decimated by their own mismanagement of some real innovations, as well as the rise by Linux to almost complete domination of the non-Fortune 500 datacenter market (that is, while Fortune 500 companies might buy Sun's overpriced machines, the Fortune Other 50000 use mostly commodity servers running Linux). So now, Sun is desperate for some traction into those other 50000 companies.

Given Sun's history of how they manage products, leaving innovation to wither and die while they chase the million-dollar service contracts at the Fortune 50, I'd say things may not bode well for MySQL.