Bug #13769 Innodb 'Table was not locked with LOCK TABLES', LOCK TABLES not used
Submitted: 5 Oct 2005 11:28 Modified: 13 Oct 2005 15:00
Reporter: Alexander Y. Fomichev Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:4.1.14 (-bk) OS:Linux (Gentoo 1.6.13 [ AMD64])
Assigned to: CPU Architecture:Any

[5 Oct 2005 11:28] Alexander Y. Fomichev
Description:
G'day,

After last upgrade MySQL from 4.1.13 to 4.1.14 on dual-opteron  server ( used as replication slave ) Slave_SQL thread sporadicaly hits error like:
Error 'Table 'product' was not locked with LOCK TABLES' on query. Default database: 'shop_ro'. Query: 'UPDATE product SET code='DF-PM-M3430S' WHERE product_id='735730'', Error_code: 1100
I couldn't see any regularity of this issue (as of table(s) size, structure etc. ) except for it olways occur on innodb table and a query is a part of long sequence of queries the same type [AUTOCOMMIT=1]. As i can see, no other threads use 'not locked' table at the time and no explicit 'LOCK TABLE' used before. And yes, seems like AMD64 is only affected, anyhow i haven't seen error like this on Intel PIII ( another replication slave ).
I've try last mysql-4.1.15 2005-10-04-bk source but seems like it affected too, i've got the same error this morning. 

Related info:

>Release:       mysql-4.1.15 (Source distribution)
>Server: /usr/bin/mysqladmin  Ver 8.41 Distrib 4.1.15, for pc-linux-gnu on x86_64
Copyright (C) 2000 MySQL AB & MySQL Finland AB & TCX DataKonsult AB
This software comes with ABSOLUTELY NO WARRANTY. This is free software,
and you are welcome to modify and redistribute it under the GPL license

Server version          4.1.15-log
Protocol version        10
Connection              Localhost via UNIX socket
UNIX socket             /var/run/mysqld/mysqld.sock
Uptime:                 22 hours 56 min 43 sec

Threads: 14  Questions: 27694269  Slow queries: 2130  Opens: 802  Flush tables: 1  Open tables: 700  Queries per second avg: 335.270
>C compiler:    gcc (GCC) 3.4.4 (Gentoo 3.4.4-r1, ssp-3.4.4-1.0, pie-8.7.8)
>C++ compiler:  gcc (GCC) 3.4.4 (Gentoo 3.4.4-r1, ssp-3.4.4-1.0, pie-8.7.8)
>Environment:
        <machine, os, target, libraries (multiple lines)>
System: Linux lights.vh.com.ru 2.6.11.12 #1 SMP Fri Jun 17 20:51:55 MSD 2005 x86_64 AMD Opteron(tm) Processor 246 AuthenticAMD GNU/Linux
Architecture: x86_64

