Hi Georgi,
On 3/6/09 12:30 PM, Georgi Kodinov wrote:
> #At file:///home/kgeorge/mysql/work/B38217-5.1-bugteam/ based on
> revid:kristofer.pettersson@stripped
>
> 2829 Georgi Kodinov 2009-03-06
> Bug #22047: Time in SHOW PROCESSLIST for SQL thread in replication seems to
> become negative
>
> THD::start_time has a dual meaning : it's either the time since the process
> entered a given state or is the transaction time returned by e.g. NOW().
> This causes problems, as sometimes THD::start_time may be set to a value
> that is correct and needed when used as a base for NOW(), but these times
> may be arbitrary (SET @@timestamp) or non-local (coming from the master
> through the replication feed).
[..]
Hum, documentation says that:
"Time - The time in seconds that the thread has been in its current state.".
This doesn't seem to match what is implemented in the server, but let's
focus on behavior for the SQL thread. In the manual we have:
"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."
So it is quite possible that Time will negative if the timestamp of the
last replicated event is ahead of the local time of the slave.
Furthermore in the documentation:
"You can use this to determine the date of the last replicated event.
Note that if your slave has been disconnected from the master for one
hour, and then reconnects, you may immediately see Time values like 3600
for the slave SQL thread in SHOW PROCESSLIST."
Since the Time is calculated as (slave local time - timestamp), a
negative time value indicates that the time on the slave is in the past
when compared to the clock of the master -- can be reproduced by
disconnecting a slave, delaying the clock and reconnecting.
OK, so i think by now we have established that it is okay for Time to be
negative for the SQL thread. So, what is the bug?
I think it is the fact that the processlist routines are not aware that
Time might be negative in some cases:
protocol->store((uint32) (now - thd_info->start_time));
table->field[5]->store((uint32)(tmp->start_time ?
now - tmp->start_time : 0), TRUE);
I think those casts are wrong even in the non SQL thread case as time
might be adjusted at random. What do you think?
Regards,
-- Davi Arnaut
