[MDEV-4303] Enabling the InnoDB Lock Monitor with the standard InnoDB Plugin enabled does not log output to error log - JIRA

Details

Type: Bug
Status: Open
Priority: Minor
Resolution: Unresolved
Affects Version/s: 5.5.30, 5.5.40, 10.0.14
Fix Version/s: 10.0
Component/s: Platform Windows, Storage Engine - InnoDB
Labels:
None
Environment:
Windows

Description

If you are running MariaDB 5.5.30 (at least on Windows), you have enabled the "standard InnoDB Plugin" (i.e., not XtraDB+), and you enable the InnoDB Lock Monitor (i.e., CREATE TABLE innodb_lock_monitor (id int) ENGINE=InnoDB), extra lock information is printed when you invoke SHOW ENGINE INNODB STATUS, however, this information is not logged to the Error log at all now.

1. Start MariaDB 5.5.30 with the standard InnoDB Plugin enabled:

[mysqld]
ignore_builtin_innodb
plugin-load=innodb=ha_innodb.dll;innodb_trx=ha_innodb.dll;innodb_locks=ha_innodb.dll;innodb_lock_waits=ha_innodb.dll;innodb_cmp=ha_innodb.dll;innodb_cmp_reset=ha_innodb.dll;innodb_cmpmem=ha_innodb.dll;innodb_cmpmem_reset=ha_innodb.dll

2. SHOW ENGINE INNODB STATUS\G
3. CREATE TABLE innodb_lock_monitor (id int) ENGINE=InnoDB;
4. SHOW ENGINE INNODB STATUS\G
5. Compare the 2 SHOW ENGINE INNODB STATUS Outputs. You'll see the extra lock information is correctly in the 2nd output.
6. Examine the error log. You'll see no SHOW ENGINE INNODB STATUS is logged to the error log.

Gliffy Diagrams

Attachments

Activity

Ascending order - Click to sort in descending order

Hide

Permalink

Chris Calender added a comment - 2013-03-20 16:59 - edited

Test Case to generate something useful in the output:

Connection #1

create table t (id int) engine=innodb;
insert into t (id) values (1),(2),(3),(4),(5);
start transaction;
select * from t for update;

Connection #2

show engine innodb status\G
create table innodb_lock_monitor (id int) engine=innodb;
show engine innodb status\G
drop table innodb_lock_monitor;

Show

Chris Calender added a comment - 2013-03-20 16:59 - edited Test Case to generate something useful in the output: Connection #1 create table t (id int) engine=innodb; insert into t (id) values (1),(2),(3),(4),(5); start transaction; select * from t for update ; Connection #2 show engine innodb status\G create table innodb_lock_monitor (id int) engine=innodb; show engine innodb status\G drop table innodb_lock_monitor;

9 older comments

Hide

Permalink

Elena Stepanova added a comment - 2013-03-26 22:36 - edited

Stack trace of the file write when the same server / plugin are started manually:

12:35:02.8219504 AM	mysqld.exe	16824	WriteFile	C:\Program Files\MariaDB 5.5\data\HOME.err	SUCCESS	Offset: 87,384, Length: 3,448, Priority: Normal


0	fltmgr.sys	FltAcquirePushLockShared + 0x907	0xfffff88001394067	C:\Windows\system32\drivers\fltmgr.sys
1	fltmgr.sys	FltIsCallbackDataDirty + 0xa39	0xfffff88001395329	C:\Windows\system32\drivers\fltmgr.sys
2	fltmgr.sys	fltmgr.sys + 0x16c7	0xfffff880013936c7	C:\Windows\system32\drivers\fltmgr.sys
3	ntoskrnl.exe	NtCreateFile + 0x31f	0xfffff80003382e0b	C:\Windows\system32\ntoskrnl.exe
4	ntoskrnl.exe	NtWriteFile + 0x7e3	0xfffff8000338d803	C:\Windows\system32\ntoskrnl.exe
5	ntoskrnl.exe	KeSynchronizeExecution + 0x3a23	0xfffff80003075ed3	C:\Windows\system32\ntoskrnl.exe
6	ntdll.dll	ZwWriteFile + 0xa	0x76fb139a	C:\Windows\System32\ntdll.dll
7	KernelBase.dll	WriteFile + 0x7b	0x7fefc441b3b	C:\Windows\System32\KernelBase.dll
8	kernel32.dll	WriteFile + 0x36	0x76e63566	C:\Windows\System32\kernel32.dll
9	ha_innodb.dll	_write_nolock + 0x45d, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\write.c(324)	0x7fee9a081a1	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
10	ha_innodb.dll	_write + 0x8d, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\write.c(73)	0x7fee9a08531	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
11	ha_innodb.dll	_flush + 0x42, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\fflush.c(152)	0x7fee9a01456	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
12	ha_innodb.dll	_fflush_nolock + 0x1d, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\fflush.c(101)	0x7fee9a014ad	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
13	ha_innodb.dll	fflush + 0x2c, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\fflush.c(64)	0x7fee9a015f4	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
14	ha_innodb.dll	srv_printf_innodb_monitor + 0x461, c:\buildbot\winx64-packages\build\mariadb-5.5.30\storage\innobase\srv\srv0srv.c(2007)	0x7fee99e28b1	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
15	ha_innodb.dll	srv_monitor_thread + 0x124, c:\buildbot\winx64-packages\build\mariadb-5.5.30\storage\innobase\srv\srv0srv.c(2188)	0x7fee99e2d54	C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll
16	kernel32.dll	BaseThreadInitThunk + 0xd	0x76e5652d	C:\Windows\System32\kernel32.dll
17	ntdll.dll	RtlUserThreadStart + 0x21	0x76f8c521	C:\Windows\System32\ntdll.dll

