Dual-upgrade (OpenEMR 4.2.1 -> 5.0.1) failed with MariaDB crash

question

(Troy) #1

Situation
I completed the OpenEMR upgrade to 5.0.1 (Patch 7) and the XAMPP upgrade and verified that I was able to log in, read patient records and log out. I shutdown Apache and MariaDB, copied the entire XAMPP directory to an external disk and shut down the computer. The next day, MariaDB crashed when the first user (me) tried to access the login screen. (The MariaDB error log is below.)

This OpenEMR installation has been in use for several years. I noted during the upgrade that the log table is 6GB. I also note that XAMPP 5.6.0 contains MariaDB 10.1.13. The stack trace is similar to, but not a perfect match for this MariaDB issue: https://jira.mariadb.org/browse/MDEV-9977

I believe that the crash is due to MariaDB failing to properly handle files larger than 4GB. I suspect that I have several options:

  • Truncate the log table to less than 4GB.
  • Use a 64-bit version of MariaDB. I’m not sure I want to attempt surgery on XAMPP.
  • Use a version of XAMPP which does not contain a version of MariaDB which has this bug.

Which of these options makes the most sense? Is there a better option which I’ve missed?

Thanks for your feedback.

OpenEMR Version
I’m using OpenEMR version 4.2.1 on XAMPP 1.8.2 and upgrading to 5.0.1 on XAMPP 5.6.0.

Browser:
I’m using: Google Chrome 73, Microsoft Edge 44

Operating System
I’m using Windows 8.1 (64-bit) and Windows 10 (64-bit)

Logs
From mysql_error.log:

2019-04-14 09:35:09 6d8 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.
2019-04-14  9:35:09 1752 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2019-04-14  9:35:09 1752 [Note] InnoDB: The InnoDB memory heap is disabled
2019-04-14  9:35:09 1752 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-04-14  9:35:09 1752 [Note] InnoDB: Memory barrier is not used
2019-04-14  9:35:09 1752 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-04-14  9:35:09 1752 [Note] InnoDB: Using generic crc32 instructions
2019-04-14  9:35:09 1752 [Note] InnoDB: Initializing buffer pool, size = 256.0M
2019-04-14  9:35:09 1752 [Note] InnoDB: Completed initialization of buffer pool
2019-04-14  9:35:09 1752 [Note] InnoDB: Highest supported file format is Barracuda.
2019-04-14  9:35:10 1752 [Note] InnoDB: 128 rollback segment(s) are active.
2019-04-14  9:35:10 1752 [Note] InnoDB: Waiting for purge to start
2019-04-14  9:35:11 1752 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.28-76.1 started; log sequence number 8383372683
2019-04-14  9:35:11 7840 [Note] InnoDB: Dumping buffer pool(s) not yet started
2019-04-14  9:35:11 1752 [Note] Plugin 'FEEDBACK' is disabled.
2019-04-14  9:35:11 1752 [Note] Server socket created on IP: '::'.
2019-04-14  9:35:11 1752 [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 257152 in space 682,
InnoDB: space name openemr/log,
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.
2019-04-14 09:36:36 3748  InnoDB: Assertion failure in thread 14152 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.
190415  9:36:36 [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=2
max_threads=1001
thread_count=2
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: 0x0x1605aff0
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_func@@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@@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()
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!?mysql_insert@@YA_NPAVTHD@@PAUTABLE_LIST@@AAV?$List@VItem@@@@AAV?$List@V?$List@VItem@@@@@@22W4enum_duplicates@@_N@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!SetUserGeoName()
ntdll.dll!RtlAcquireResourceExclusive()
ntdll.dll!RtlAcquirePebLock()
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlGetAppContainerNamedObjectPath()
ntdll.dll!RtlGetAppContainerNamedObjectPath()

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x16062388): insert into log (date, event,category, user, groupname, comments, patient_id, success, checksum,crt_user) values ( '2019-04-14 05:36:36', 'security-administration-select', 'Security', '','','l7OEA9DGwCXb+K0avyHhPmSm51kTbAqppbr17O1wnwdJTlhghts7gnTHnqLmKeK6YlF1CwCavopfwlqKmDZoTg==','0','1','','')
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.

(Troy) #2

I resolved the issue by truncating the log and log_comment_encrypt tables to only include values from the current year, taking care not to break any relationship between the log.id and log_comment_encrypt.log_id columns. (I have not read the code to see if such a relationship exists, but it seems logical.)