InnoDB with shared buffer pool takes long to shutdown

Bug #643650 reported by Vadim Tkachenko
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
High
Unassigned

Bug Description

I noticed that on server with big amount of memory ( 120GB buffer pool)
when I use buffer_pool_shared memory it takes very long to shutdown.

There is some process after InnoDB finished flushing, it is CPU bound process.

stack trace:

(gdb) thread app all bt

Thread 2 (Thread 0x599e2940 (LWP 17830)):
#0 buf_pool_free () at ./include/ut0rnd.ic:224
#1 0x0000000000798a3a in innobase_shutdown_for_mysql () at srv/srv0start.c:2215
#2 0x000000000072c78f in innobase_end (hton=<value optimized out>, type=<value optimized out>) at handler/ha_innodb.cc:2588
#3 0x000000000068f6ab in ha_finalize_handlerton (plugin=0x5725db8) at handler.cc:395
#4 0x000000000070cbc6 in plugin_deinitialize (plugin=0x5725db8, ref_check=true) at sql_plugin.cc:828
#5 0x000000000070d6fe in reap_plugins () at sql_plugin.cc:916
#6 0x000000000070db8d in plugin_shutdown () at sql_plugin.cc:1551
#7 0x00000000005b01bc in clean_up (print_message=true) at mysqld.cc:1363
#8 0x00000000005b061e in unireg_end () at mysqld.cc:1289
#9 0x00000000005b430d in kill_server (arg=<value optimized out>) at mysqld.cc:1224
#10 kill_server_thread (arg=<value optimized out>) at mysqld.cc:1252
#11 0x0000003d2760673d in start_thread () from /lib64/libpthread.so.0
#12 0x0000003d26ed3d1d in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x2ab90c584fb0 (LWP 17698)):
#0 0x0000003d2760aee9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00000000005b52f5 in main (argc=<value optimized out>, argv=<value optimized out>) at mysqld.cc:4765

Related branches

Changed in percona-server:
status: New → Confirmed
importance: Undecided → High
assignee: nobody → Yasufumi Kinoshita (yasufumi-kinoshita)
milestone: none → 5.1-13.0
Revision history for this message
Vadim Tkachenko (vadim-tk) wrote :

The same happens when InnoDB starts and attaches to existing shared buffer pool.

A lot of time is spent in
0x00000000007d8b73 in ut_fold_ulint_pair (chunk=0x913e1d8, mem_size=<value optimized out>) at ./include/ut0rnd.ic:171
171 ./include/ut0rnd.ic: No such file or directory.
        in ./include/ut0rnd.ic

Revision history for this message
Vadim Tkachenko (vadim-tk) wrote :

detailed trace during start

(gdb) thread app all bt

Thread 1 (Thread 0x2b5214dfffb0 (LWP 18233)):
#0 ut_fold_binary (chunk=0x135a91d8, mem_size=<value optimized out>) at ./include/ut0rnd.ic:225
#1 buf_chunk_init (chunk=0x135a91d8, mem_size=<value optimized out>) at buf/buf0buf.c:962
#2 0x00000000007da881 in buf_pool_init () at buf/buf0buf.c:1366
#3 0x000000000079978d in innobase_start_or_create_for_mysql () at srv/srv0start.c:1445
#4 0x000000000072c2d0 in innobase_init (p=<value optimized out>) at handler/ha_innodb.cc:2463
#5 0x0000000000690861 in ha_initialize_handlerton (plugin=0x12305db8) at handler.cc:435
#6 0x000000000070cc6d in plugin_initialize (plugin=0x12305db8) at sql_plugin.cc:1019
#7 0x000000000070f41a in plugin_init (argc=0xdb7cf0, argv=0x122df698, flags=<value optimized out>) at sql_plugin.cc:1246
#8 0x00000000005b38bf in init_server_components () at mysqld.cc:4050
#9 0x00000000005b4e59 in main (argc=<value optimized out>, argv=<value optimized out>) at mysqld.cc:4623

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

Anyway, calc check sum is needed to confirm destruction, I think.
It should be changed to ut_fold_binary_32 of innodb_fast_checksum.patch?
But it might make around 1/2 of the time.

