Details
-
Bug
-
Status: Closed (View Workflow)
-
Minor
-
Resolution: Fixed
-
10.0.4, 5.5.33a
-
None
-
Debian Wheezy amd64
MariaDB 5.5.32 official binary (not the Debian packaged version)
Description
In the INFORMATION_SCHEMA.PROCESSLIST table, the Time column reports the actual UNIX timestamp for new connections instead of a NULL value like the SHOW PROCESSLIST (or a duration) like it should.
Examples from a server having an important number or connections/seconds :
user@host:~# /bin/mksh -c 'i=0; while ((i < 200)); do BUG="$(mysql -Ne "SELECT * FROM INFORMATION_SCHEMA.PROCESSLIST WHERE USER like \"unauthen%\";")"; [[ -n "$BUG" ]] && print "I_S: $BUG" && print "SHOW: $(mysql -e "SHOW FULL PROCESSLIST;" |grep unau)\nTIMESTAMP: $(date +%s)\n"; sleep .05; ((i++)); done'
|
I_S: 788377361 unauthenticated user 192.168.49.162:38772 NULL Connect 1380896552 Reading from net NULL 1380896552152.118 0 0 0.000
|
788377355 unauthenticated user 192.168.39.123:48828 NULL Connect 1380896552 Reading from net NULL 1380896552152.118 0 0 0.000
|
SHOW: 788377355 unauthenticated user 192.168.39.123:48828 NULL Connect NULL Reading from net NULL 0.000
|
788377367 unauthenticated user 192.168.38.143:56011 NULL Connect NULL Reading from net NULL 0.000
|
788377368 unauthenticated user 192.168.35.174:38835 NULL Connect NULL Reading from net NULL 0.000
|
TIMESTAMP: 1380896552
|
|
|
I_S: 788414352 unauthenticated user connecting host NULL Connect 1380896751 login NULL 1380896751439.210 0 0 0.000
|
SHOW: 788414355 unauthenticated user connecting host NULL Connect NULL login NULL 0.000
|
TIMESTAMP: 1380896751
|
|
|
I_S: 788490446 unauthenticated user 192.168.39.24:46534 NULL Connect 1380897163 Reading from net NULL 1380897163496.970 0 0 0.000
|
SHOW: 788490447 unauthenticated user connecting host NULL Connect NULL login NULL 0.000
|
TIMESTAMP: 1380897163
|
|
|
I_S: 788490911 unauthenticated user 192.168.40.201:55249 NULL Connect 1380897165 Reading from net NULL 1380897165571.172 0 0 0.000
|
SHOW: 788490918 unauthenticated user 192.168.48.247:55195 NULL Connect NULL Reading from net NULL 0.000
|
TIMESTAMP: 1380897165
|
We can see that the Time column on I_S (as well as the Time_MS column) always reports the actual timestamp and not a duration (or a NULL value like the SHOW PROCESSLIST does) as it should.
ps: MySQL 5.5.30 and 5.5.28 doesnt seems to have this bug (they return 0 as the Time value on I_S.PROCESSLIST for these connecting threads).
I can easily reproduce it with a concurrent test, but haven't found an easy way to create a deterministic test case with sync points because the scenario requires a new connection where I can't set debug_sync.
However, the reason seems to be more or less clear. Here is the patch for
MDEV-4578:=== modified file 'sql/sql_show.cc'
— sql/sql_show.cc 2013-06-13 18:18:40 +0000
+++ sql/sql_show.cc 2013-06-13 18:19:32 +0000
@@ -2355,9 +2357,8 @@
table->field[4]->store(command_name[tmp->command].str,
command_name[tmp->command].length, cs);
/* MYSQL_TIME */
+ ulonglong start_utime= tmp->start_time * HRTIME_RESOLUTION + tmp->start_time_sec_part;
+ ulonglong utime= start_utime < unow.val ? unow.val - start_utime : 0;
table->field[5]->store(utime / HRTIME_RESOLUTION, TRUE);
/* STATE */
if ((val= thread_state_info(tmp)))
Earlier if tmp->start_time was 0 (which happens to be when a new connection is connecting) we would set utime to 0 as well. Now we don't check for that anymore, so utime ends up being set to unow.
Please let me know if you need the concurrent test.