[MDEV-773] LP:611878 - user_statistics.busy_time is unreliable - JIRA

Details

Type: Bug
Status: Open
Priority: Minor
Resolution: Unresolved
Affects Version/s: 5.2.14
Fix Version/s: 5.3.13, 5.2.15, 5.5
Component/s: None
Labels:
- Launchpad
- user_statistics

Description

I was testing MariaDB 5.2.1-beta (on Debian 5.0), and bumped into the following weird behavior of user_statistics.busy_time: the value of this column seems completely unreliable and randomly increases at some points in time:

MariaDB [(none)]> SELECT CONNECTED_TIME,BUSY_TIME,CPU_TIME FROM information_schema.user_statistics WHERE USER='core_d7';
+----------------+------------------+------------------+
| CONNECTED_TIME | BUSY_TIME        | CPU_TIME         |
+----------------+------------------+------------------+
|           2887 | 36893488147880.9 | 237.741877899973 |

later...

|           2919 | 36893488147887.3 | 241.586389299972 |

later...

|           2921 | 36893488147888.2 | 242.004482199972 |

and now:

|           3144 | 55340232221635 | 268.829147599973 |

I don't have any additional information information at this point, just wanted to report the behavior in case it rings a bell for someone.

Gliffy Diagrams

Attachments

Options
- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

Attachments

LPexportBug611878.xml
9 kB
2012-10-03 11:32

Issue Links

relates to

MDEV-775 LP:1018694 - CPU_TIME counter from USER_STATISTICS gets wrong after some uptime

Open

MDEV-673 LP:706991 - incorrect Bytes_received in user_statistics table

Open

MDEV-4578 information_schema.processlist reports incorrect value for Time (2147483647)

Closed

Activity

Ascending order - Click to sort in descending order

Hide

Permalink

Kristian Nielsen added a comment - 2010-07-31 08:27

Re: user_statistics.busy_time is unreliable
I believe the reporter meant to say that MariaDB 5.2.1 beta was being tested.

Show

Kristian Nielsen added a comment - 2010-07-31 08:27 Re: user_statistics.busy_time is unreliable I believe the reporter meant to say that MariaDB 5. 2 .1 beta was being tested.

Hide

Permalink

Damien Tournoud added a comment - 2010-07-31 09:51

Re: user_statistics.busy_time is unreliable
Indeed, that was 5.2.1-beta (Debian 5.0 build).

Show

Damien Tournoud added a comment - 2010-07-31 09:51 Re: user_statistics.busy_time is unreliable Indeed, that was 5.2.1-beta (Debian 5.0 build).

Hide

Permalink

Damien Tournoud added a comment - 2010-08-05 09:42

Re: user_statistics.busy_time is unreliable
Anything I could do to help this go forward?

Show

Damien Tournoud added a comment - 2010-08-05 09:42 Re: user_statistics.busy_time is unreliable Anything I could do to help this go forward?

Hide

Permalink

Anton Khalikov added a comment - 2012-05-15 18:35

Re: user_statistics.busy_time is unreliable
I can confirm this bug. We collect user statistics and run "SELECT * FROM INFORMATION_SCHEMA.USER_STATISTICS; FLUSH USER_STATISTICS" every 5 minutes. This is what I've got just before the end of a 5 minute interval:

MariaDB [(none)]> select USER, TOTAL_CONNECTIONS, CPU_TIME, BYTES_RECEIVED, BYTES_SENT, ROWS_READ, ROWS_SENT, ROWS_DELETED, ROWS_INSERTED, ROWS_UPDATED, SELECT_COMMANDS, UPDATE_COMMANDS, OTHER_COMMANDS from INFORMATION_SCHEMA.USER_STATISTICS order by CPU_TIME desc limit 0,1\G

- - - - 1. row ***************************
        USER: u4740
        TOTAL_CONNECTIONS: 3311
        CPU_TIME: 168767.2010919
        BYTES_RECEIVED: 722875
        BYTES_SENT: 15747206
        ROWS_READ: 73910638
        ROWS_SENT: 13124
        ROWS_DELETED: 0
        ROWS_INSERTED: 5749
        ROWS_UPDATED: 2982
        SELECT_COMMANDS: 1466
        UPDATE_COMMANDS: 3360
        OTHER_COMMANDS: 3311
        1 row in set (0.00 sec)

and right after FLUSH again:

