← Back to team overview

maria-discuss team mailing list archive

Re: Horrendeous InnoDB crash

 

The log starts just with:

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 binary
distribution

No errors at startup (database prefilled with manually run retrieval
script). Then, at 16:47, when the scheduled retrieve task starts for the
first time, the log adds:

InnoDB: Error: trying to access page number 250370 in space 69,
InnoDB: space name news/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 line 5866

So, with almost certainty, the scheduled task corrupts the database.
Especially since I was now (unfortunately) able to replicate the same
conditions for the crash. But there's nothing in that php script that could
normally do that. (Especially since it runs manually just fine, without
corrupting anything). The scheduled task runs as me, but is 'hidden', though
(i.e., doesn't open a console).


-----Original Message-----
From: Chris Calender [mailto:chris.calender@xxxxxxxxxxx] 
Sent: Monday, June 6, 2016 17:44
To: Mark <asarian@xxxxxxxxx>; maria-discuss@xxxxxxxxxxxxxxxxxxx
Subject: Re: [Maria-discuss] Horrendeous InnoDB crash

Hello,

No need for the config file, you have corruption in your tablespace, hence
the crash.

It starts up here, at 16:39:16:

 > 2016-06-06 16:39:16 1e24 InnoDB: Warning: Using...
 > ...
 > 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 binary
distribution

At the exact same time, we see the corruption (thus this corruption was both
detected and mentioned at startup):

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

Then, about 8 minutes later, you attempt to select from the same table that
is corrupted ("spotweb.commentsxover"), hence the immediate assertion
failure:

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

And the stack trace confirms the query:

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

Since that is the only table referenced as being corrupted, you could
probably get by with dropping it and then restoring it from a backup. 
If you do not have a current backup, then you will need to enable
innodb_force_recovery (read below link for details), then dump from the
table, dumping "around" the corruption using mysqldump with ORDER BY pk and
LIMIT, and then once you have as much data as possible, then DROP the table,
and import your dump.

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

Hope this helps!

Best wishes,
Chris


On 6/6/2016 11:17 AM, Mark 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 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 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()
>
> mysqld.exe!?get_ctx@MDL_ticket@@QBEPAVMDL_context@@XZ()
>
> mysqld.exe!?functype@Item_func_dyncol_create@@UBE?AW4Functype@Item_fun
> c@@XZ()
>
> 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()
>
> mysqld.exe!?get_trg_event_map@Update_rows_log_event@@UAEEXZ()
>
> mysqld.exe!?ha_open@handler@@QAEHPAUTABLE@@PBDHI@Z()
>
> mysqld.exe!?open_table_from_share@@YA?AW4open_frm_error@@PAVTHD@@PAUTA
> BLE_SHARE@@PBDIIIPAUTABLE@@_N@Z()
>
> mysqld.exe!?open_table@@YA_NPAVTHD@@PAUTABLE_LIST@@PAVOpen_table_conte
> xt@@@Z()
>
> mysqld.exe!?recover_from_failed_open@Open_table_context@@QAE_NXZ()
>
> mysqld.exe!?open_tables@@YA_NPAVTHD@@ABUDDL_options_st@@PAPAUTABLE_LIS
> T@@PAIIPAVPrelocking_strategy@@@Z()
>
> mysqld.exe!?open_and_lock_tables@@YA_NPAVTHD@@ABUDDL_options_st@@PAUTA
> BLE_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_me
> rge_intersection=on,index_merge_sort_intersection=off,engine_condition
> _pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_wit
> h_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=o
> n,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,jo
> in_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,tab
> le_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@xxxxxxxxx]
> *Sent:* Monday, June 6, 2016 16:16
> *To:* Mark <asarian@xxxxxxxxx>
> *Cc:* maria-discuss@xxxxxxxxxxxxxxxxxxx
> *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@xxxxxxxxx 
> <mailto:asarian@xxxxxxxxx>> 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@xxxxxxxxx]
>     *Sent:* Monday, June 6, 2016 11:39
>     *To:* Mark <asarian@xxxxxxxxx <mailto:asarian@xxxxxxxxx>>;
>     maria-discuss@xxxxxxxxxxxxxxxxxxx
>     <mailto:maria-discuss@xxxxxxxxxxxxxxxxxxx>
>     *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,
>
>         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 08:47:46 e08  InnoDB: Assertion failure in thread
>         3592 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  8:47:46 [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.
>
>
>
>
>
>         _______________________________________________
>
>         Mailing list:https://launchpad.net/~maria-discuss
>
>         Post to     :maria-discuss@xxxxxxxxxxxxxxxxxxx
>         <mailto:maria-discuss@xxxxxxxxxxxxxxxxxxx>
>
>         Unsubscribe :https://launchpad.net/~maria-discuss
>
>         More help   :https://help.launchpad.net/ListHelp
>
>     _______________________________________________
>     Mailing list: https://launchpad.net/~maria-discuss
>     Post to     : maria-discuss@xxxxxxxxxxxxxxxxxxx
>     <mailto:maria-discuss@xxxxxxxxxxxxxxxxxxx>
>     Unsubscribe : https://launchpad.net/~maria-discuss
>     More help   : https://help.launchpad.net/ListHelp
>
>
>
> _______________________________________________
> Mailing list: https://launchpad.net/~maria-discuss
> Post to     : maria-discuss@xxxxxxxxxxxxxxxxxxx
> Unsubscribe : https://launchpad.net/~maria-discuss
> More help   : https://help.launchpad.net/ListHelp
>


--
Chris Calender, M.S., Principal Support Engineer MariaDB Corporation



References