Bug #84940 MySQL Server crash possibly introduced in InnoDB statistics calculation
Submitted: 10 Feb 2017 7:46 Modified: 10 Apr 2017 6:46
Reporter: Oli Sennhauser Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.6.35, 5.7.17 OS:Linux (Debian 8, unknown)
Assigned to: CPU Architecture:Any

[10 Feb 2017 7:46] Oli Sennhauser
Description:
MySQL server crashed with a stack trace.

One of our customers got a stack trace of the following type in MySQL 5.6.35 (he claimed it does not happen in a similar box in 5.6.33):

terminate called after throwing an instance of 'std::out_of_range'
  what():  vector::_M_range_check: __n (which is 4294967295) >= this->size() (which is 0)
04:06:45 UTC - mysqld got signal 6 ;
...
Thread pointer: 0x0
...
stack_bottom = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x33)[0x876d73]
/usr/sbin/mysqld(handle_fatal_signal+0x35c)[0x64089c]
/lib64/libpthread.so.0(+0x10f90)[0x7fecc63d2f90]
/lib64/libc.so.6(gsignal+0x37)[0x7fecc57e8167]
/lib64/libc.so.6(abort+0x16a)[0x7fecc57e95ea]
/usr/lib/gcc/x86_64-pc-linux-gnu/4.9.4/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x16d)[0x7fecc60e017d]
/usr/lib/gcc/x86_64-pc-linux-gnu/4.9.4/libstdc++.so.6(+0x73fc6)[0x7fecc60ddfc6]
/usr/lib/gcc/x86_64-pc-linux-gnu/4.9.4/libstdc++.so.6(+0x74011)[0x7fecc60de011]
/usr/lib/gcc/x86_64-pc-linux-gnu/4.9.4/libstdc++.so.6(+0x74228)[0x7fecc60de228]
/usr/lib/gcc/x86_64-pc-linux-gnu/4.9.4/libstdc++.so.6(_ZSt24__throw_out_of_range_fmtPKcz+0x139)[0x7fecc613e869]
/usr/sbin/mysqld[0x9c3e02]
/usr/sbin/mysqld[0x9c51a0]
/usr/sbin/mysqld[0x9c60d1]
/lib64/libpthread.so.0(+0x74a4)[0x7fecc63c94a4]
/lib64/libc.so.6(clone+0x6d)[0x7fecc589c66d]

Googling around led us to a similar stack trace in MySQL 5.7.17:

http://stackoverflow.com/questions/41875287/mysql-5-7-17-restarts-unexpected

terminate called after throwing an instance of 'std::out_of_range'
 what(): vector::_M_range_check: __n (which is 4294967295) >= this->size() (which is 0) 
17:01:17 UTC - mysqld got signal 6 ; 
Thread pointer: 0x0 
...
stack_bottom = 0 thread_stack 0x30000 
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0xe7fdcc] 
/usr/sbin/mysqld(handle_fatal_signal+0x459)[0x7a9d39] 
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7f81f88d58d0] 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f81f72de067] 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f81f72df448] 
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x15d)[0x7f81f7bcbb3d] 
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0x5ebb6)[0x7f81f7bc9bb6] 
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0x5ec01)[0x7f81f7bc9c01] 
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0x5ee19)[0x7f81f7bc9e19] 
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(_ZSt24__throw_out_of_range_fmtPKcz+0x11f)[0x7f81f7c1fcdf] 
/usr/sbin/mysqld[0x11ae3fe] /usr/sbin/mysqld[0x11b0948] 
/usr/sbin/mysqld(_Z17dict_stats_updateP12dict_table_t23dict_stats_upd_option_t+0x1140)[0x11b4340] 
/usr/sbin/mysqld(dict_stats_thread+0x331)[0x11b61c1] 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x80a4)[0x7f81f88ce0a4] 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f81f739162d]

Those stack traces look pretty similar. Fortunately the 2nd stack trace still contains some labels:

/usr/lib/x86_64-linux-gnu/libstdc++.so.6(_ZSt24__throw_out_of_range_fmtPKcz+0x11f)[0x7f81f7c1fcdf] 
/usr/sbin/mysqld(_Z17dict_stats_updateP12dict_table_t23dict_stats_upd_option_t+0x1140)[0x11b4340] 

So we ASSUME we have the same problem.

Looking in the new features of 5.6.35 and 5.7.17:

https://dev.mysql.com/doc/relnotes/mysql/5.6/en/news-5-6-35.html
https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-17.html

Boot show changes in the InnoDB statistics code:

