maria-discuss team mailing list archive

["Mark" <asarian@xxxxxxxxx>]

No, honestly, that wasn't it. :) As per the Jira link Jan Lindström provided, the data becomes corrupted as a result of certain queries! (I didn't know why, but it was pretty repeatable: wipe the database, re-populate it again, run the scheduled script, and bam, the 'xovers' table immediately crashes).

Without the fix provided in 10.1.14, I would have never been able to solve this (except maybe to revert to myisam).

A big thanks again to Jan Lindström, for identifying the issue, and to everyone else willing to think along with me! :)


-----Original Message-----
From: Jan Steinman [mailto:Jan@xxxxxxxxxxxxxx] 
Sent: Tuesday, June 7, 2016 01:05
To: Mark <asarian@xxxxxxxxx>
Cc: chris@xxxxxxxxxxx; maria-discuss@xxxxxxxxxxxxxxxxxxx
Subject: Re: [Maria-discuss] Horrendeous InnoDB crash

> So, with almost certainty, the scheduled task corrupts the database.

No, it looks to me like the scheduled task is trying to access corrupted data — important distinction!

To rule this out, dump the database, move your datadir to a safe place, run mysql_install_db, then load the dump: “mysql <dump.sql”.

Then run your scheduled task again. My bet is it will work fine, then.

::::  
:::: Jan Steinman, EcoReality Co-op ::::

> On 2016-06-06, at 08:59, Mark <asarian@xxxxxxxxx> wrote:
> 
> 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_fu
>> n
>> 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@@PAUT
>> A
>> BLE_SHARE@@PBDIIIPAUTABLE@@_N@Z()
>> 
>> mysqld.exe!?open_table@@YA_NPAVTHD@@PAUTABLE_LIST@@PAVOpen_table_cont
>> e
>> xt@@@Z()
>> 
>> mysqld.exe!?recover_from_failed_open@Open_table_context@@QAE_NXZ()
>> 
>> mysqld.exe!?open_tables@@YA_NPAVTHD@@ABUDDL_options_st@@PAPAUTABLE_LI
>> S
>> T@@PAIIPAVPrelocking_strategy@@@Z()
>> 
>> mysqld.exe!?open_and_lock_tables@@YA_NPAVTHD@@ABUDDL_options_st@@PAUT
>> A
>> 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_m
>> e 
>> rge_intersection=on,index_merge_sort_intersection=off,engine_conditio
>> n 
>> _pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_wi
>> t 
>> 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=o
>> n 
>> ,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,j
>> o 
>> in_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,ta
>> b 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
> 
> 
> _______________________________________________
> 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