And why the importance of it is "High"?
It doesn't break anything data. Not danger.
No magic solutions.

Revision history for this message
Peter Zaitsev (pz-percona) wrote : Re: [Bug 643650] Re: InnoDB with shared buffer pool takes long to shutdown

Yasufumi,

Do we need to check checksums ? In which cases it will detect the problem
?
Can't buffer pool have correct checksums but to be logically inconsistent
(meaning this check is not enough)
Do you use this to catch when MySQL was not shut normally ?

--
Peter Zaitsev, CEO, Percona Inc.
Tel: +1 888 401 3401 ext 501 Skype: peter_zaitsev
24/7 Emergency Line +1 888 401 3401 ext 911

Percona Training Workshops
http://www.percona.com/training/

Revision history for this message
Vadim Tkachenko (vadim-tk) wrote : Re: [Bug 643650] [NEW] InnoDB with shared buffer pool takes long to shutdown

Yasufumi,

We can use new checksum from Facebook, they have implementation based
on CPU instructions.

Why do you need to check checksum at shutdown?

I am setting this as "high" because the purpose of feature is to
minimize downtime, and this bug makes it problematic.

On Tuesday, September 21, 2010, Yasufumi Kinoshita
<email address hidden> wrote:
> Anyway, calc check sum is needed to confirm destruction, I think.
> It should be changed to ut_fold_binary_32 of innodb_fast_checksum.patch?
> But it might make around 1/2 of the time.
>
> And why the importance of it is "High"?
> It doesn't break anything data. Not danger.
> No magic solutions.
>
> --
> InnoDB with shared buffer pool takes long to shutdown
> https://bugs.launchpad.net/bugs/643650
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona Server.
>
> Status in Percona Server with XtraDB: Confirmed
>
> Bug description:
> I noticed that on server with big amount of memory ( 120GB buffer pool)
> when I use buffer_pool_shared memory it takes very long to shutdown.
>
> There is some process after InnoDB finished flushing, it is CPU bound process.
>
> stack trace:
>
>
> (gdb) thread app all bt
>
> Thread 2 (Thread 0x599e2940 (LWP 17830)):
> #0  buf_pool_free () at ./include/ut0rnd.ic:224
> #1  0x0000000000798a3a in innobase_shutdown_for_mysql () at srv/srv0start.c:2215
> #2  0x000000000072c78f in innobase_end (hton=<value optimized out>, type=<value optimized out>) at handler/ha_innodb.cc:2588
> #3  0x000000000068f6ab in ha_finalize_handlerton (plugin=0x5725db8) at handler.cc:395
> #4  0x000000000070cbc6 in plugin_deinitialize (plugin=0x5725db8, ref_check=true) at sql_plugin.cc:828
> #5  0x000000000070d6fe in reap_plugins () at sql_plugin.cc:916
> #6  0x000000000070db8d in plugin_shutdown () at sql_plugin.cc:1551
> #7  0x00000000005b01bc in clean_up (print_message=true) at mysqld.cc:1363
> #8  0x00000000005b061e in unireg_end () at mysqld.cc:1289
> #9  0x00000000005b430d in kill_server (arg=<value optimized out>) at mysqld.cc:1224
> #10 kill_server_thread (arg=<value optimized out>) at mysqld.cc:1252
> #11 0x0000003d2760673d in start_thread () from /lib64/libpthread.so.0
> #12 0x0000003d26ed3d1d in clone () from /lib64/libc.so.6
>
> Thread 1 (Thread 0x2ab90c584fb0 (LWP 17698)):
> #0  0x0000003d2760aee9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
> #1  0x00000000005b52f5 in main (argc=<value optimized out>, argv=<value optimized out>) at mysqld.cc:4765
>
>
>

--
Vadim Tkachenko, CTO, Percona Inc.
Phone +1-888-401-3403, Skype: vadimtk153
Schedule meeting: http://tungle.me/VadimTkachenko

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

Peter,

How to detect someone or some problem break the contents of the shm between shutdown and re-start?

> Can't buffer pool have correct checksums but to be logically inconsistent
> (meaning this check is not enough)

I don't understand what you say...

Or, do you misunderstand about the check sum of the each pages?
It is calculated only when writing the pages to disk. not valid when on memory.
The other checksum is needed.

