MySQL slow_query_log reporting more Rows_examined than rows in table (no joins)

Question

When refactoring my entriestable and pulling the source column into a separate sources table , I'm performing an UPDATE which you can see in the below slow_query_log.

The entries table has somewhere between 2 and 3 million rows.

# Time: 120121 22:24:44
# User@Host: bt_user[bt_user] @ localhost []
# Query_time: 3910.984208  Lock_time: 0.091942 Rows_sent: 0  Rows_examined: 2092977602
SET timestamp=1327202684;
update entries set source_id = 4 where source = 'SOME_SOURCE';

Another bad case:

mysql> update entries set source_id = 7 where source = 'SOME_OTHER_SOURCE';
Query OK, 31270 rows affected (53 min 3.37 sec)
Rows matched: 31270  Changed: 31270  Warnings: 0

# Time: 120121 23:43:36
# User@Host: root[root] @ localhost []
# Query_time: 3183.845250  Lock_time: 0.000110 Rows_sent: 0  Rows_examined: 875871174
SET timestamp=1327207416;
update entries set source_id = 7 where source = 'SOME_OTHER_SOURCE';

Here is a more normal case:

mysql> update entries set source_id = 6 where source = 'YET_ANOTHER_SOURCE';
Query OK, 138592 rows affected (23.84 sec)
Rows matched: 138592  Changed: 138592  Warnings: 0

# Time: 120121 22:49:54
# User@Host: root[root] @ localhost []
# Query_time: 23.843946  Lock_time: 0.000149 Rows_sent: 0  Rows_examined: 554368
SET timestamp=1327204194;
update entries set source_id = 6 where source = 'YET_ANOTHER_SOURCE';

Any idea what the deal is with the very large Rows_examined? If I can determine that, I'll understand maybe why the problematic transactions took over an hour to execute.

If you need more information, just ask and I'll try to provide it. Thanks for helping!

mysql> show create table entries\G
*************************** 1. row ***************************
       Table: entries
Create Table: CREATE TABLE `entries` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `source` varchar(100) NOT NULL,
  `source_id` int(10) unsigned NOT NULL DEFAULT '1000',
  `ip` int(10) unsigned DEFAULT NULL,
  `domain` varchar(255) DEFAULT NULL,
  `url` varchar(2038) DEFAULT NULL,
  `info` varchar(255) DEFAULT NULL,
  `md5` varchar(32) NOT NULL,
  `start_date` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,
  `end_date` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00',
  PRIMARY KEY (`id`),
  KEY `both_date_source_index` (`start_date`,`end_date`,`source`),
  KEY `source_index` (`source`),
  KEY `ip_index` (`ip`),
  KEY `domain_part_index` (`domain`(20)),
  KEY `url_part_index` (`url`(30)),
  KEY `md5_index` (`md5`)
) ENGINE=InnoDB AUTO_INCREMENT=2355472 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

The indexing may need some review, but if that's affecting my problem...

My triggers (there is probably a better way to do this):

mysql> show triggers\G
*************************** 1. row ***************************
             Trigger: after_insert_count
               Event: INSERT
               Table: entries
           Statement: BEGIN

    IF NEW.ip IS NOT NULL THEN
      IF (SELECT COUNT(*) FROM ip_counts WHERE ip = NEW.ip) > 0 THEN
        UPDATE ip_counts SET count = count+1 WHERE ip = NEW.ip;
      ELSE
        INSERT INTO ip_counts (ip, count) VALUES (NEW.ip, 1);
      END IF;
    END IF;
    IF NEW.domain IS NOT NULL THEN
      IF (SELECT COUNT(*) FROM domain_counts WHERE domain = NEW.domain) > 0 THEN
        UPDATE domain_counts SET count = count+1 WHERE domain = NEW.domain;
      ELSE
        INSERT INTO domain_counts (domain, count) VALUES (NEW.domain, 1);
      END IF;
    END IF;
    IF NEW.url IS NOT NULL THEN
      IF (SELECT COUNT(*) FROM url_counts WHERE url = NEW.url) > 0 THEN
        UPDATE url_counts SET count = count+1 WHERE url = NEW.url;
      ELSE
        INSERT INTO url_counts (url, count) VALUES (NEW.url, 1);
      END IF;
    END IF;
  END
              Timing: AFTER
             Created: NULL
            sql_mode:
             Definer: root@localhost
character_set_client: utf8
collation_connection: utf8_general_ci
  Database Collation: utf8_general_ci
