mysql very slow inserts

I've posted the question on the bacula-users list too but everyone is asleep there I think. My Bacula installation has suddenly slowed to a crawl and I've tracked it down (I think) to temporary table inserts. I've switched Bacula to use attribute spooling so it's fairly obvious that the backup job runs really fast (to the limit of USB2 connected backup medium) but then at the end of the job when it inserts the records into the database it almost stops. The backup job took about 2 minutes to copy a few GB of data but the database operation is still running a few hours later - it is making progress just slowly. It seems that Bacula has created a temporary table called batch and is inserting records into that, and then at the end I think it inserts the records into the main job table. The system load is ~1.15, and mysqld is highest on the list of processes but is only 1-2%, which I assume means that the cpu is being blocked somewhere due to IO (?). Disk write performance inside the VM where Bacula and mysql runs is around 90MB/second, which is more than sufficient to insert a few hundred thousand rows. iostat while all this is going on shows pretty much nothing happening. I think this has happened before but then came good before I got time to look at it properly. Can anyone please recommend how I can figure out where it's all going wrong? I've used the general log in mysql to determine that it's only the INSERT operations running, and iostat and strace to look for anything obviously loaded, but have come up empty. Thanks James

On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
The system load is ~1.15, and mysqld is highest on the list of processes but is only 1-2%, which I assume means that the cpu is being blocked somewhere due to IO (?).
Disk write performance inside the VM where Bacula and mysql runs is around 90MB/second, which is more than sufficient to insert a few hundred thousand rows.
iostat while all this is going on shows pretty much nothing happening.
What does iostat show for %util? If the overall speed is low but %util is near 100% then it usually means a storage hardware problem. Also 90MB/s isn't the issue for most database stuff, the issue is the number of synchronous operations. Of course for a temporary table it probably shouldn't be synchronising the data, Arjen? -- My Main Blog http://etbe.coker.com.au/ My Documents Blog http://doc.coker.com.au/

On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
The system load is ~1.15, and mysqld is highest on the list of processes but is only 1-2%, which I assume means that the cpu is being blocked somewhere due to IO (?).
Disk write performance inside the VM where Bacula and mysql runs is around 90MB/second, which is more than sufficient to insert a few hundred thousand rows.
iostat while all this is going on shows pretty much nothing happening.
What does iostat show for %util? If the overall speed is low but %util is near 100% then it usually means a storage hardware problem.
I don't see a %util. This is an average sort of output of iostat 1: avg-cpu: %user %nice %system %iowait %steal %idle 0.00 0.00 0.00 4.04 0.00 95.96 Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn xvdap1 91.00 0.00 204.00 0 204 xvdap2 0.00 0.00 0.00 0 0 %iowait varies from 0-20% (0% most of the time) %user varies from 0-2% (<1% most of the time) %system varies from 0-5% (~2% most of the time)
Also 90MB/s isn't the issue for most database stuff, the issue is the number of synchronous operations. Of course for a temporary table it probably shouldn't be synchronising the data, Arjen?
My point of including that figure is that it matches the baseline when the server was set up. IO performance hasn't dropped in any way I can measure. When I have a database issue like this I normally look at indexes and query plans and stuff, but of course this is a temporary table and not visible outside the process that created it, or at least as far as I can tell, so I can't easily test it. And this problem came on suddenly, without any change that I'm aware of. I've seen that happen before where database queries work fine for a few years until the database grows to the point where it can no longer fit the required information (indexes etc) in memory and performance drops off very quickly, but this particular operation is purely temporary tables which exist in isolation, and there is nothing else going on on the system at the same time. I'm looking up how to migrate from mysql to postgresql, which is something I have wanted to do for a while anyway, but that may not be straightforward for an established Bacula database... James

On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
iostat while all this is going on shows pretty much nothing happening.
What does iostat show for %util? If the overall speed is low but %util is near 100% then it usually means a storage hardware problem.
I don't see a %util. This is an average sort of output of iostat 1:
Run "iostat -x 1" and you'll get it. -- My Main Blog http://etbe.coker.com.au/ My Documents Blog http://doc.coker.com.au/

