Re: [Maria-discuss] Horrendeous InnoDB crash

6 Jun 2016

      This is a documented bug?! Can you please point me to it?! I haven’t found anything about it.

From: Jan Lindström [mailto:jan.lindstrom@mariadb.com] 
Sent: Monday, June 6, 2016 18:20
To: Mark <asarian@xs4all.nl>
Cc: Justin Swanhart <greenlion@gmail.com>; Maria Discuss <maria-discuss@lists.launchpad.net>
Subject: Re: [Maria-discuss] Horrendeous InnoDB crash

Hi,

This looks like a bug that has been fixed on MariaDB 10.1.14, can you try ?

R: Jan

On Mon, Jun 6, 2016 at 6:39 PM, Mark <asarian@xs4all.nl <mailto:asarian@xs4all.nl> > wrote:

Here it is; came pretty stock this way with XAMPP (made some minor adjustments for key cache and such, but crashed on pure stock too)

It’s really the scheduled task that makes it crash, but I can’t fathom why.

From: Justin Swanhart [mailto:greenlion@gmail.com <mailto:greenlion@gmail.com> ] 
Sent: Monday, June 6, 2016 17:30

To: Mark <asarian@xs4all.nl <mailto:asarian@xs4all.nl> >
Cc: maria-discuss@lists.launchpad.net <mailto:maria-discuss@lists.launchpad.net> 
Subject: Re: [Maria-discuss] Horrendeous InnoDB crash

Please attach your my.cnf (perhaps it is my.ini on Windows)

Sent from my iPhone

On Jun 6, 2016, at 11:17 AM, Mark <asarian@xs4all.nl <mailto:asarian@xs4all.nl> > wrote:

And yet the same 9*&^%^&*()_ crash (see below). I’m beginning to get real tired of this.

The corruption starts almost immediately upon running a scheduled task that’s retrieving posts (at 16:47 hours). It’s the same task I ran manually first. There’s absolutely no reason why a simple scheduled post retrieval script should immediately corrupt MariaDB beyond all recognition. The scheduled task consists of nothing more than a script (that runs as me), like:

c:\xampp\php\php.exe c:\xampp\htdocs\news\retrieve.php –force

It runs every 30 mins.

And no, no write-delays, or computer crashes that preceded this.

2016-06-06 15:52:27 3552 [Note] C:\xampp\mysql\bin\mysqld.exe: Normal shutdown

2016-06-06 15:52:27 3552 [Note] Event Scheduler: Purging the queue. 0 events

2016-06-06 15:52:27 3504 [Note] InnoDB: FTS optimize thread exiting.

2016-06-06 15:52:27 3552 [Note] InnoDB: Starting shutdown...

2016-06-06 15:52:29 3552 [Note] InnoDB: Shutdown completed; log sequence number 6767908697

2016-06-06 15:52:29 3552 [Note] C:\xampp\mysql\bin\mysqld.exe: Shutdown complete

2016-06-06 16:39:16 1e24 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.

2016-06-06 16:39:16 7716 [Note] InnoDB: Using mutexes to ref count buffer pool pages

2016-06-06 16:39:16 7716 [Note] InnoDB: The InnoDB memory heap is disabled

2016-06-06 16:39:16 7716 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions

2016-06-06 16:39:16 7716 [Note] InnoDB: Memory barrier is not used

2016-06-06 16:39:16 7716 [Note] InnoDB: Compressed tables use zlib 1.2.3

2016-06-06 16:39:16 7716 [Note] InnoDB: Using generic crc32 instructions

2016-06-06 16:39:16 7716 [Note] InnoDB: Initializing buffer pool, size = 16.0M

2016-06-06 16:39:16 7716 [Note] InnoDB: Completed initialization of buffer pool

2016-06-06 16:39:16 7716 [Note] InnoDB: Highest supported file format is Barracuda.

2016-06-06 16:39:16 7716 [Note] InnoDB: 128 rollback segment(s) are active.

2016-06-06 16:39:16 7716 [Note] InnoDB: Waiting for purge to start

2016-06-06 16:39:16 7716 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.28-76.1 started; log sequence number 6767908697

2016-06-06 16:39:16 7100 [Note] InnoDB: Dumping buffer pool(s) not yet started

