| Bug #23666 | strange Innodb_row_lock_time_% values in show status; also millisecs wrong | ||
|---|---|---|---|
| Submitted: | 26 Oct 2006 14:24 | Modified: | 20 Jun 2010 1:13 |
| Reporter: | Shane Bester (Platinum Quality Contributor) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
| Version: | mysql-noinstall-5.0.21-winx64 | OS: | Windows (win-x64) |
| Assigned to: | Sunny Bains | CPU Architecture: | Any |
| Tags: | innodb, innodb_row_lock_time, Innodb_row_lock_time_avg, Innodb_row_lock_time_max, STATUS | ||
[26 Oct 2006 14:24]
Shane Bester
[26 Oct 2006 14:25]
MySQL Verification Team
innodb status
Attachment: bug_note.txt (plain/text, text), 6.01 KiB.
[26 Oct 2006 21:30]
MySQL Verification Team
Happened on 5.0.26 on win-x64 too. This isn't available for download afaik, but I'll try come up with a testcase soon. Could be after ' Deadlock found when trying to get lock; try restarting transaction: create temporary ta..' error is seen. I haven't tried on other platforms yet either. | Innodb_row_lock_time | 18446744073709546617 | | Innodb_row_lock_time_avg | 50528968 | | Innodb_row_lock_time_max | 3133602239 | | Innodb_row_lock_waits | 85 | | Innodb_rows_deleted | 18590 | | Innodb_rows_inserted | 100001 | | Innodb_rows_read | 4549662 | | Innodb_rows_updated | 54 | +-----------------------------------+----------------------+ 44 rows in set (0.01 sec)
[15 Nov 2006 19:22]
Heikki Tuuri
Hmm... might be a 64-bit/32-bit variable mismatch.
[21 Nov 2006 15:32]
Heikki Tuuri
The bug is that ut_usectime() in ut0ut.c has a wrong definition on Windows.
The bug manifests best on a 64-bit Windows, because there a ulint is 64-bit, and a negative value of diff_time in the code snippet below causes the sum counter srv_n_lock_wait_time to get a wildly wrong value.
Furthermore, in the calculation of the export_vars, we divide by 10000, while we should divide by 1000 to get milliseconds, as stated in the manual!
ut0ut.c in 5.0:
/**************************************************************
Returns system time. */
void
ut_usectime(
/*========*/
ulint* sec, /* out: seconds since the Epoch */
ulint* ms) /* out: microseconds since the Epoch+*sec */
{
#ifdef __WIN__
SYSTEMTIME st;
GetLocalTime(&st);
*sec = (ulint) st.wSecond;
*ms = (ulint) st.wMilliseconds;
#else
struct timeval tv;
gettimeofday(&tv,NULL);
*sec = (ulint) tv.tv_sec;
*ms = (ulint) tv.tv_usec;
#endif
}
Microsoft website:
typedef struct _SYSTEMTIME { WORD wYear; WORD wMonth; WORD wDayOfWeek; WORD wDay; WORD wHour; WORD wMinute; WORD wSecond; WORD wMilliseconds;
} SYSTEMTIME, *PSYSTEMTIME;
srv0srv.c in 5.0:
if (thr->lock_state == QUE_THR_LOCK_ROW) {
ut_usectime(&sec, &ms);
finish_time = (ib_longlong)sec * 1000000 + ms;
diff_time = (ulint) (finish_time - start_time);
srv_n_lock_wait_current_count--;
srv_n_lock_wait_time = srv_n_lock_wait_time + diff_time;
if (diff_time > srv_n_lock_max_wait_time) {
srv_n_lock_max_wait_time = diff_time;
}
}
...
export_vars.innodb_row_lock_current_waits= srv_n_lock_wait_current_coun\
t;
export_vars.innodb_row_lock_time= srv_n_lock_wait_time / 10000;
if (srv_n_lock_wait_count > 0) {
export_vars.innodb_row_lock_time_avg = (ulint)
(srv_n_lock_wait_time / 10000 / srv_n_lock_wait_count);
} else {
export_vars.innodb_row_lock_time_avg = 0;
}
export_vars.innodb_row_lock_time_max= srv_n_lock_max_wait_time / 10000;
[21 Nov 2006 15:44]
Heikki Tuuri
Assigning this little bug to Marko. Use GetSystemTimeAsFileTime() as the replacement of getttimeofday() on Windows: http://msdn.microsoft.com/library/default.asp?url=/library/en-us/sysinfo/base/getsystemtim... Regards, Heikki
[3 Jan 2007 13:49]
Heikki Tuuri
Assigning this little bug to Sunny.
[6 Apr 2007 17:21]
Bugs System
Pushed into 5.0.40
[6 Apr 2007 17:23]
Bugs System
Pushed into 5.1.18-beta
[11 Apr 2007 2:37]
Paul DuBois
Noted in 5.0.40, 5.1.18 changelogs. The values displayed for the Innodb_row_lock_time, Innodb_row_lock_time_avg, and Innodb_row_lock_time_max status variables were incorrect.
[5 May 2010 15:11]
Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[6 May 2010 2:31]
Paul DuBois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug. Re-closing.
[28 May 2010 5:48]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)
[28 May 2010 6:18]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[28 May 2010 6:45]
Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[29 May 2010 23:15]
Paul DuBois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug. Re-closing.
[17 Jun 2010 11:49]
Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:26]
Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:14]
Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