On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
iostat while all this is going on shows pretty much nothing happening.
What does iostat show for %util? If the overall speed is low but %util is near 100% then it usually means a storage hardware problem.
I don't see a %util. This is an average sort of output of iostat 1:
Run "iostat -x 1" and you'll get it.
I'm doing a test conversion to postgresql now, although swapping back is easy enough as the old mysql database is intact. While doing the conversion which is basically a bulk insert into postgresql database, %util is indeed high - 95-100% in the VM and mostly >50% on the physical machine for both raid1 member disks, even though the iops remain low. So my first guess is that it's probably not a problem with the actual disks - both disks appear equally affected and SMART reports nothing out of the ordinary. I'll migrate some VM's and reboot the physical machine, which I thought I'd already done but uptime says otherwise. Any other suggestions? Thanks James

On 26/04/13 11:59, James Harper wrote:
On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
iostat while all this is going on shows pretty much nothing happening.
What does iostat show for %util? If the overall speed is low but %util is near 100% then it usually means a storage hardware problem.
I don't see a %util. This is an average sort of output of iostat 1:
Run "iostat -x 1" and you'll get it.
I'm doing a test conversion to postgresql now, although swapping back is easy enough as the old mysql database is intact.
While doing the conversion which is basically a bulk insert into postgresql database, %util is indeed high - 95-100% in the VM and mostly >50% on the physical machine for both raid1 member disks, even though the iops remain low.
So my first guess is that it's probably not a problem with the actual disks - both disks appear equally affected and SMART reports nothing out of the ordinary. I'll migrate some VM's and reboot the physical machine, which I thought I'd already done but uptime says otherwise.
Any other suggestions?
When doing bulk inserts on PostgreSQL, you'll find it goes a lot faster if you do them all inside a transaction. For more speed, use the 'COPY' command rather than INSERT, as it's specifically designed for bulk loading. You can also drop the indexes at the start and recreate them at the end. (Which if done inside a transaction, will not drop them for other users) You can disable foreign key checks, or at least defer them all until the end of the transaction, which is quicker than having them checked per-insert. You can disable synchronous writes for your query. However as Ari pointed out too -- databases are quite capable of doing a LOT of inserts per second, even before applying the above optimisations. If it's running noticeably slowly then there's probably something wrong elsewhere, in the DDL or the program. -T