2016-06-06 16:39:16 7716 [Note] Plugin 'FEEDBACK' is disabled.

2016-06-06 16:39:16 7716 [Note] Server socket created on IP: '::'.

2016-06-06 16:39:16 7716 [Note] C:\xampp\mysql\bin\mysqld.exe: ready for connections.

Version: '10.1.13-MariaDB'  socket: ''  port: 3306  mariadb.org <http://mariadb.org>  binary distribution

InnoDB: Error: trying to access page number 250370 in space 69,

InnoDB: space name spotweb/commentsxover,

InnoDB: which is outside the tablespace bounds.

InnoDB: Byte offset 0, len 16384, i/o type 10.

InnoDB: If you get this error at mysqld startup, please check that

InnoDB: your my.cnf matches the ibdata files that you have in the

InnoDB: MySQL server.

2016-06-06 16:47:38 a74  InnoDB: Assertion failure in thread 2676 in file fil0fil.cc <http://fil0fil.cc>  line 5866

InnoDB: We intentionally generate a memory trap.

InnoDB: Submit a detailed bug report to http://bugs.mysql.com.

InnoDB: If you get repeated assertion failures or crashes, even

InnoDB: immediately after the mysqld startup, there may be

InnoDB: corruption in the InnoDB tablespace. Please refer to

InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html

InnoDB: about forcing recovery.

160606 16:47:38 [ERROR] mysqld got exception 0x80000003 ;

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.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs

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.

Server version: 10.1.13-MariaDB

key_buffer_size=16777216

read_buffer_size=262144

max_used_connections=1

max_threads=1001

thread_count=1

It is possible that mysqld could use up to 

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 787100 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0x4af7270

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...

mysqld.exe!my_parameter_handler()

mysqld.exe!my_mb_ctype_mb()

mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ() <mailto:mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ()> 

mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ() <mailto:mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ()> 

mysqld.exe!?functype@Item_func_dyncol_create@@UBE?AW4Functype@Item_func@@XZ() <mailto:mysqld.exe!?functype@Item_func_dyncol_create@@UBE?AW4Functype@Item_func@@XZ()> 

mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ() <mailto:mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ()> 

mysqld.exe!??0Global_read_lock@@QAE@XZ()

mysqld.exe!??0Global_read_lock@@QAE@XZ()

mysqld.exe!?get_trg_event_map@Update_rows_log_event@@UAEEXZ() <mailto:mysqld.exe!?get_trg_event_map@Update_rows_log_event@@UAEEXZ()> 

mysqld.exe!?get_trg_event_map@Update_rows_log_event@@UAEEXZ() <mailto:mysqld.exe!?get_trg_event_map@Update_rows_log_event@@UAEEXZ()> 

mysqld.exe!?ha_open@handler@@QAEHPAUTABLE@@PBDHI@Z() <mailto:mysqld.exe!?ha_open@handler@@QAEHPAUTABLE@@PBDHI@Z()> 

mysqld.exe!?open_table_from_share@@YA?AW4open_frm_error@@PAVTHD@@PAUTABLE_SHARE@@PBDIIIPAUTABLE@@_N@Z()

mysqld.exe!?open_table@@YA_NPAVTHD@@PAUTABLE_LIST@@PAVOpen_table_context@@@Z()

mysqld.exe!?recover_from_failed_open@Open_table_context@@QAE_NXZ() <mailto:mysqld.exe!?recover_from_failed_open@Open_table_context@@QAE_NXZ()> 

mysqld.exe!?open_tables@@YA_NPAVTHD@@ABUDDL_options_st@@PAPAUTABLE_LIST@@PAIIPAVPrelocking_strategy@@@Z()

mysqld.exe!?open_and_lock_tables@@YA_NPAVTHD@@ABUDDL_options_st@@PAUTABLE_LIST@@_NIPAVPrelocking_strategy@@@Z()

mysqld.exe!??0Table_scope_and_contents_source_st@@QAE@ABU0@@Z()

mysqld.exe!?mysql_execute_command@@YAHPAVTHD@@@Z()

mysqld.exe!?mysql_parse@@YAXPAVTHD@@PADIPAVParser_state@@@Z()