Some paths:  /usr/bin/perl /usr/bin/make /usr/bin/gmake /usr/bin/gcc /usr/bin/cc
GCC: Reading specs from /usr/lib/gcc/x86_64-pc-linux-gnu/3.4.4/specs
Configured with: /var/tmp/portage/gcc-3.4.4-r1/work/gcc-3.4.4/configure --prefix=/usr --bindir=/usr/x86_64-pc-linux-gnu/gcc-bin/3.4.4 --includedir=/usr/lib/gcc/x86_64-pc-linux-gnu/3.4.4/include --datadir=/usr/share/gcc-data/x86_64-pc-linux-gnu/3.4.4 --mandir=/usr/share/gcc-data/x86_64-pc-linux-gnu/3.4.4/man --infodir=/usr/share/gcc-data/x86_64-pc-linux-gnu/3.4.4/info --with-gxx-include-dir=/usr/lib/gcc/x86_64-pc-linux-gnu/3.4.4/include/g++-v3 --host=x86_64-pc-linux-gnu --build=x86_64-pc-linux-gnu --disable-altivec --enable-nls --without-included-gettext
--with-system-zlib --disable-checking --disable-werror --disable-libunwind-exceptions --enable-multilib --disable-libgcj --enable-languages=c,c++ --enable-shared --enable-threads=posix --enable-__cxa_atexit --enable-clocale=gnu
Thread model: posix
gcc version 3.4.4 (Gentoo 3.4.4-r1, ssp-3.4.4-1.0, pie-8.7.8)
Compilation info: CC='gcc'  CFLAGS='-march=opteron -mtune=opteron -O4 -pipe -D_GNU_SOURCE -DHAVE_ERRNO_AS_DEFINE=1'  CXX='gcc'  CXXFLAGS='-march=opteron -mtune=opteron -O4 -pipe -D_GNU_SOURCE -felide-constructors -fno-exceptions -fno-rtti -DUSE_MYSYS_NEW'  LDFLAGS=''  ASFLAGS=''
LIBC:
lrwxrwxrwx  1 root root 13 Sep  5 19:21 /lib/libc.so.6 -> libc-2.3.5.so
-rwxr-xr-x  1 root root 1255872 Sep  5 19:20 /lib/libc-2.3.5.so
-rw-r--r--  1 root root 4042384 Sep  5 19:20 /usr/lib/libc.a
-rwxr-xr-x  1 root root 210 Sep  5 19:20 /usr/lib/libc.so
Configure command: ./configure '--prefix=/usr' '--libdir=/usr/lib' '--exec-prefix=/usr' '--datadir=/usr/share' '--libexecdir=/usr/sbin' '--sysconfdir=/etc' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--includedir=/usr/include' '--localstatedir=/var/lib/mysql' '--enable-assembler' '--with-mysql-user=mysql' '--with-innodb' '--with-ndbcluster' '--with-unix-socket-path=/var/run/mysqld/mysqld.sock' '--with-charset=cp1251' '--with-extra-charsets=latin1,koi8r,cp1251,utf8' '--with-openssl' '--without-readline' '--without-libedit' '--enable-thread-safe-client' '--with-named-thread-libs=-lpthread' '--build=x86_64-pc-linux-gnu' 'CFLAGS=-march=opteron -mtune=opteron -O4 -pipe -D_GNU_SOURCE -DHAVE_ERRNO_AS_DEFINE=1' 'CXXFLAGS=-march=opteron -mtune=opteron -O4 -pipe -D_GNU_SOURCE -felide-constructors -fno-exceptions -fno-rtti -DUSE_MYSYS_NEW' 'CXX=gcc' 'build_alias=x86_64-pc-linux-gnu'

How to repeat:
Hmm... couldn't repeat: sporadic error
[5 Oct 2005 12:07] Valeriy Kravchuk
Please, check and, possibly, upgrade your glibc version. See http://bugs.mysql.com/bug.php?id=8555  and http://bugs.mysql.com/bug.php?id=13737 (final comments) for details. 

Inform about any results (have you upgraded or not needed, if upgraded, then does it really help in your case).
[5 Oct 2005 13:40] Alexander Y. Fomichev
Hmm.. this issue is not looks like a kernel thread (dead)lock one ( related to glibc or not ), i don't see any kernel problem i.g. locked thread, SIG* in dmesg or something else, mysqld stop and start perfectly, no locked process/threads, replication could be restarted by trivial 'SLAVE START' without any after-effects [ sorry, i really forgot to mention about it ].
Now i use glibc-2.3.5-r1 - latest stable glibc version (as of gentoo ). And yes, previous mysql-4.1.13 works fine with this glibc version during two weeks or so ( and some months before -- with 2.3.5 ). Unlikely but it could still be compile time issue, so i'll degarde to 4.1.13 to see if it solve again.
[5 Oct 2005 14:45] Valeriy Kravchuk
OK, I was just curious, because it was a reson of some weird bugs on 64-bit Linuxes...