Vadim,

When shutdown is not to check, but to store.
When startup is to check.

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

And...

Vadim,

> We can use new checksum from Facebook, they have implementation based
> on CPU instructions.

I know 32 bit base sum only. Do you mean some assembly codes?
I don't know the code of direct using the CPU instructions...

Revision history for this message
Vadim Tkachenko (vadim-tk) wrote : Re: [Bug 643650] Re: InnoDB with shared buffer pool takes long to shutdown

Yasufumi,

You can see there
http://bazaar.launchpad.net/~mysqlatfacebook/mysqlatfacebook/5.1/annotate/head:/mysys/my_crc32.c

On Tue, Sep 21, 2010 at 7:34 PM, Yasufumi Kinoshita
<email address hidden> wrote:
> And...
>
> Vadim,
>
>> We can use new checksum from Facebook, they have implementation based
>> on CPU instructions.
>
> I know 32 bit base sum only.  Do you mean some assembly codes?
> I don't know the code of direct using the CPU instructions...
>
> --
> InnoDB with shared buffer pool takes long to shutdown
> https://bugs.launchpad.net/bugs/643650
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona Server.
>
> Status in Percona Server with XtraDB: Confirmed
>
> Bug description:
> I noticed that on server with big amount of memory ( 120GB buffer pool)
> when I use buffer_pool_shared memory it takes very long to shutdown.
>
> There is some process after InnoDB finished flushing, it is CPU bound process.
>
> stack trace:
>
>
> (gdb) thread app all bt
>
> Thread 2 (Thread 0x599e2940 (LWP 17830)):
> #0  buf_pool_free () at ./include/ut0rnd.ic:224
> #1  0x0000000000798a3a in innobase_shutdown_for_mysql () at srv/srv0start.c:2215
> #2  0x000000000072c78f in innobase_end (hton=<value optimized out>, type=<value optimized out>) at handler/ha_innodb.cc:2588
> #3  0x000000000068f6ab in ha_finalize_handlerton (plugin=0x5725db8) at handler.cc:395
> #4  0x000000000070cbc6 in plugin_deinitialize (plugin=0x5725db8, ref_check=true) at sql_plugin.cc:828
> #5  0x000000000070d6fe in reap_plugins () at sql_plugin.cc:916
> #6  0x000000000070db8d in plugin_shutdown () at sql_plugin.cc:1551
> #7  0x00000000005b01bc in clean_up (print_message=true) at mysqld.cc:1363
> #8  0x00000000005b061e in unireg_end () at mysqld.cc:1289
> #9  0x00000000005b430d in kill_server (arg=<value optimized out>) at mysqld.cc:1224
> #10 kill_server_thread (arg=<value optimized out>) at mysqld.cc:1252
> #11 0x0000003d2760673d in start_thread () from /lib64/libpthread.so.0
> #12 0x0000003d26ed3d1d in clone () from /lib64/libc.so.6
>
> Thread 1 (Thread 0x2ab90c584fb0 (LWP 17698)):
> #0  0x0000003d2760aee9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
> #1  0x00000000005b52f5 in main (argc=<value optimized out>, argv=<value optimized out>) at mysqld.cc:4765
>
>
>

--
Vadim Tkachenko, CTO, Percona Inc.
Phone +1-888-401-3403,  Skype: vadimtk153
Schedule meeting: http://tungle.me/VadimTkachenko

Revision history for this message
Peter Zaitsev (pz-percona) wrote :
Download full text (3.2 KiB)

Yasufumi,

I do not think this is something what we need to protect from at least it
should be the option two reasons are

1) There are a lot of things one can mess when Innodb is down on disk. I
would argue it is harder to access
and mess with buffer pool in shared memory by mistake

2) If someone wants to mess with buffer pool checksums are not going to
help. I can swap places for pages for
example which will corrupt database but will not be noticed.

In general this is advanced feature for someone who knows what he is doing.

On Tue, Sep 21, 2010 at 7:32 PM, Yasufumi Kinoshita <
<email address hidden>> wrote:

