MariaDB

user_statistics.busy_time is unreliable

Bug #611878 reported by Damien Tournoud
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MariaDB
New
Undecided
Unassigned
MariaDB 5.2

Bug 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.

See original description
Revision history for this message
Kristian Nielsen (knielsen) wrote :

I believe the reporter meant to say that MariaDB 5._2_.1 beta was being tested.

Revision history for this message
Damien Tournoud (damientournoud) wrote :

Indeed, that was 5.2.1-beta (Debian 5.0 build).

description: updated
Revision history for this message
Damien Tournoud (damientournoud) wrote :

Anything I could do to help this go forward?

Sergei Golubchik (sergii)
Changed in maria:
milestone: none → 5.2
Revision history for this message
Anton Khalikov (anton-khalikov) wrote :

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

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.