InnoDB: By default, InnoDB reads uncommitted data when calculating statistics. In the case of an uncommitted transaction that deletes rows from a table, InnoDB excludes records that are delete-marked when calculating row estimates and index statistics, which can lead to non-optimal execution plans for other transactions that are operating on the table concurrently using a transaction isolation level other than READ UNCOMMITTED. To avoid this scenario, a new configuration option, innodb_stats_include_delete_marked, can be enabled to ensure that InnoDB includes delete-marked records when calculating persistent optimizer statistics. (Bug #23333990)

So we assume, the bug has to do with this new features.

Please let us know if we can provide some more information.

How to repeat:
Unknown yet.

Suggested fix:
Seems to be a boundary check/overflow according to the error message...
[10 Feb 2017 8:12] Shane Bester
Oli, Umesh, this would be same as internal:
Bug 24585978 - INNODB: ASSERTION TOTAL_RECS > 0 FAILURE IN FILE DICT0STATS.CC
[10 Feb 2017 15:29] Sinisa Milivojevic
Hi Oli,

It turns out  that this bug is a duplicate of the following one:

https://bugs.mysql.com/bug.php?id=82842

And this bug is already fixed. Here is the note from that bug:

-------------

Fixed as of the upcoming 5.7.18, 8.0.1 release, and here's the changelog entry:

An error in code related to table statistics raised an assertion in the
dict0stats.cc source file.
-------------

Oli,

Please, do let us know if you still experience this problem in 5.7.18.

Thanks.
[10 Feb 2017 16:06] Oli Sennhauser
Hi Sinisha

Thanks for the information. Bug #82842 is hidden (because of "security" reasons?!?).

Would be nice having a back-port to 5.6 as well. Current customer is still running 5.6. Especially when you have introduced it in 5.6 in a recent release.

Regards,
Oli
[10 Feb 2017 16:49] Sinisa Milivojevic
Oli,

It should be fixed already in 5.6.36, so please, test it when it is out !!!!!
[14 Mar 2017 10:34] Umesh Shastry
Bug #85438 marked as duplicate of this
[7 Apr 2017 8:30] Jai Gupta
mysql --version
mysql  Ver 14.14 Distrib 5.6.35-80.0, for Linux (x86_64) using  6.0

terminate called after throwing an instance of 'std::out_of_range'
  what():  vector::_M_range_check
08:05:38 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona XtraDB Cluster better by reporting any
bugs at https://bugs.launchpad.net/percona-xtradb-cluster

key_buffer_size=25165824
read_buffer_size=131072
max_used_connections=201
max_threads=202
thread_count=53
connection_count=4
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 156765 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x90ebc5]
/usr/sbin/mysqld(handle_fatal_signal+0x4b4)[0x66d3d4]
/lib64/libpthread.so.0(+0xf7e0)[0x7f0517fa57e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f05161de5e5]
/lib64/libc.so.6(abort+0x175)[0x7f05161dfdc5]
/usr/lib64/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x12d)[0x7f0516a98a7d]
/usr/lib64/libstdc++.so.6(+0xbcbd6)[0x7f0516a96bd6]
/usr/lib64/libstdc++.so.6(+0xbcc03)[0x7f0516a96c03]
/usr/lib64/libstdc++.so.6(+0xbcd22)[0x7f0516a96d22]
/usr/lib64/libstdc++.so.6(_ZSt20__throw_out_of_rangePKc+0x67)[0x7f0516a3bdb7]
/usr/sbin/mysqld[0xb22e6c]
/usr/sbin/mysqld[0xb25191]
/usr/sbin/mysqld[0xb2787a]
/lib64/libpthread.so.0(+0x7aa1)[0x7f0517f9daa1]
/lib64/libc.so.6(clone+0x6d)[0x7f0516294aad]
You may download the Percona XtraDB Cluster operations manual by visiting
http://www.percona.com/software/percona-xtradb-cluster/. You may find information
in the manual which will help you identify the cause of the crash.
[7 Apr 2017 14:47] Sinisa Milivojevic
Hi Oli!

This bug is fixed in 5.7 and higher versions. It will never be fixed in 5.6, as the patch would be too large for 5.6.

Do us a favor and try latest 5.7.
[7 Apr 2017 14:50] Sinisa Milivojevic
Oli,

It is actually fixed in 5.6.36.  You used 5.6.35.

Also, we do not maintain Percona XtraDB Cluster, so we do not know when will they port the fix.
[10 Apr 2017 6:46] Oli Sennhauser
Hello Sinisa

Thank you for the notification. I will inform the customer.

Best Regards,
Oli
[10 Apr 2017 14:50] Sinisa Milivojevic
Oli,

It was my pleasure !!!!
[24 Apr 2017 6:53] Libor Laichmann
Could you confirm me that this bug has been resolved in the 5.7.18 version? Thx
[24 Apr 2017 13:34] Sinisa Milivojevic
Yes, this bug is fixed in 5.7.18 release.

You do not have to ask me the questions. Our ChangeLog, named "MySQL Release Notes" is freely available for download or browsing on our dev.mysql.com site.
[15 May 2017 20:54] Edward Hibbert
I'm seeing this on production system running a Percona Cluster, where the fix has not yet been ported.  Does anyone know if there are any workarounds for this, e.g. by setting configuration variable relating to the statistics function?
[16 May 2017 5:29] Shane Bester
workaround is to disable innodb persistent stats.

[mysqld]
innodb-stats-persistent             = 0
innodb-stats-transient-sample-pages = 20
innodb-stats-auto-recalc            = 0
[16 May 2017 6:55] Edward Hibbert
Thanks Shane - will try that and see if it helps stability.  What's the downside of that - maybe less efficient queries?
[19 May 2017 9:58] Edward Hibbert
Turning the stats off does appear to work around this crash.
[28 Aug 2017 7:42] Umesh Shastry
Bug #87557 marked as duplicate of this one.
[29 Nov 2017 9:55] Sveta Smirnova
I see there is not ChangeLog entry for version 5.6.36 which may indicate this bug is fixed.
[29 Nov 2017 10:18] Umesh Shastry
Hi Sveta,

Thank you for the feedback. I see from internal bug updates that Bug #24585978(Bug #82842) is fixed in 5.6.36, 5.7.18 and 8.0.1-dmr and same is reflected in the 5.7.18/8.0.1-dmr change log but seems to be missing in 5.6.36 change log. 

InnoDB: An error in code related to table statistics raised an assertion in the dict0stats.cc source file. (Bug #24585978)

https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-18.html
https://dev.mysql.com/doc/relnotes/mysql/8.0/en/news-8-0-1.html

I'll pass on this to concern person on this.

Thanks,
Umesh
[29 Nov 2017 12:47] Umesh Shastry
Daniel added the changelog entry to the 5.6.36 Release Notes. It should appear online soon.

Thanks,
Umesh