mysqld.exe!?dispatch_command@@YA_NW4enum_server_command@@PAVTHD@@PADI@Z()

mysqld.exe!?do_command@@YA_NPAVTHD@@@Z()

mysqld.exe!?threadpool_process_request@@YAHPAVTHD@@@Z()

mysqld.exe!?tp_end@@YAXXZ()

KERNEL32.DLL!SetUserGeoID()

ntdll.dll!TpSimpleTryPost()

ntdll.dll!EtwNotificationRegister()

KERNEL32.DLL!BaseThreadInitThunk()

ntdll.dll!RtlUnicodeStringToInteger()

ntdll.dll!RtlUnicodeStringToInteger()

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort.

Query (0x4b01740): SELECT messageid FROM commentsxover ORDER BY id DESC LIMIT 5000

Connection ID (thread ID): 2

Status: NOT_KILLED

Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains

information that should help you find out what is causing the crash.

From: Justin Swanhart [mailto:greenlion@gmail.com] 
Sent: Monday, June 6, 2016 16:16
To: Mark <asarian@xs4all.nl <mailto:asarian@xs4all.nl> >
Cc: maria-discuss@lists.launchpad.net <mailto:maria-discuss@lists.launchpad.net> 
Subject: Re: [Maria-discuss] Horrendeous InnoDB crash

Hi,

Do you have write-behind caching turned on?  Do you have RAID card without BBU?  Did your computer crash?  If the OS or hardware (like IDE HDD cache) lies about actually writing to disk, InnoDB can become corrupted, and this is not the fault of innodb.  Be aware that if this is a VM, many VM lie about disk writes, a "feature" you must turn off.

Sent from my iPhone

On Jun 6, 2016, at 6:23 AM, Mark <asarian@xs4all.nl <mailto:asarian@xs4all.nl> > wrote:

Sorry I wiped the database; but it got to the point where MariaDB immediately crashed upon startup (so the usual repair attempts were futile, as they all kinda assume a MariaDB server that’s up and running). I have years of experience (FreeBSD) with myisam tables; but a crash like this is a first for me, really, where the entire database was foobarred to the point MariaDB wouldn’t even start any more.

Thanks for creating the bug report. I shall investigate myself too, in trying to find a way to integrate the MariaDB shutdown gracefully (in UNIX this is all much simpler and straightforward).

-        Mark

From: Vladislav Vaintroub [mailto:vvaintroub@gmail.com] 
Sent: Monday, June 6, 2016 11:39
To: Mark <asarian@xs4all.nl <mailto:asarian@xs4all.nl> >; maria-discuss@lists.launchpad.net <mailto:maria-discuss@lists.launchpad.net> 
Subject: Re: [Maria-discuss] Horrendeous InnoDB crash

Yes, it is possible that Windows does not give enough time to MariaDB to shut down gracefully. I just created a task for this one here https://jira.mariadb.org/browse/MDEV-10183.

Still, Innodb should handle this situation gracefully, and recover on startup, so what you see is a bug. It is a pity that you wiped down the database, it would be useful for a bug report.

On 06.06.2016 11:08, Mark wrote:

Got a huge crash today, right after initializing my first MariaDB database (see below). Got several more errors about tables having crashed later on, and MariaDB wouldn't even start up any more (I wound up wiping the entire database).

So, my question is, what could cause MariaDB to fail so horrendeously?! I though InnoDB was supposed to be *better* than myisam!? Is is because maybe Windows 10 doesn't give MariaDB enough time to shut down gracefully? Could it be because a Windows scheduler job (potentially) aborts the fetcher script when it's still running? (Again, I though InnoDB was supposed to be transaction-safe).

In its current state, MariaDB is completely unusable for me.

And no, I don't have hard disk errors. :)

Seriously, though, I could use some major insight!

Thanks.

2016-06-06 10:32:15 2552 [Note] Server socket created on IP: '::'.

2016-06-06 10:32:15 2552 [Note] C:\xampp\mysql\bin\mysqld.exe: ready for connections.

Version: '10.1.13-MariaDB'  socket: ''  port: 3306  mariadb.org <http://mariadb.org>  binary distribution

InnoDB: Error: trying to access page number 251010 in space 69,

InnoDB: space name news/commentsxover,