[MDEV-9621] Insert delayed bug Created: 2016-02-24  Updated: 2016-04-07  Resolved: 2016-04-07

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Insert
Affects Version/s: 10.1.9, 10.1.11
Fix Version/s: 10.1.14

Type: Bug Priority: Major
Reporter: Michael Van Der Beek Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None
Environment:

Centos 5 custom version.



 Description   

Hi All,
I am having a problem with insert delayed option with the above mariadb.
Its is returning weird errors.
The max_delayed_threads = 40
I am doing this on a test system. There are no other insert delayed into the queue.
So it cannot be a delayed thread queue problem. The error doesn't make sense even.
Sorry if this has been reported before. Not sure how to search for such a specific error.

The mariadb installed are:

# rpm -qa | grep Maria
MariaDB-shared-10.1.11-1
MariaDB-connect-engine-10.1.11-1
MariaDB-client-10.1.11-1
MariaDB-compat-10.1.11-1
MariaDB-common-10.1.11-1
MariaDB-server-10.1.11-1

I don't see this in mysql version I was using (5.1), haven't tried on later version.
The reason was am planning migration of the database so I am testing all commands individually. This command is from radius server doing a insert a session to the session table radacct. The values are not important, its just for testing of the command.
I am checking the performance of myisam vs innodb for this table. So I need to old way of inserting to do a proper comparing.

MariaDB [server1]> INSERT DELAYED INTO radacct             (acctsessionid,    acctuniqueid,     username,           groupname,              realm,            nasipaddress,     nasportid,              nasporttype,      acctstarttime,    acctstoptime,              acctsessiontime,  acctauthentic,    connectinfo_start,              connectinfo_stop, acctinputoctets,  acctoutputoctets,              calledstationid,  callingstationid, acctterminatecause,              servicetype,      framedprotocol,   framedipaddress,              acctstartdelay,   acctstopdelay,      acctupdatetime     )           VALUES ("aasda1","ascac","ascasc","assfa","reasas","ascac","123","asc",now(),now(),12312,"testa","123asc",10,10,"asca","ascasc","teast","ascasc","ascasc","aasca","teast",12312,123123,now());
Query OK, 1 row affected, 1 warning (0.00 sec)

MariaDB [server1]> INSERT DELAYED INTO radacct             (acctsessionid,    acctuniqueid,     username,           groupname,              realm,            nasipaddress,     nasportid,              nasporttype,      acctstarttime,    acctstoptime,              acctsessiontime,  acctauthentic,    connectinfo_start,              connectinfo_stop, acctinputoctets,  acctoutputoctets,              calledstationid,  callingstationid, acctterminatecause,              servicetype,      framedprotocol,   framedipaddress,              acctstartdelay,   acctstopdelay,      acctupdatetime     )           VALUES ("aasda1","ascac","ascasc","assfa","reasas","ascac","123","asc",now(),now(),12312,"testa","123asc",10,10,"asca","ascasc","teast","ascasc","ascasc","aasca","teast",12312,123123,now());
ERROR 1110 (42000): Column 'acctupdatetime' specified twice

Note the two delayed insert are identical.

The table structure is as follows:
CREATE TABLE `radacct` (
  `radacctid` bigint(20) NOT NULL AUTO_INCREMENT,
  `acctsessionid` varchar(64) NOT NULL DEFAULT '',
  `acctuniqueid` varchar(32) NOT NULL DEFAULT '',
  `username` varchar(64) NOT NULL DEFAULT '',
  `groupname` varchar(64) NOT NULL DEFAULT '',
  `realm` varchar(64) DEFAULT '',
  `nasipaddress` varchar(15) NOT NULL DEFAULT '',
  `nasportid` varchar(15) DEFAULT NULL,
  `nasporttype` varchar(32) DEFAULT NULL,
  `acctstarttime` datetime DEFAULT NULL,
  `acctstoptime` datetime DEFAULT NULL,
  `acctsessiontime` int(11) DEFAULT NULL,
  `acctauthentic` varchar(32) DEFAULT NULL,
  `connectinfo_start` varchar(50) DEFAULT NULL,
  `connectinfo_stop` varchar(50) DEFAULT NULL,
  `acctinputoctets` bigint(20) DEFAULT NULL,
  `acctoutputoctets` bigint(20) DEFAULT NULL,
  `calledstationid` varchar(50) NOT NULL DEFAULT '',
  `callingstationid` varchar(50) NOT NULL DEFAULT '',
  `acctterminatecause` varchar(32) NOT NULL DEFAULT '',
  `servicetype` varchar(32) DEFAULT NULL,
  `framedprotocol` varchar(32) DEFAULT NULL,
  `framedipaddress` varchar(15) NOT NULL DEFAULT '',
  `acctstartdelay` int(11) DEFAULT NULL,
  `acctstopdelay` int(11) DEFAULT NULL,
  `acctupdatetime` datetime DEFAULT NULL,
  `deleted` char(1) DEFAULT '',
  `objectclass` varchar(64) DEFAULT 'AAA-SessionInfo',
  PRIMARY KEY (`radacctid`),
  KEY `username` (`username`),
  KEY `framedipaddress` (`framedipaddress`),
  KEY `acctsessionid` (`acctsessionid`),
  KEY `acctsessiontime` (`acctsessiontime`),
  KEY `acctuniqueid` (`acctuniqueid`),
  KEY `acctstarttime` (`acctstarttime`),
  KEY `acctstoptime` (`acctstoptime`),
  KEY `nasipaddress` (`nasipaddress`),
  KEY `acctupdatetime` (`acctupdatetime`),
  KEY `deleted` (`deleted`),
  KEY `objectclass` (`objectclass`)
) ENGINE=MyISAM AUTO_INCREMENT=7117 DEFAULT CHARSET=latin1 

