[Maria-developers] negative TIME in SHOW FULL PROCESSLIST and information_schema.processlist
Hi, While merging the Percona microsec_process patch (the 5.1 port of the patch is called acc-pslist), I encountered a problem related to Bug#22047: http://bugs.mysql.com/bug.php?id=22047 The issue is with the exact behaviour of the TIME column of SHOW FULL PROCESSLIST and information_schema.processlist. The documentation says (http://dev.mysql.com/doc/refman/5.1/en/show-processlist.html): Time The time in seconds that the thread has been in its current state. However, the TIME column is actually computed as <current local time> - @@TIMESTAMP This means that the value will differ from the documented value for threads that modify @@TIMESTAMP. In particular, it will differ for the replication thread. There is a replication FAQ, which says this: http://dev.mysql.com/doc/refman/5.1/en/replication-faq.html 16.3.4.3: How do I know how late a slave is compared to the master? You can read the Seconds_Behind_Master column in SHOW SLAVE STATUS. See Section 16.4.1,“Replication Implementation Details”. In the Time column in the output of SHOW PROCESSLIST, the number of seconds displayed for the slave SQL thread is the number of seconds between the timestamp of the last replicated event and the real time of the slave machine. You can use this to determine the date of the last replicated event. However, this does not take into account the possibility of time skew between master and slave. The actual value displayed in SHOW PROCESSLIST is <current time> - <time of original event> + <time skew> To me, this is just too complex to be really useful. On the other hand, Seconds_Behind_Master _does_ take into account the time skew, so it seems a much more useful metric to use to me. Frankly, to me this last part of the documentation sounds to me like trying to spin a bug as a feature. Now, the microsec_process patch adds a TIME_MS column, which works like TIME is documented, except with microsecond precision. This leaves three options to choose between: 1. Let TIME_MS also depend on @@TIMESTAMP. This is particularly ugly, as TIMESTAMP has seconds granularity, so rounding effects will be "interesting". I really don't like this idea. 2. Let TIME_MS be independent of @@TIMESTAMP; it will just be the time since last state change, with microseconds resolution. But keep currently implemented semantics of TIME. This means that TIME and TIME_MS will be unrelated for threads that change @@TIMESTAMP (like the slave thread). This will be confusing. 3. Change implementation of TIME so that both TIME and TIME_MS are independent of @@TIMESTAMP. Of these, I tend to prefer option 3. Reason is that the semantics is much cleaner and simple to understand. The functionality to see how much slave is behind is in any case better obtained using Seconds_Behind_Master. However, it does involve a change in behaviour, so I want to ask opinions if anyone thinks the change in behaviour would cause too much breakage? If so, I prefer to implement option 2. If not, I will go ahead with option 3. Thanks, - Kristian.
On Fri, Sep 18, 2009 at 1:55 PM, Kristian Nielsen <knielsen@knielsen-hq.org> wrote:
There is a replication FAQ, which says this:
http://dev.mysql.com/doc/refman/5.1/en/replication-faq.html
16.3.4.3: How do I know how late a slave is compared to the master?
You can read the Seconds_Behind_Master column in SHOW SLAVE STATUS. See Section 16.4.1,“Replication Implementation Details”.
In the Time column in the output of SHOW PROCESSLIST, the number of seconds displayed for the slave SQL thread is the number of seconds between the timestamp of the last replicated event and the real time of the slave machine. You can use this to determine the date of the last replicated event.
However, this does not take into account the possibility of time skew between master and slave. The actual value displayed in SHOW PROCESSLIST is
<current time> - <time of original event> + <time skew>
To me, this is just too complex to be really useful.
On the other hand, Seconds_Behind_Master _does_ take into account the time skew, so it seems a much more useful metric to use to me. Frankly, to me this last part of the documentation sounds to me like trying to spin a bug as a feature.
FWIW, 12 months ago I could still spot negative values, well really high values as I think it reports an unsigned int) in Seconds_Behind_Master. Never manually, but indeed with a script that was busy selecting the value. (The script would break when the value suddenly became "really high value".) This was after such behavior had been "fixed" at least 2 times. (Can't find the bug number now.) A bit off topic, but maybe relevant as background info.
Now, the microsec_process patch adds a TIME_MS column, which works like TIME is documented, except with microsecond precision. This leaves three options to choose between:
1. Let TIME_MS also depend on @@TIMESTAMP. This is particularly ugly, as TIMESTAMP has seconds granularity, so rounding effects will be "interesting". I really don't like this idea.
2. Let TIME_MS be independent of @@TIMESTAMP; it will just be the time since last state change, with microseconds resolution. But keep currently implemented semantics of TIME. This means that TIME and TIME_MS will be unrelated for threads that change @@TIMESTAMP (like the slave thread). This will be confusing.
3. Change implementation of TIME so that both TIME and TIME_MS are independent of @@TIMESTAMP.
Of these, I tend to prefer option 3.
Reason is that the semantics is much cleaner and simple to understand.
The functionality to see how much slave is behind is in any case better obtained using Seconds_Behind_Master.
However, it does involve a change in behaviour, so I want to ask opinions if anyone thinks the change in behaviour would cause too much breakage?
I'm the wrong person to answer, but seems to me we should at this stage prefer being bug-for-bug compatible and changing semantics between MariaDB and MySQL may turn out to be more of a problem than being helpful. (If we could agree with the MySQL team to adopt the fix in a future version, it would be different.) Btw, Monty is back home but still not on email / IRC. Call him if you want his opinion. henrik -- email: henrik.ingo@avoinelama.fi tel: +358-40-5697354 www: www.avoinelama.fi/~hingo book: www.openlife.cc
Henrik Ingo <henrik.ingo@avoinelama.fi> writes:
I'm the wrong person to answer, but seems to me we should at this stage prefer being bug-for-bug compatible and changing semantics between MariaDB and MySQL may turn out to be more of a problem than being helpful. (If we could agree with the MySQL team to adopt the fix in a future version, it would be different.)
Compatibility is a valid point, but we must also be very careful not to fall into the trap of not daring to do changes that make sense. So we need balance. If we stop fixing bugs or bad behaviour then I think we have made ourselves irrelevant. In this case, the problem is that we add another column. So we have two time columns, one in whole seconds (for compatibility) and one in fractional milliseconds. And I think it is really confusing if these two columns sometimes differ widely from each other. Hence the need for a carefully thought out decision. Thanks, - Kristian.
On Mon, Sep 21, 2009 at 2:23 PM, Kristian Nielsen <knielsen@knielsen-hq.org> wrote:
Henrik Ingo <henrik.ingo@avoinelama.fi> writes:
I'm the wrong person to answer, but seems to me we should at this
Just wanted to leave that quote :-) I re-read your original text and offer some other non-expert thoughts... Where else would @@TIMESTAMP be modified? Can a user do that from SQL? (If so, why???) If replication is the only reason for concern, then yes, Seconds_behind_master is what I was always using. henrik -- email: henrik.ingo@avoinelama.fi tel: +358-40-5697354 www: www.avoinelama.fi/~hingo book: www.openlife.cc
Henrik Ingo <henrik.ingo@avoinelama.fi> writes:
Where else would @@TIMESTAMP be modified? Can a user do that from SQL?
Yes (or @TIMESTAMP at least).. mysql> set TIMESTAMP=100; Query OK, 0 rows affected (0.00 sec) mysql> select now(); +---------------------+ | now() | +---------------------+ | 1970-01-01 01:01:40 | +---------------------+ 1 row in set (0.00 sec) mysql> show full processlist; +----+------+-----------+------+---------+------------+-------+-----------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------+------+---------+------------+-------+-----------------------+ | 15 | root | localhost | test | Query | 1253605187 | NULL | show full processlist | +----+------+-----------+------+---------+------------+-------+-----------------------+ 1 row in set (0.00 sec)
(If so, why???)
Loading mysqlbinlog output, testing, ... and confusing SHOW FULL PROCESSLIST :-) Thanks, - Kristian.
On Tue, Sep 22, 2009 at 10:42 AM, Kristian Nielsen <knielsen@knielsen-hq.org> wrote:
Henrik Ingo <henrik.ingo@avoinelama.fi> writes:
Where else would @@TIMESTAMP be modified? Can a user do that from SQL?
Yes (or @TIMESTAMP at least)..
mysql> set TIMESTAMP=100; Query OK, 0 rows affected (0.00 sec)
mysql> select now(); +---------------------+ | now() | +---------------------+ | 1970-01-01 01:01:40 | +---------------------+ 1 row in set (0.00 sec)
mysql> show full processlist; +----+------+-----------+------+---------+------------+-------+-----------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------+------+---------+------------+-------+-----------------------+ | 15 | root | localhost | test | Query | 1253605187 | NULL | show full processlist | +----+------+-----------+------+---------+------------+-------+-----------------------+ 1 row in set (0.00 sec)
(If so, why???)
Loading mysqlbinlog output, testing, ... and confusing SHOW FULL PROCESSLIST :-)
Ok, now I remember the point why you use it. (essentially, any re-inserting of old data where timestamp columns are involved.) So if you are arguing that SHOW FULL PROCESSLIST current behavior is a bug, then you might be right? henrik -- email: henrik.ingo@avoinelama.fi tel: +358-40-5697354 www: www.avoinelama.fi/~hingo book: www.openlife.cc
participants (2)
-
Henrik Ingo -
Kristian Nielsen