Very large values for Rows_read in slow log

[Alexey Sapunov]

version 5.1.54-rel12.5-log

# Time: 110222 11:39:14
# User@Host: test[test] @ test[xxx.xxx.xxx.xxx]
# Thread_id: 2337843 Schema: test Last_errno: 0 Killed: 0
# Query_time: 246.073040 Lock_time: 0.001541 Rows_sent: 0 Rows_examined: 564770 Rows_affected: 0 Rows_read: 18446744073709551613
# Bytes_sent: 51 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0
# No InnoDB statistics available for this query
SET timestamp=1298363954;
CREATE TEMPORARY TABLE tmp_p_search_result (
            d_id INT UNSIGNED NOT NULL,
            PRIMARY KEY(d_id)
        ) AS
        SELECT
            d.d_id
        FROM
            ds_d_h d, d_v_h a
        WHERE
            d.p_id = 9025
            AND a.id = d.adv_id
            AND (a.br_id = 478193);

[Stewart Smith (stewart)]

It would be great to have a .test case for this.

[Stewart Smith (stewart)]

Marking as confirmed as Devananda has also observed. Would like a test case for it though.

[Curtis Wood (curtis-wood)]

We are running into this as well, and unfortunately it's wide spread. We are running the latest non-commercial version of Percona, and with 2000+ servers fleet wide it's effecting maybe 43% of them. No issues in the error logs. When this occurs the query hangs anywhere from 4 seconds to 5+ minutes.

# Time: 120612 10:44:08
# User@Host: xxxxxxxxx[xxxxxxxxxxxx] @ localhost []
# Thread_id: 66 Schema: xxxxxxxxxx Last_errno: 0 Killed: 0
# Query_time: 18.086745 Lock_time: 0.082408 Rows_sent: 13 Rows_examined: 13 Rows_affected: 0 Rows_read: 18446744073709551599
# Bytes_sent: 478 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# InnoDB_trx_id: 11AD200
use xxxxxxxxx;
SET timestamp=1339515848;
SELECT product_family_name, product_family_id FROM product_family;

root@xxxxxxxxxxxx [~]# time echo "SELECT product_family_name, product_family_id FROM product_family;" | mysql xxxxxxxxx
product_family_name product_family_id
...
...
...

real 0m0.005s
user 0m0.000s
sys 0m0.004s

Percona-Server-shared-compat-5.5.23-rel25.3.240.rhel5
Percona-Server-devel-51-5.1.63-rel13.4.443.rhel5
Percona-Server-shared-51-5.1.63-rel13.4.443.rhel5
Percona-Server-client-51-5.1.63-rel13.4.443.rhel5
Percona-Server-server-51-5.1.63-rel13.4.443.rhel5

root@xxxxxxxxx [~]# egrep "Rows_read: 184467440737.*$" /var/log/slow-queries.log|sort -nk 3|head -10
# Query_time: 4.000177 Lock_time: 0.000067 Rows_sent: 10 Rows_examined: 693759 Rows_affected: 0 Rows_read: 18446744073709466200
# Query_time: 4.000248 Lock_time: 0.000078 Rows_sent: 10 Rows_examined: 724594 Rows_affected: 0 Rows_read: 18446744073709470657
# Query_time: 4.000331 Lock_time: 0.000074 Rows_sent: 10 Rows_examined: 650429 Rows_affected: 0 Rows_read: 18446744073709479235
# Query_time: 4.000542 Lock_time: 0.000074 Rows_sent: 10 Rows_examined: 724637 Rows_affected: 0 Rows_read: 18446744073709474391
# Query_time: 4.000932 Lock_time: 0.000096 Rows_sent: 10 Rows_examined: 645024 Rows_affected: 0 Rows_read: 18446744073709465318
# Query_time: 4.001047 Lock_time: 0.000069 Rows_sent: 10 Rows_examined: 752624 Rows_affected: 0 Rows_read: 18446744073709458732
# Query_time: 4.001127 Lock_time: 0.000100 Rows_sent: 10 Rows_examined: 716372 Rows_affected: 0 Rows_read: 18446744073709474195
# Query_time: 4.001382 Lock_time: 0.000104 Rows_sent: 10 Rows_examined: 638262 Rows_affected: 0 Rows_read: 18446744073709418615
# Query_time: 4.002043 Lock_time: 0.000078 Rows_sent: 10 Rows_examined: 706282 Rows_affected: 0 Rows_read: 18446744073709477621
# Query_time: 4.002342 Lock_time: 0.000068 Rows_sent: 10 Rows_examined: 595649 Rows_affected: 0 Rows_read: 18446744073709487038

root@xxxxxxxxx [~]# egrep "Rows_read: 184467440737.*$" /var/log/slow-queries.log|sort -nk 3|tail -10
# Query_time: 306.723568 Lock_time: 300.055669 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 18446744073709551577
# Query_time: 306.730633 Lock_time: 300.026453 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 18446744073709551577
# Query_time: 306.754312 Lock_time: 300.071788 Rows_sent: 0 Rows_examined: 2 Rows_affected: 2 Rows_read: 18446744073709551577
# Query_time: ...

[Alexey Kopytov (akopytov)]

It's a duplicate of bug #830286. Setting this one as a duplicate, because bug #830286 has a test case and a contributed patch.