Regards,

Michael



 Comments   
Comment by Elena Stepanova [ 2016-02-24 ]

Michaelv, thanks for the report.
MySQL or earlier versions of MariaDB are not affected; but I'm afraid if you really need INSERT DELAYED functionality, MySQL is not an option for you, it does not have INSERT DELAYED anymore, it was deprecated in 5.6 and in 5.7 it's treated as a normal INSERT.

The problem was introduced in 10.1.9 with this commit:

commit e3868ee07273b1ea2c495d92891fd7d1ed1eea9e
Author: Monty <monty@mariadb.org>
Date:   Fri Nov 6 13:02:19 2015 +0200
 
    Don't store vcol bitmaps in TABLE if table doesn't have virtual fields.
    (Makes TABLE a bit smaller)


The warning returned upon a successful execution in the output quoted in description is irrelevant – it's just a data type conversion. Below is the same test case, just one value is changed from string to integer to get rid of the warning; it does not affect the outcome, it still fails on current 10.1:

 
CREATE TABLE `radacct` (
`radacctid` bigint(20) NOT NULL AUTO_INCREMENT,
`acctsessionid` varchar(64) NOT NULL DEFAULT '',
`acctuniqueid` varchar(32) NOT NULL DEFAULT '',
`username` varchar(64) NOT NULL DEFAULT '',
`groupname` varchar(64) NOT NULL DEFAULT '',
`realm` varchar(64) DEFAULT '',
`nasipaddress` varchar(15) NOT NULL DEFAULT '',
`nasportid` varchar(15) DEFAULT NULL,
`nasporttype` varchar(32) DEFAULT NULL,
`acctstarttime` datetime DEFAULT NULL,
`acctstoptime` datetime DEFAULT NULL,
`acctsessiontime` int(11) DEFAULT NULL,
`acctauthentic` varchar(32) DEFAULT NULL,
`connectinfo_start` varchar(50) DEFAULT NULL,
`connectinfo_stop` varchar(50) DEFAULT NULL,
`acctinputoctets` bigint(20) DEFAULT NULL,
`acctoutputoctets` bigint(20) DEFAULT NULL,
`calledstationid` varchar(50) NOT NULL DEFAULT '',
`callingstationid` varchar(50) NOT NULL DEFAULT '',
`acctterminatecause` varchar(32) NOT NULL DEFAULT '',
`servicetype` varchar(32) DEFAULT NULL,
`framedprotocol` varchar(32) DEFAULT NULL,
`framedipaddress` varchar(15) NOT NULL DEFAULT '',
`acctstartdelay` int(11) DEFAULT NULL,
`acctstopdelay` int(11) DEFAULT NULL,
`acctupdatetime` datetime DEFAULT NULL,
`deleted` char(1) DEFAULT '',
`objectclass` varchar(64) DEFAULT 'AAA-SessionInfo',
PRIMARY KEY (`radacctid`),
KEY `username` (`username`),
KEY `framedipaddress` (`framedipaddress`),
KEY `acctsessionid` (`acctsessionid`),
KEY `acctsessiontime` (`acctsessiontime`),
KEY `acctuniqueid` (`acctuniqueid`),
KEY `acctstarttime` (`acctstarttime`),
KEY `acctstoptime` (`acctstoptime`),
KEY `nasipaddress` (`nasipaddress`),
KEY `acctupdatetime` (`acctupdatetime`),
KEY `deleted` (`deleted`),
KEY `objectclass` (`objectclass`)
) ENGINE=MyISAM AUTO_INCREMENT=7117 DEFAULT CHARSET=latin1;
 