> Peter,
>
> How to detect someone or some problem break the contents of the shm
> between shutdown and re-start?
>
>
> > Can't buffer pool have correct checksums but to be logically inconsistent
> > (meaning this check is not enough)
>
> I don't understand what you say...
>
> Or, do you misunderstand about the check sum of the each pages?
> It is calculated only when writing the pages to disk. not valid when on
> memory.
> The other checksum is needed.
>
>
> Vadim,
>
> When shutdown is not to check, but to store.
> When startup is to check.
>
> --
> InnoDB with shared buffer pool takes long to shutdown
> https://bugs.launchpad.net/bugs/643650
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona Server.
>
> Status in Percona Server with XtraDB: Confirmed
>
> Bug description:
> I noticed that on server with big amount of memory ( 120GB buffer pool)
> when I use buffer_pool_shared memory it takes very long to shutdown.
>
> There is some process after InnoDB finished flushing, it is CPU bound
> process.
>
> stack trace:
>
>
> (gdb) thread app all bt
>
> Thread 2 (Thread 0x599e2940 (LWP 17830)):
> #0 buf_pool_free () at ./include/ut0rnd.ic:224
> #1 0x0000000000798a3a in innobase_shutdown_for_mysql () at
> srv/srv0start.c:2215
> #2 0x000000000072c78f in innobase_end (hton=<value optimized out>,
> type=<value optimized out>) at handler/ha_innodb.cc:2588
> #3 0x000000000068f6ab in ha_finalize_handlerton (plugin=0x5725db8) at
> handler.cc:395
> #4 0x000000000070cbc6 in plugin_deinitialize (plugin=0x5725db8,
> ref_check=true) at sql_plugin.cc:828
> #5 0x000000000070d6fe in reap_plugins () at sql_plugin.cc:916
> #6 0x000000000070db8d in plugin_shutdown () at sql_plugin.cc:1551
> #7 0x00000000005b01bc in clean_up (print_message=true) at mysqld.cc:1363
> #8 0x00000000005b061e in unireg_end () at mysqld.cc:1289
> #9 0x00000000005b430d in kill_server (arg=<value optimized out>) at
> mysqld.cc:1224
> #10 kill_server_thread (arg=<value optimized out>) at mysqld.cc:1252
> #11 0x0000003d2760673d in start_thread () from /lib64/libpthread.so.0
> #12 0x0000003d26ed3d1d in clone () from /lib64/libc.so.6
>
> Thread 1 (Thread 0x2ab90c584fb0 (LWP 17698)):
> #0 0x0000003d2760aee9 in pthread_cond_wait@@GLIBC_2.3.2 () from
> /lib64/libpthread.so.0
> #1 0x00000000005b52f5 in main (argc=<value optimized out>, argv=<value
> optimized out>) at mysqld.cc:4765
>
>
>

--
Peter Zaitsev, CEO, Percona Inc.
Tel: +1 888 401 3401 ext 501 Skype: peter_zaitsev
24/7 Emergency Line +...

Read more...

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

If
"the buffer_pool_shm is perfect"
and
"outside operations out of mysql is perfect (by user / server) "
and
"shm implementation is perfect ",
the checkpoint may not be needed.

If the checksum is removed, I don't support the function at all.
The checksum is needed to confirm innocence/guilt of the patch code if you will meet problem.
I don't analyze with many kind of possibility.

Revision history for this message
Yasufumi Kinoshita (yasufumi-kinoshita) wrote :

Vadim,

> You can see there
http://bazaar.launchpad.net/~mysqlatfacebook/mysqlatfacebook/5.1/annotate/head:/mysys/my_crc32.c

It is SSE4.2 specific instructions....
So, the #ifdef of the patch is wrong.

I uses "AMD Phenom(tm) II X6 1090T Processor" (x86_64), but the processor doesn't support the instructions.

I don't use SSE (explicitly in the source code) for now, to keep compatibility.

Changed in percona-server:
status: Confirmed → Fix Committed
Revision history for this message
Vadim Tkachenko (vadim-tk) wrote :

even with proposed changes it is very slow at shutdown.

Can we have option
--innodb_buffer_pool_shm_checksum=ON | OFF which enables / disables checksum calculation ?

Changed in percona-server:
status: Fix Committed → Fix Released
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-429

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.