Bug #88374 don't log: "pure virtual method called": terminate correctly
Submitted: 6 Nov 2017 10:44 Modified: 22 Oct 2020 14:26
Reporter: Simon Mudd (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Errors Severity:S4 (Feature request)
Version:5.7 OS:Any
Assigned to: CPU Architecture:Any
Tags: error termination, mysqld, pure virtual function

[6 Nov 2017 10:44] Simon Mudd
Description:
Error seen when storage failed while mysqld was trying to start up:

2017-11-06 07:11:57 36400 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-11-06 07:11:57 36400 [Note] InnoDB: Using Linux native AIO
2017-11-06 07:11:57 36400 [Note] InnoDB: Not using CPU crc32 instructions
2017-11-06 07:11:57 36400 [Note] InnoDB: Initializing buffer pool, size = 21.0G
2017-11-06 07:11:57 36400 [Note] InnoDB: Setting NUMA memory policy to MPOL_INTERLEAVE
2017-11-06 07:12:00 36400 [Note] InnoDB: Setting NUMA memory policy to MPOL_DEFAULT
2017-11-06 07:12:00 36400 [Note] InnoDB: Completed initialization of buffer pool
2017-11-06 07:12:00 36400 [Note] InnoDB: Highest supported file format is Barracuda.
2017-11-06 07:12:01 36400 [Note] InnoDB: 128 rollback segment(s) are active.
2017-11-06 07:12:01 36400 [Note] InnoDB: Waiting for purge to start
2017-11-06 07:12:01 36400 [Note] InnoDB: 5.6.37 started; log sequence number 18067884144984
2017-11-06 07:12:01 7f674e7fc700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool
2017-11-06 07:12:01 36400 [Note] Server hostname (bind-address): '::'; port: 3306
2017-11-06 07:12:01 36400 [Note]   - '::' resolves to '::';
2017-11-06 07:12:01 36400 [Note] Server socket created on IP: '::'.
2017-11-06 07:12:01 36400 [Note] Event Scheduler: Loaded 1 event
2017-11-06 07:12:01 36400 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.37-log'  socket: 'mysql.sock'  port: 3306  MySQL Community Server (GPL)
2017-11-06 07:12:01 36400 [Note] Event Scheduler: scheduler thread started with id 1
2017-11-06 07:12:43 7f674e7fc700 InnoDB: Buffer pool(s) load completed at 171106  7:12:43
2017-11-06 10:48:04 36400 [ERROR] InnoDB: Error in system call pread(). The operating system error number is 5.
2017-11-06 10:48:04 7f674cdf1700  InnoDB: Operating system error number 5 in a file operation.
InnoDB: Error number 5 means 'Input/output error'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2017-11-06 10:48:04 36400 [ERROR] InnoDB: File (unknown): 'read' returned OS error 105. Cannot continue operation
2017-11-06 10:48:04 36400 [ERROR] InnoDB: Error in system call pread(). The operating system error number is 5.
2017-11-06 10:48:04 7f674cc2a700  InnoDB: Operating system error number 5 in a file operation.
InnoDB: Error number 5 means 'Input/output error'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2017-11-06 10:48:04 36400 [ERROR] InnoDB: File (unknown): 'read' returned OS error 105. Cannot continue operation
pure virtual method called
terminate called without an active exception

I do not think the code should talk about pure virtual methods being called and so should just exit. Clearly there's a gap here in the code handling this type of issue. In the end mysqld stops (it can't do much else) but the last 2 lines should be reported properly.

How to repeat:
see above.

Suggested fix:
Terminate correctly even under error circumstances such as this.
I'm not sure if further logging was going to take place as this error stopped everything.
[22 Oct 2020 14:26] MySQL Verification Team
Hi Mr. Mudd,

Thank you for your feature request.

We find that it is actually quite a good idea.

Verified as reported.