MariaDB [(none)]> select USER, TOTAL_CONNECTIONS, CPU_TIME, BYTES_RECEIVED, BYTES_SENT, ROWS_READ, ROWS_SENT, ROWS_DELETED, ROWS_INSERTED, ROWS_UPDATED, SELECT_COMMANDS, UPDATE_COMMANDS, OTHER_COMMANDS from INFORMATION_SCHEMA.USER_STATISTICS order by CPU_TIME desc limit 0,1\G

- - - - 1. row ***************************
        USER: u4740
        TOTAL_CONNECTIONS: 31
        CPU_TIME: 827.8829815
        BYTES_RECEIVED: 8945
        BYTES_SENT: 4590920
        ROWS_READ: 177196
        ROWS_SENT: 1709
        ROWS_DELETED: 0
        ROWS_INSERTED: 0
        ROWS_UPDATED: 27
        SELECT_COMMANDS: 7
        UPDATE_COMMANDS: 30
        OTHER_COMMANDS: 30
        1 row in set (0.00 sec)

So we see here CPU_TIME has been reset but increased to over 800 units within a couple of seconds. And it reached about 170000 units within 5 minutes. Either units are milliseconds or there is something really wrong.

Could anyone confirm ?

I use Debian 6 on amd64, MariaDB 5.2.12

Show

Anton Khalikov added a comment - 2012-05-15 18:35 Re: user_statistics.busy_time is unreliable I can confirm this bug. We collect user statistics and run "SELECT * FROM INFORMATION_SCHEMA.USER_STATISTICS; FLUSH USER_STATISTICS" every 5 minutes. This is what I've got just before the end of a 5 minute interval: MariaDB [(none)] > select USER, TOTAL_CONNECTIONS, CPU_TIME, BYTES_RECEIVED, BYTES_SENT, ROWS_READ, ROWS_SENT, ROWS_DELETED, ROWS_INSERTED, ROWS_UPDATED, SELECT_COMMANDS, UPDATE_COMMANDS, OTHER_COMMANDS from INFORMATION_SCHEMA.USER_STATISTICS order by CPU_TIME desc limit 0,1\G 1. row *************************** USER: u4740 TOTAL_CONNECTIONS: 3311 CPU_TIME: 168767.2010919 BYTES_RECEIVED: 722875 BYTES_SENT: 15747206 ROWS_READ: 73910638 ROWS_SENT: 13124 ROWS_DELETED: 0 ROWS_INSERTED: 5749 ROWS_UPDATED: 2982 SELECT_COMMANDS: 1466 UPDATE_COMMANDS: 3360 OTHER_COMMANDS: 3311 1 row in set (0.00 sec) and right after FLUSH again: MariaDB [(none)] > select USER, TOTAL_CONNECTIONS, CPU_TIME, BYTES_RECEIVED, BYTES_SENT, ROWS_READ, ROWS_SENT, ROWS_DELETED, ROWS_INSERTED, ROWS_UPDATED, SELECT_COMMANDS, UPDATE_COMMANDS, OTHER_COMMANDS from INFORMATION_SCHEMA.USER_STATISTICS order by CPU_TIME desc limit 0,1\G 1. row *************************** USER: u4740 TOTAL_CONNECTIONS: 31 CPU_TIME: 827.8829815 BYTES_RECEIVED: 8945 BYTES_SENT: 4590920 ROWS_READ: 177196 ROWS_SENT: 1709 ROWS_DELETED: 0 ROWS_INSERTED: 0 ROWS_UPDATED: 27 SELECT_COMMANDS: 7 UPDATE_COMMANDS: 30 OTHER_COMMANDS: 30 1 row in set (0.00 sec) So we see here CPU_TIME has been reset but increased to over 800 units within a couple of seconds. And it reached about 170000 units within 5 minutes. Either units are milliseconds or there is something really wrong. Could anyone confirm ? I use Debian 6 on amd64, MariaDB 5.2.12

Hide

Permalink

Rasmus Johansson added a comment - 2012-05-15 18:38

Launchpad bug id: 611878

Show

Rasmus Johansson added a comment - 2012-05-15 18:38 Launchpad bug id: 611878

Hide

Permalink

Elena Stepanova added a comment - 2012-11-04 02:33 - edited

See also MDEV-673, MDEV-775 and comments to it with LP bugs in Percona project. There have been and still are several bugs related to user_statistics, some of them fixed, some still open.

Show

Elena Stepanova added a comment - 2012-11-04 02:33 - edited See also MDEV-673 , MDEV-775 and comments to it with LP bugs in Percona project. There have been and still are several bugs related to user_statistics, some of them fixed, some still open.

LP:611878 - user_statistics.busy_time is unreliable

Details

Description

Gliffy Diagrams

Attachments

Attachments

Issue Links

Activity

People

Dates

Agile