Please, inform about the NPTL version used (the results of getconf GNU_LIBPTHREAD_VERSION command), just to know. Any suggestions on how to repeat the described behaviour with a reasonable test case are also welcomed.
[5 Oct 2005 16:00] Alexander Y. Fomichev
lights ~ # getconf GNU_LIBPTHREAD_VERSION
NPTL 2.3.5
Hmm... i don't now just for now how this behaviour can be reproduced, actually this is only dual AMD64 host i have && this is production server. I've some of EM64T nocona, unlikely it will be too useful in this case ( seems like have to do with some type of race ) but i'll try use one as a test platform.
[12 Oct 2005 14:52] Valeriy Kravchuk
So, have you tested on your EM64T nocona and what were the results? 

You already written about that, but just to be sure, please, provide the usual statements used in a sequence (UPDATE?) and structures of tables used (SHOW CREATE TABLE product etc.)
[13 Oct 2005 12:45] Alexander Y. Fomichev
EM64T test shows no any locking problem, so i guess it is amd64 related [ or even worse - my_own_host related ] problem, downgrade to 4.1.13 on AMD64 under the same conditions shows loking issue too, so seems like it is a not mysql problem, sorry for wasting your time.

Just to clarify:
I've try to use previous gcc-3.4.3 to examine probability of compile time issue and yes, i haven't seen any problem until yesterday when i've got again: 
051012 20:05:45 [ERROR] Slave: Error 'Table 'product_document' was not locked with LOCK TABLES' on query. Default database: 'shop_ro'. Query: 'REPLACE INTO product_document (
                                                        file_name,
                                                        document_name,
                                                        mb_pid,
                                                        document_type,
                                                        lang)
                                                VALUES (
                                                        '15520.jpg',
                                                        '15520.jpg',
                                                        5294801,
                                                        'img_reg',
                                                        'ru')', Error_code: 1100

As of queries an tables structure:
All of queries executed in AUTOCOMMIT=1 mode [ while most of queries on this server explicitly use BEGIN/COMMIT transaction]
___________________________________________

UPDATE product SET code='DF-PM-M3430S' WHERE product_id='735730'

replace product_ext_data set origname='Gigabyte',restriction='<F2><E5><F5><ED><E8><F7><E5><F1><EA><E0><FF> <F3><EF><E0><EA><EE><E2><EA>
<E0>',hardware='128-<E1><E8><F2>.',awards='2048 x 1536',series='DDR SDRAM',spec_delivery='128 <CC><C1>',ISBN='<E4><E0>',design='<ED><E5><F2>', product_id = '716077', lang = 'ru'

UPDATE product
                                                SET product_type_id = 68
                                                WHERE mb_pid = 5258109

REPLACE INTO product_document (
                                                        file_name,
                                                        document_name,
                                                        mb_pid,
                                                        document_type,
                                                        lang)
                                                VALUES (
                                                        '160019.jpg',
                                                        '160019.jpg',
                                                        5295740,
                                                        'img_reg',
                                                        'ru')