*************************** 2. row ***************************
             Trigger: after_update_count
               Event: UPDATE
               Table: entries
           Statement: BEGIN

    IF OLD.ip IS NOT NULL THEN


      UPDATE ip_counts SET count = count-1 WHERE ip = OLD.ip;
    END IF;
    IF OLD.domain IS NOT NULL THEN
      UPDATE domain_counts SET count = count-1 WHERE domain = OLD.domain;
    END IF;
    IF OLD.url IS NOT NULL THEN
      UPDATE url_counts SET count = count-1 WHERE url = OLD.url;
    END IF;

    IF NEW.ip IS NOT NULL THEN
      IF (SELECT COUNT(*) FROM ip_counts WHERE ip = NEW.ip) > 0 THEN
        UPDATE ip_counts SET count = count+1 WHERE ip = NEW.ip;
      ELSE
        INSERT INTO ip_counts (ip, count) VALUES (NEW.ip, 1);
      END IF;
    END IF;
    IF NEW.domain IS NOT NULL THEN
      IF (SELECT COUNT(*) FROM domain_counts WHERE domain = NEW.domain) > 0 THEN
        UPDATE domain_counts SET count = count+1 WHERE domain = NEW.domain;
      ELSE
        INSERT INTO domain_counts (domain, count) VALUES (NEW.domain, 1);
      END IF;
    END IF;
    IF NEW.url IS NOT NULL THEN
      IF (SELECT COUNT(*) FROM url_counts WHERE url = NEW.url) > 0 THEN
        UPDATE url_counts SET count = count+1 WHERE url = NEW.url;
      ELSE
        INSERT INTO url_counts (url, count) VALUES (NEW.url, 1);
      END IF;
    END IF;
  END
              Timing: AFTER
             Created: NULL
            sql_mode:
             Definer: root@localhost
character_set_client: utf8
collation_connection: utf8_general_ci
  Database Collation: utf8_general_ci
*************************** 3. row ***************************
             Trigger: after_delete_count
               Event: DELETE
               Table: entries
           Statement: BEGIN

    IF OLD.ip IS NOT NULL THEN


      UPDATE ip_counts SET count = count-1 WHERE ip = OLD.ip;
    END IF;
    IF OLD.domain IS NOT NULL THEN
      UPDATE domain_counts SET count = count-1 WHERE domain = OLD.domain;
    END IF;
    IF OLD.url IS NOT NULL THEN
      UPDATE url_counts SET count = count-1 WHERE url = OLD.url;
    END IF;
  END
              Timing: AFTER
             Created: NULL
            sql_mode:
             Definer: root@localhost
character_set_client: utf8
collation_connection: utf8_general_ci
  Database Collation: utf8_general_ci
3 rows in set (0.00 sec)

Do you have any foreign key constraints in your table? Please post output of `SHOW CREATE TABLE entries`. — piotrm, Jan 22 '12 at 05:08
@piotrm updated my question with `show create table entries` output. Thanks for showing interest! — TJ Koblentz, Jan 22 '12 at 05:19
Yes, I have triggers -- that could be it! Maybe I could try to disable them while I run these updates? I'm pasting them right now... (ps: thanks for sticking around, if I figure this out with your help, make sure to post an answer so you can get credit!) — TJ Koblentz, Jan 22 '12 at 05:36
I'll try to follow this suggestion http://stackoverflow.com/questions/6480074/mysql-disable-all-triggers and let you know how it goes. — TJ Koblentz, Jan 22 '12 at 05:41
Well I'm confused about the math... and if you want to chip in on a possibly smart trigger methodology, I'd be glad to hear it. But, regarding my original question -- you solved it. After removing the triggers, everything went better than expected. Thanks so much! Post some answer so I can mark this question as solved -- maybe it'll help someone in the future (and I'd like you to get the credit for it). Cheers! — TJ Koblentz, Jan 22 '12 at 05:50

score 2 · Accepted Answer · answered Jan 22 '12 at 06:39

When using update, insert or delete statements triggers can be responsive for extremely long query execution times and surprisingly high Rows_examined count in the slow_query_log file.

To see all triggers for a table use:

SHOW TRIGGERS WHERE `table`='tblName'

Mysql has to run every statement in the trigger block usually affecting other tables, so Rows_examined can be just anything, not necessarily related to row count of updated table.

In your case there is a trigger called for every row affected in the update that checks whether some fields are NOT NULL which doesn't mean they are being actually changed but just checks if there is a non-null value for that column in a given row that qualifies for update.

MySQL slow_query_log reporting more Rows_examined than rows in table (no joins)

1 Answers1