INSERT DELAYED INTO radacct (acctsessionid, acctuniqueid, username, groupname, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, acctupdatetime ) VALUES ("aasda1","ascac","ascasc","assfa","reasas","ascac","123","asc",now(),now(),12312,"testa","123asc",10,10,10,"ascasc","teast","ascasc","ascasc","aasca","teast",12312,123123,now());

Comment by Michael Van Der Beek [ 2016-02-25 ]

Hi Elena,

Thanks for the fast response. One of the reasons for Insert Delayed was the buffering of insert into the table which
speeds up response time. I wasn't sure I can achieve near the same speed with Innodb/Xtradb.
Hence my testing.
Also I have this weird issue.
I am running a 64bit kernel, running on 8G of ram (VM centos). For some weird reason, when I try to set the innodb_buffer_pool > 2G I get this error on start up.

2016-02-24 16:28:18 4160034560 [Note] /usr/sbin/mysqld (mysqld 10.1.11-MariaDB) starting as process 8897 ...
2016-02-24 16:28:18 4160034560 [ERROR] innobase_buffer_pool_size can't be over 4GB on 32-bit systems
2016-02-24 16:28:18 4160034560 [ERROR] Plugin 'InnoDB' init function returned error.
2016-02-24 16:28:18 4160034560 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2016-02-24 16:28:18 4160034560 [Note] Plugin 'FEEDBACK' is disabled.
2016-02-24 16:28:18 4160034560 [ERROR] Unknown/unsupported storage engine: InnoDB
2016-02-24 16:28:18 4160034560 [ERROR] Aborting

Kernel being used

Linux server1.testing.com 2.6.18-308.1.1.el5 #1 SMP Wed Mar 7 04:16:51 EST 2012 x86_64 x86_64 x86_64 GNU/Linux

$ file /sbin/init
/sbin/init: ELF 64-bit LSB executable, AMD x86-64, version 1 (SYSV), for GNU/Linux 2.6.9, dynamically linked (uses shared libs), for GNU/Linux 2.6.9, stripped

Not sure why it is reporting this 32bit issue.
I installed.

-rw-r--r-- 1 root root 11246365 Jan 29 12:40 galera-25.3.12-1.rhel5.el5.i386.rpm
-rw-r--r-- 1 root root   110818 Feb 14  2015 jemalloc-3.6.0-2.el5.i386.rpm
-rw-r--r-- 1 root root 14409006 Jan 29 13:32 MariaDB-10.1.11-centos5-i686-client.rpm
-rw-r--r-- 1 root root    51351 Jan 29 13:32 MariaDB-10.1.11-centos5-i686-common.rpm
-rw-r--r-- 1 root root  3491380 Jan 29 13:32 MariaDB-10.1.11-centos5-i686-compat.rpm
-rw-r--r-- 1 root root  2122913 Jan 29 13:32 MariaDB-10.1.11-centos5-i686-connect-engine.rpm
-rw-r--r-- 1 root root 69106584 Jan 29 13:32 MariaDB-10.1.11-centos5-i686-server.rpm
-rw-r--r-- 1 root root  1653188 Jan 29 13:32 MariaDB-10.1.11-centos5-i686-shared.rpm

In one of your replies you stated.

Fix Version/s 10.1 [ 16100 ]
Assignee Michael Widenius [ monty ]

Does this means it is already fixed? Our its being assigned to Michael Widenius to be fixed?

Regards,

Michael

Comment by Michael Van Der Beek [ 2016-02-25 ]

Opps I mean 4G not > 2G

Comment by Elena Stepanova [ 2016-02-25 ]

Michaelv, you have installed 32-bit packages of MariaDB (i686). 64-bit packages have x86_64 in their name.

In one of your replies you stated.
Fix Version/s 10.1 [ 16100 ]
Assignee Michael Widenius [ monty ]
Does this means it is already fixed? Our its being assigned to Michael Widenius to be fixed?

No, it hasn't been fixed it. When it's fixed, the Resolution value will be changed to Fixed, and Status to Closed.

To monty: My first comment to the issue relates to this bug report, the rest is irrelevant and can be ignored.

Comment by Michael Widenius [ 2016-04-07 ]

The problem was that I had accidently typed + instead of * when initializing a bit array.

Comment by Michael Widenius [ 2016-04-07 ]

Fix pushed into 10.1.

Generated at Thu Feb 08 07:36:04 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.