CREATE TABLE `product` (
  `rep_mod` timestamp NOT NULL default CURRENT_TIMESTAMP on update CURRENT_TIMESTAMP,
  `product_id` int(11) NOT NULL auto_increment,
  `code` varchar(32) NOT NULL default '',
  `manufacturer_id` int(11) NOT NULL default '0',
  `sname` varchar(250) NOT NULL default '',
  `name` varchar(250) default NULL,
  `measure` varchar(10) default NULL,
  `weight` float default NULL,
  `_recommended_price` float(10,4) NOT NULL default '0.0000',
  `mancode` varchar(20) default NULL,
  `mb_pid` int(11) NOT NULL default '0',
  `em_pid` int(11) default '0',
  `desc_flag` int(1) NOT NULL default '0',
  `image_ext` varchar(255) default NULL,
  `img_s` varchar(50) NOT NULL default '',
  `_avg_price` float(10,2) default NULL,
  `product_type_id` int(11) NOT NULL default '0',
  `bolero_pid` int(11) NOT NULL default '0',
  `country_id` int(11) NOT NULL default '0',
  `emx_update` int(8) NOT NULL default '31',
  `authorized_delivery` int(1) NOT NULL default '0',
  `disabled_payment_ids` varchar(200) NOT NULL default '',
  `disabled_delivery_type_ids` varchar(200) NOT NULL default '',
  `is_comparable` tinyint(1) NOT NULL default '0',
  PRIMARY KEY  (`product_id`),
  KEY `code` (`code`),
  KEY `manufacturer_id` (`manufacturer_id`),
  KEY `name` (`name`),
  KEY `em_pid` (`em_pid`),
  KEY `mb_pid` (`mb_pid`),
  KEY `mancode` (`mancode`),
  KEY `desc_flag` (`desc_flag`),
  KEY `bolero_pid` (`bolero_pid`),
  KEY `product_type_id` (`product_type_id`)
) ENGINE=InnoDB DEFAULT CHARSET=cp1251

CREATE TABLE `product_ext_data` (
  `product_id` int(11) NOT NULL default '0',
  `length` smallint(6) default NULL,
  `age_min` tinyint(4) default NULL,
  `age_max` tinyint(4) default NULL,
  `date` int(11) default NULL,
  `date2` int(11) default NULL,
  `volume` int(11) default NULL,
  `volumeall` int(11) default NULL,
  `zone` varchar(150) default NULL,
  `grade` varchar(150) default NULL,
  `compl` varchar(150) default NULL,
  `ISBN` varchar(150) default NULL,
  `size` varchar(150) default NULL,
  `screensize` varchar(150) default NULL,
  `format` varchar(150) default NULL,
  `lang1` varchar(150) default NULL,
  `lang2` varchar(150) default NULL,
  `version` varchar(150) default NULL,
  `pack` varchar(150) default NULL,
  `sound` varchar(150) default NULL,
  `pics` varchar(150) default NULL,
  `series` varchar(150) default NULL,
  `awards` varchar(150) default NULL,
  `hardware` varchar(255) default NULL,
  `restriction` varchar(150) default NULL,
  `origname` varchar(200) default NULL,
  `pages` int(11) default NULL,
  `tracks` text,
  `key_vars` text,
  `design` varchar(255) default NULL,
  `spec_delivery` varchar(255) default NULL,
  `lang` char(2) NOT NULL default 'ru',
  PRIMARY KEY  (`product_id`,`lang`),
  KEY `date` (`date`),
  KEY `compl` (`compl`(40)),
  KEY `series` (`series`(100)),
  KEY `ISBN` (`ISBN`)
) ENGINE=InnoDB DEFAULT CHARSET=cp1251

CREATE TABLE `product_document` (
  `file_name` varchar(255) NOT NULL default '',
  `document_name` varchar(255) default NULL,
  `mb_pid` int(11) NOT NULL default '0',
  `document_type` varchar(50) NOT NULL default '',
  `lang` enum('ru','en') NOT NULL default 'ru',
  `ctime` timestamp NOT NULL default CURRENT_TIMESTAMP on update CURRENT_TIMESTAMP,
  PRIMARY KEY  (`mb_pid`,`document_type`,`file_name`),
  KEY `prod_doc_type` (`document_type`),
  KEY `mb_pid` (`mb_pid`)
) ENGINE=InnoDB DEFAULT CHARSET=cp1251
[13 Oct 2005 13:16] Valeriy Kravchuk
So, what is the current status of this report, from your point of view? Should we try to create a repetable test case on AMD64 any more, or I can just close it, based on your last comment?

Please, clarify.
[13 Oct 2005 13:38] Alexander Y. Fomichev
Change status to 'Not a bug', pls