Show

Elena Stepanova added a comment - 2013-03-26 22:36 - edited Stack trace of the file write when the same server / plugin are started manually: 12:35:02.8219504 AM mysqld.exe 16824 WriteFile C:\Program Files\MariaDB 5.5\data\HOME.err SUCCESS Offset: 87,384, Length: 3,448, Priority: Normal 0 fltmgr.sys FltAcquirePushLockShared + 0x907 0xfffff88001394067 C:\Windows\system32\drivers\fltmgr.sys 1 fltmgr.sys FltIsCallbackDataDirty + 0xa39 0xfffff88001395329 C:\Windows\system32\drivers\fltmgr.sys 2 fltmgr.sys fltmgr.sys + 0x16c7 0xfffff880013936c7 C:\Windows\system32\drivers\fltmgr.sys 3 ntoskrnl.exe NtCreateFile + 0x31f 0xfffff80003382e0b C:\Windows\system32\ntoskrnl.exe 4 ntoskrnl.exe NtWriteFile + 0x7e3 0xfffff8000338d803 C:\Windows\system32\ntoskrnl.exe 5 ntoskrnl.exe KeSynchronizeExecution + 0x3a23 0xfffff80003075ed3 C:\Windows\system32\ntoskrnl.exe 6 ntdll.dll ZwWriteFile + 0xa 0x76fb139a C:\Windows\System32\ntdll.dll 7 KernelBase.dll WriteFile + 0x7b 0x7fefc441b3b C:\Windows\System32\KernelBase.dll 8 kernel32.dll WriteFile + 0x36 0x76e63566 C:\Windows\System32\kernel32.dll 9 ha_innodb.dll _write_nolock + 0x45d, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\write.c(324) 0x7fee9a081a1 C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 10 ha_innodb.dll _write + 0x8d, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\write.c(73) 0x7fee9a08531 C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 11 ha_innodb.dll _flush + 0x42, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\fflush.c(152) 0x7fee9a01456 C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 12 ha_innodb.dll _fflush_nolock + 0x1d, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\fflush.c(101) 0x7fee9a014ad C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 13 ha_innodb.dll fflush + 0x2c, f:\dd\vctools\crt_bld\self_64_amd64\crt\src\fflush.c(64) 0x7fee9a015f4 C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 14 ha_innodb.dll srv_printf_innodb_monitor + 0x461, c:\buildbot\winx64-packages\build\mariadb-5.5.30\storage\innobase\srv\srv0srv.c(2007) 0x7fee99e28b1 C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 15 ha_innodb.dll srv_monitor_thread + 0x124, c:\buildbot\winx64-packages\build\mariadb-5.5.30\storage\innobase\srv\srv0srv.c(2188) 0x7fee99e2d54 C:\Program Files\MariaDB 5.5\lib\plugin\ha_innodb.dll 16 kernel32.dll BaseThreadInitThunk + 0xd 0x76e5652d C:\Windows\System32\kernel32.dll 17 ntdll.dll RtlUserThreadStart + 0x21 0x76f8c521 C:\Windows\System32\ntdll.dll

Hide

Permalink

Chris Calender added a comment - 2013-03-26 22:41 - edited

On a side note, I don't seem to see anything logged when I create just "innodb_monitor" (as opposed to "innodb_lock_monitor"). Please check this one as well (and any of those other innodb monitors - tables and tablespace), as it is working with XtraDB+ enabled.

Show

Chris Calender added a comment - 2013-03-26 22:41 - edited On a side note, I don't seem to see anything logged when I create just "innodb_monitor" (as opposed to "innodb_lock_monitor"). Please check this one as well (and any of those other innodb monitors - tables and tablespace), as it is working with XtraDB+ enabled.

Hide

Permalink

Elena Stepanova added a comment - 2013-03-26 23:22

Hi Chris,

You mean that you aren't getting anything either with innodb_lock_monitor or with innodb_monitor, right?
I didn't either, I tried it as well (but only when it's run as a service; in standalone mode it worked).

Show

Elena Stepanova added a comment - 2013-03-26 23:22 Hi Chris, You mean that you aren't getting anything either with innodb_lock_monitor or with innodb_monitor, right? I didn't either, I tried it as well (but only when it's run as a service; in standalone mode it worked).

Hide

Permalink

Chris Calender added a comment - 2013-03-26 23:35

Yes, that's correct.

Show

Chris Calender added a comment - 2013-03-26 23:35 Yes, that's correct.

Hide

Permalink

Elena Stepanova added a comment - 2014-10-20 18:03

Still reproducible with InnoDB plugin on 5.5 and 10.0 running as a service (on 10.0 – both with the deprecated table creation, and with innodb_status_output).

As said above, not reproducible with XtraDB.

But also not reproducible on MySQL 5.6.21, which probably means that the problem is not in InnoDB plugin as such, but in it being a plugin?..

I have a local VM where I can experiment in any mean and wild way, as long as I know what can help to investigate the problem.

Show

Elena Stepanova added a comment - 2014-10-20 18:03 Still reproducible with InnoDB plugin on 5.5 and 10.0 running as a service (on 10.0 – both with the deprecated table creation, and with innodb_status_output ). As said above, not reproducible with XtraDB. But also not reproducible on MySQL 5.6.21, which probably means that the problem is not in InnoDB plugin as such, but in it being a plugin?.. I have a local VM where I can experiment in any mean and wild way, as long as I know what can help to investigate the problem.

People

Assignee:

Sergei Golubchik

Reporter:

Chris Calender

Votes:

0 Vote for this issue

Watchers:

3 Start watching this issue

Dates

Created:

2013-03-19 23:51

Updated:

2014-10-20 18:03

Agile

View on Board