Opening the admin page executes the following query:

SELECT DISTINCT(type) FROM watchdog ORDER BY type;

Adding an index on type improves the performance from 43 seconds to 1.19 seconds

I have 478235 records.

"I know it's a varchar column"

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

robertDouglass’s picture

Version: 4.7.4 » 5.x-dev

This should be addressed in 5 and backported to 4.7 and 4.6.

msameer’s picture

My bad. Looks like the server was a bit overloaded because I managed to execute the query without an index in about 5-6 seconds but still. The index improves the performance.

If you think that this should be in 5.x, I can work on a patch ?

robertDouglass’s picture

I'm in the process of benchmarking this. Please do roll a patch.

robertDouglass’s picture

I've now benchmarked this with 217905 rows in my watchdog table:

Conditions Average time Standard deviation
Standard Drupal core 565.329 4.693
Changed all VARCHAR columns to CHAR (not related to this issue, but was curious) 831.791 13.733
Changed CHARs back to VARCHAR 563.758 3.225
Made an index on column 'type' 0.709 1.334

So yes, we're looking at a situation where with that number of watchdog rows, making an index speeds up the query by nearly three orders of magnitude.

robertDouglass’s picture

I just hate that issue responses don't respect the Input Format.

Standard Drupal core

  • Average time: 565.329
  • Standard deviation: 4.693

Made an index on column 'type'

  • Average time: 0.709
  • Standard deviation: 1.334
robertDouglass’s picture

FileSize
798 bytes

Here's a patch against 4.7.

robertDouglass’s picture

Status: Active » Needs review
FileSize
1.21 KB

And here's one for HEAD.

robertDouglass’s picture

FileSize
1.44 KB

Forgot the new db case for postgres.

NOTE: because I've added this as upgrade 183 (I'm assuming it will get backported), there is NO case where the index might get added twice, so there is no need to check for the existence of the index before adding it.

robertDouglass’s picture

FileSize
2.43 KB

Updated 4.7 version; forgot to add to the three database creation files.

chx’s picture

Status: Needs review » Reviewed & tested by the community

While I have no HEAD pgsql Drupal, I ran the update SQL statement on a pgsql database and it worked. So, it works, the advantage is tremendous -- get it in!

killes@www.drop.org’s picture

I don't think it is neccessary to backport to 4.7. People with a lot of watchdog entries and a habit of looking at their logs all the time can add it themeselves. ;)

webchick’s picture

Status: Reviewed & tested by the community » Needs work

Ok in that case, the update number needs increasing to 1000-something.

RobRoy’s picture

Status: Needs work » Needs review
FileSize
1.17 KB

Cleaned up the patch for HEAD and put the update in the 1000 series.

robertDouglass’s picture

Gerhard: I don't agree with not backporting - aren't we planning on having another 4.7.* release at some point? Why deny that version this improvement? Is there a real reason *not* to? There are certainly good reasons why it should be backported; it is the highest quality watchdog we know how to offer.

robertDouglass’s picture

FileSize
1.4 KB

RobRoy's patch missed the postgres case for new databases.

This patch puts the upgrade in 1015 - use it if the change won't get backported to 4.7.

robertDouglass’s picture

FileSize
1.43 KB

This patch puts the upgrade in 183 - use it if the change will get backported to 4.7.

killes@www.drop.org’s picture

My reason to not backport is that it is only an admin function that is affected and so the overall impact isn't that big and that I try to avoid sql updates in minor releases if at all possible.

RobRoy’s picture

Oops, I updated the wrong patch. Sorry about that, and thanks for the catch Robert. I would change the double quotes to singles in the pgsql db_query but I'm too tired and don't want to seem TOO anal, but I feel like core stuff should set a good example as that's how I learned a lot of my coding standards.

Since this is such a big improvement IMHO it's worth a backport since a huge query time like that could affect your whole site's performance say if you had a bunch admins looking at the watchdog table. And if 4.7 users don't hit update.php after their core update, no big whoop. They're not going to see any db errors so the impact on the stability of that branch isn't really affected. Just my $0.02.

robertDouglass’s picture

Status: Needs review » Reviewed & tested by the community

So unless Gerhard changes his mind, #16 is the patch to go with, and it is RTBC. Chx has tested the postgres update.

@RobRoy... since I had the editor open to the line with the double quotes, I almost changed them and re-rolled, just for your benefit. But the whole file uses double quotes... and it would have been the only line with single, so I balked.

robertDouglass’s picture

FileSize
1.44 KB

see, that was sneaky of me! I said #16 but that's the one that assumes the backport ;-) Just trying to force killes' hand, I guess. I'm uploading a copy of 15 to this follow up... this is the patch to use.

Dries’s picture

Status: Reviewed & tested by the community » Fixed

Committed to CVS HEAD. Thanks.

robertDouglass’s picture

Status: Fixed » Reviewed & tested by the community
FileSize
1.42 KB

oh, that was even sneakier. I uploaded the wrong friggin' patch!

deep breath...

Here is the right one.

robertDouglass’s picture

Status: Reviewed & tested by the community » Fixed

Dries applied the right one.

Anonymous’s picture

Status: Fixed » Closed (fixed)
olo’s picture

I have an analogous problem in Drupal 6.0 with the same table ("watchdog"), but with the "uid" field, which isn't indexed yet.

When deleting multiple users, I can see in PostgreSQL logs that there are multiple UPDATE queries that occupy > 25 seconds:

duration: 35890.329 ms statement: UPDATE watchdog SET uid = 0 WHERE uid = 0

Adding an index fixes the problem:

CREATE INDEX watchdog_uid_idx ON watchdog USING btree (uid);

Should I file a new issue report?

Mumonkan’s picture

olo, i have seen the same problem. in drupal 5 though. i think (in our case) it is a cron process cleaning up deleted users. but i see the same trouble -- multi-second (often way way way too long!) queries of the form "UPDATE watchdog SET uid=0 WHERE uid=...". totally unacceptable, as it is locking the watchdog table all over the site (duh, of course watchdog is used by a ton of things), so the site gets ridiculously slow.

i find it kind of baffling this hasnt been addressed before. maybe people are zeroing out watchdog all the time, or simply have incredibly zippy servers (ha).

but fwiw, i agree that an index on uid would seem to be the (simple) solution. i would guess we would want to file this as a new report. but i figured i should comment, if for no other reason than to help some frustrated drupal admin find it via google. like i wish i had done a few weeks ago. haha