(thanks for including me on this thread, Russell) Hi James Most default DB installs work "fine" until they get a significant amount of data, users, etc. Migration to another DB will not solve fundamental flaws in schema or query design or other such factors. In addition, often schema, queries and also server setup is architected towards using the particular original database it was designed on. Thus it's generally unlikely that simply moving from one brand db server to another create vast (if any) improvements - and that's apart from the pain of migrating in the first place. For these reasons, I generally don't recommend migrations, regardless of which-to-which brand it is. However, if you are familiar with PostreSQL and not with MySQL or MariaDB, then naturally you'd be more likely to create an optimal setup with PostgreSQL. So if the application you're using supports PostgreSQL, then that can be the best choice for you. If you find that you do need to use MySQL/MariaDB for this task, it's important to configure the server appropriately. It's important to realise that the defaults are for a functional setup with minimal disk/memory use, they are not for a production system. Some people just up some of the numbers, but that's not really how it works ;-) If this is for a business/company/organisation, feel free to contact my business for assistance. Details in signature. What we'd need to look at is which storage engine is getting used by the app, and what tasks it's trying to do. Based on that we can create a baseline configuration that'll perform reasonably well, which can then be tuned further over time. You mentioned bulk inserts. I can insert between 80K (InnoDB) and 340K (MyISAM - datawarehousing engine) rows per second on a single connection/thread in MySQL. It's not a matter of whether MySQL can handle this ;-) Regards, Arjen. -- Exec.Director @ Open Query (http://openquery.com) MariaDB/MySQL services

(thanks for including me on this thread, Russell)
Hi James
Most default DB installs work "fine" until they get a significant amount of data, users, etc.
Migration to another DB will not solve fundamental flaws in schema or query design or other such factors. In addition, often schema, queries and also server setup is architected towards using the particular original database it was designed on. Thus it's generally unlikely that simply moving from one brand db server to another create vast (if any) improvements - and that's apart from the pain of migrating in the first place. For these reasons, I generally don't recommend migrations, regardless of which-to-which brand it is.
However, if you are familiar with PostreSQL and not with MySQL or MariaDB, then naturally you'd be more likely to create an optimal setup with PostgreSQL. So if the application you're using supports PostgreSQL, then that can be the best choice for you.
If you find that you do need to use MySQL/MariaDB for this task, it's important to configure the server appropriately. It's important to realise that the defaults are for a functional setup with minimal disk/memory use, they are not for a production system. Some people just up some of the numbers, but that's not really how it works ;-) If this is for a business/company/organisation, feel free to contact my business for assistance. Details in signature.
What we'd need to look at is which storage engine is getting used by the app, and what tasks it's trying to do. Based on that we can create a baseline configuration that'll perform reasonably well, which can then be tuned further over time.
You mentioned bulk inserts. I can insert between 80K (InnoDB) and 340K (MyISAM - datawarehousing engine) rows per second on a single connection/thread in MySQL. It's not a matter of whether MySQL can handle this ;-)
Thanks for the input. I recognise that there is an obvious problem not related to choice of database when tps drops from tens of thousands to hundreds, and thanks to Russell's hints about IO monitoring I think I've identified that it is to do with some bottleneck in my Xen installation (almost certainly related to a bug somewhere), and I'm going to try a reboot when practical. Last time this happened I did a bunch of things, including throwing more memory at the VM, adding another processor, swapping the backend to innodb, upgrading mysql, upgrading Bacula, and putting the storage on local rather than iSCSI disks. Nothing helped until I rebooted the physical machine and then it seemed to come good after that although I didn't make the connection at the time. James

The system load is ~1.15, and mysqld is highest on the list of processes but is only 1-2%, which I assume means that the cpu is being blocked somewhere due to IO (?).
Disk write performance inside the VM where Bacula and mysql runs is around 90MB/second, which is more than sufficient to insert a few hundred thousand rows.
Digging further... I had make the assumption that low kb/second of disk activity meant that the disk subsystem was idle. Russell pointed out that %util when iostat is called with -x and it shows high io load. In dom0 when mostly idle: # dd if=/dev/zero of=test.bin bs=1024 count=10240 oflag=direct 10240+0 records in 10240+0 records out 10485760 bytes (10 MB) copied, 2.00537 s, 5.2 MB/s In domu when idle: # dd if=/dev/zero of=test.bin bs=1k count=1024 oflag=direct 1024+0 records in 1024+0 records out 1048576 bytes (1.0 MB) copied, 0.262493 s, 4.0 MB/s In domu when slow mysql query is running: # dd if=/dev/zero of=test.bin bs=1k count=1024 oflag=direct 1024+0 records in 1024+0 records out 1048576 bytes (1.0 MB) copied, 20.6291 s, 50.8 kB/s Which does indicate that the io is struggling when the mysql query is running... I'm converting to xfs from ext3 to see if there is something gone bad with the filesystem. James

On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
Which does indicate that the io is struggling when the mysql query is running...
I'm converting to xfs from ext3 to see if there is something gone bad with the filesystem.
XFS performs very well. But unless you happen to be triggering some obscure corner case (which seems unlikely with a program as common as mysqld) I don't think that XFS will give you a huge benefit over Ext3. Eventually they all come down to seek times on disk. If you convert filesystem then before you do it please restart mysqld, umount and mount the filesystem, and do any other changes that might happen as part of the XFS conversion while still using Ext3. Then if you get a performance benefit you'll know that it's related to XFS not something else. -- My Main Blog http://etbe.coker.com.au/ My Documents Blog http://doc.coker.com.au/

On Fri, 26 Apr 2013, James Harper <james.harper@bendigoit.com.au> wrote:
Which does indicate that the io is struggling when the mysql query is running...
I'm converting to xfs from ext3 to see if there is something gone bad with the filesystem.
XFS performs very well. But unless you happen to be triggering some obscure corner case (which seems unlikely with a program as common as mysqld) I don't think that XFS will give you a huge benefit over Ext3. Eventually they all come down to seek times on disk.
Converting back to xfs is something I'd been meaning to do for a while - the VM is only about 10GB is size so it only takes a few minutes to cp -a.
If you convert filesystem then before you do it please restart mysqld, umount and mount the filesystem, and do any other changes that might happen as part of the XFS conversion while still using Ext3. Then if you get a performance benefit you'll know that it's related to XFS not something else.
I'd already done a reboot that covered this. It's not measurably better after converting as you predicted. I'm now tinkering with innodb options to see if I can improve things. Looking at the strace there are lots of: pwrite(count=512) fsync() pwrite(count=1024) fsync() with the fsync taking around 0.1-0.2 units of time (seconds I guess), which would explain why I'm limited to about 5-10 inserts a second, so the next thing I'll try is changing innodb_flush_method to something else... assuming temporary tables use innodb. Something else to look up I guess. If I can establish that the fsync() is where it's going wrong then the next thing is to find out exactly why this has changed - I still have no explanation for why the system went from flying along with the speed limited pretty much by USB throughput down to almost zero. As I said it has done this before several months ago and then spontaneously went back to the original behaviour before I had a chance to properly investigate. James

On Fri, Apr 26, 2013 at 10:30:01AM +0000, James Harper wrote:
Converting back to xfs is something I'd been meaning to do for a while - the VM is only about 10GB is size so it only takes a few minutes to cp -a.
what kind of "disk" is the VM's disk running on? mdadm+lvm? what kind of raid? i'm wondering if you've lucked onto some pathological worst-case of striping and block size. also do you have any/many snapshots of that LV? snapshots can really bugger up LVM performance. craig -- craig sanders <cas@taz.net.au>

On Fri, Apr 26, 2013 at 10:30:01AM +0000, James Harper wrote:
Converting back to xfs is something I'd been meaning to do for a while - the VM is only about 10GB is size so it only takes a few minutes to cp -a.
what kind of "disk" is the VM's disk running on? mdadm+lvm? what kind of raid?
Yes, LVM on RAID1 on 2 x 7200RPM SATA disks.
i'm wondering if you've lucked onto some pathological worst-case of striping and block size.
Could be. I'm puzzled as to how this problem spontaneously developed though, and if the problem is: . mysql suddenly deciding to fsync after each write to the innodb log file (which is what I've tracked it down to) . fsync suddenly going slow under my xen DomU . Dom0 suddenly not handling vbd ring flush operations well . something else... Not sure if I'm testing the right thing here, but the following gives me ~30kbytes/second on most machines I test this on: dd if=/dev/zero of=test.bin bs=512 count=128 oflag=sync (software raid obviously, hardware raid with battery backed cache should be about 10x-100x faster)
also do you have any/many snapshots of that LV? snapshots can really bugger up LVM performance.
No snapshots. Thanks James

In the absence of any other solution I have set innodb_flush_log_at_trx_commit=0. This stops mysql issuing an fsync() after each write and instead issues an fsync() after 1 second (give or take a few ticks). It means I could lose up to slightly more than 1 second of transactions in the event of a crash or hardware failure, but the nature of the application in question (backup software) makes that a non-issue as the data is record of another process (the backup) that has now failed and will need to be restarted anyway. Having just restarted the backup jobs, performance appears to be back to the expected level based on 5 minutes of running. I still don't know what changed to make this problem appear though. James
participants (5)
-
Arjen Lentz
-
Craig Sanders
-
James Harper
-
Russell Coker
-
Toby Corkindale