2019-07-29 23:25:12 65 [Note] Start binlog_dump to slave_server(2), pos(Master-bin.000616, 1808629)
2019-07-29 23:37:53 251 [Warning] Access denied for user 'zzdomainadmin'@'127.0.0.1' (using password: NO)
at 23:15:11 the following appeared in the application event log on the server
Faulting application mysqld.exe, version 10.3.12.0, time stamp 0x5c2f7f3f, faulting module ntdll.dll, version 6.0.6003.20562, time stamp 0x5cfa798d, exception code 0xc000000d, fault offset 0x00087471, process id 0x124, application start time 0x01d545acd61aec10.
There appears to be no hardware issue (it is running on a Virtual Machine under vmware ESXi), and all other VMs and other processes are ok; no ballooning memory; it had plenty of memory available etc...
The DB does run in Binlog mode and has a standby DB
I have done a mysqlcheck --all-databases and all appears to be ok
Can you urgently help please?
Is this a known bug and is it fixed in a later version of MariaDB and if so which version please?
Sorry for all the questions, I am panicking a great deal.
Hi, it has not reoccurred;.
Sorry there was was no minidump produced from the crash.
I do not have the query that caused this as we do not log all the queries in our production environment as that would have a severe performance impact and we would not have enough storage to log every enquiry.
Any ideas on cause, and if this is fixed in a later release please?
Stuart Slater
added a comment - - edited Hi, it has not reoccurred;.
Sorry there was was no minidump produced from the crash.
I do not have the query that caused this as we do not log all the queries in our production environment as that would have a severe performance impact and we would not have enough storage to log every enquiry.
Any ideas on cause, and if this is fixed in a later release please?
If these are of use; how do I upload such large files to this Jira please?
thank you for all your very valuable support and guidance.
Stuart Slater
added a comment - - edited Hi , just a thought; i have logbin enabled and have the logbin files on the day of the crash as follows (the crash was at 23:15:11 on 29/07/2019) :-
Logbin files from day of Crash
29/07/2019 13:10 214,745,634 Master-bin.000614
29/07/2019 23:15 146,246,161 Master-bin.000615
29/07/2019 23:24 1,808,652 Master-bin.000616
If these are of use; how do I upload such large files to this Jira please?
thank you for all your very valuable support and guidance.
Taking Master-bin.000615 the last set of entries in this file are:-
The crash occured at 23:15:10, which I have highlighted below; these are standard statements where transaction perf stats information is written to the Partitioned Table (partitioned in 31 partitions) - RJIS_JQI_PERF ; there is a pre-insert trigger on the table that populates the Partition Number column with the day number of the month of the date.
master-bin.000615 last set of entries
# at 146198196
#190729 23:14:44 server id 1 end_log_pos 146198820 CRC32 0x25bf8941 Query thread_id=84 exec_time=0 error_code=0
Experienced a crash of our primary MariaDB DB this evening at 23:15 , please can you help?
from the MariaDB log file the crash details are:-
190729 23:15:10 [ERROR] mysqld got exception 0xc000000d ;
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.
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.3.12-MariaDB-log
key_buffer_size=8388608
read_buffer_size=36864
max_used_connections=266
max_threads=65537
thread_count=270
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2381676 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
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...
ntdll.dll!EtwNotificationUnregister()
mysqld.exe!timer_callback()[threadpool_win.cc:419]
ntdll.dll!RtlIsCriticalSectionLockedByThread()
ntdll.dll!RtlSizeHeap()
kernel32.dll!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
2019-07-29 23:18:21 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
2019-07-29 23:18:21 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-07-29 23:18:21 0 [Note] InnoDB: Uses event mutexes
2019-07-29 23:18:21 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-07-29 23:18:21 0 [Note] InnoDB: Number of pools: 1
2019-07-29 23:18:21 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019-07-29 23:18:21 0 [Note] InnoDB: Initializing buffer pool, total size = 384M, instances = 1, chunk size = 128M
2019-07-29 23:18:21 0 [Note] InnoDB: Completed initialization of buffer pool
2019-07-29 23:18:21 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=150962067982
2019-07-29 23:18:22 0 [Note] InnoDB: Transaction 294057132 was in the XA prepared state.
2019-07-29 23:18:22 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo
2019-07-29 23:18:22 0 [Note] InnoDB: Trx id counter is 294057133
2019-07-29 23:18:22 0 [Note] InnoDB: Starting final batch to recover 18 pages from redo log.
2019-07-29 23:18:22 0 [Note] InnoDB: Last binlog file 'd:\MariaDB\master\logbin\Master-bin.000615', position 146245658
2019-07-29 23:18:26 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2019-07-29 23:18:26 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2019-07-29 23:18:26 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2019-07-29 23:18:26 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019-07-29 23:18:26 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-07-29 23:18:26 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-07-29 23:18:26 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
2019-07-29 23:18:26 0 [Note] InnoDB: 10.3.12 started; log sequence number 150962117583; transaction id 294057135
2019-07-29 23:18:26 0 [Note] InnoDB: Loading buffer pool(s) from D:\MariaDB\data\ib_buffer_pool
2019-07-29 23:18:26 0 [Note] Plugin 'FEEDBACK' is disabled.
2019-07-29 23:18:26 0 [Note] Recovering after a crash using d:/MariaDB/master/logbin/Master-bin
2019-07-29 23:18:35 0 [Note] InnoDB: Buffer pool(s) load completed at 190729 23:18:35
2019-07-29 23:18:44 0 [Note] Starting crash recovery...
2019-07-29 23:18:44 0 [Note] InnoDB: Starting recovery for XA transactions...
2019-07-29 23:18:44 0 [Note] InnoDB: Transaction 294057132 in prepared state after recovery
2019-07-29 23:18:44 0 [Note] InnoDB: Transaction contains changes to 1 rows
2019-07-29 23:18:44 0 [Note] InnoDB: 1 transactions in prepared state after recovery
2019-07-29 23:18:44 0 [Note] Found 1 prepared transaction(s) in InnoDB
2019-07-29 23:18:44 0 [Note] Crash recovery finished.
2019-07-29 23:18:44 0 [Note] Server socket created on IP: '::'.
2019-07-29 23:18:44 0 [Warning] 'user' entry 'root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:18:44 0 [Warning] 'proxies_priv' entry '@% root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:18:44 0 [Note] Reading of all Master_info entries succeded
2019-07-29 23:18:44 0 [Note] Added new Master_info '' to hash table
2019-07-29 23:18:44 0 [Note] D:\MariaDB\bin\mysqld.exe: ready for connections.
Version: '10.3.12-MariaDB-log' socket: '' port: 3306 mariadb.org binary distribution
2019-07-29 23:19:23 81 [Note] Start binlog_dump to slave_server(2), pos(Master-bin.000615, 146246161)
2019-07-29 23:19:52 90 [Warning] Access denied for user 'root'@'127.0.0.1' (using password: YES)
2019-07-29 23:24:11 0 [Note] D:\MariaDB\bin\mysqld.exe (initiated by: unknown): Normal shutdown
2019-07-29 23:24:11 0 [Note] Event Scheduler: Purging the queue. 0 events
2019-07-29 23:24:11 0 [Note] InnoDB: FTS optimize thread exiting.
2019-07-29 23:24:11 0 [Note] InnoDB: Starting shutdown...
2019-07-29 23:24:11 0 [Note] InnoDB: Dumping buffer pool(s) to D:\MariaDB\data\ib_buffer_pool
2019-07-29 23:24:11 0 [Note] InnoDB: Instance 0, restricted to 6144 pages due to innodb_buf_pool_dump_pct=25
2019-07-29 23:24:11 0 [Note] InnoDB: Buffer pool(s) dump completed at 190729 23:24:11
2019-07-29 23:24:12 0 [Note] InnoDB: Shutdown completed; log sequence number 150964259475; transaction id 294063316
2019-07-29 23:24:12 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019-07-29 23:24:12 0 [Note] D:\MariaDB\bin\mysqld.exe: Shutdown complete
2019-07-29 23:24:16 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
2019-07-29 23:24:16 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-07-29 23:24:16 0 [Note] InnoDB: Uses event mutexes
2019-07-29 23:24:16 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-07-29 23:24:16 0 [Note] InnoDB: Number of pools: 1
2019-07-29 23:24:16 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019-07-29 23:24:16 0 [Note] InnoDB: Initializing buffer pool, total size = 384M, instances = 1, chunk size = 128M
2019-07-29 23:24:16 0 [Note] InnoDB: Completed initialization of buffer pool
2019-07-29 23:24:16 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2019-07-29 23:24:16 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-07-29 23:24:16 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-07-29 23:24:16 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
2019-07-29 23:24:16 0 [Note] InnoDB: 10.3.12 started; log sequence number 150964259475; transaction id 294063318
2019-07-29 23:24:16 0 [Note] InnoDB: Loading buffer pool(s) from D:\MariaDB\data\ib_buffer_pool
2019-07-29 23:24:16 0 [Note] Plugin 'FEEDBACK' is disabled.
2019-07-29 23:24:16 0 [Note] Server socket created on IP: '::'.
2019-07-29 23:24:16 0 [Warning] 'user' entry 'root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:24:16 0 [Warning] 'proxies_priv' entry '@% root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:24:16 0 [Note] Reading of all Master_info entries succeded
2019-07-29 23:24:16 0 [Note] Added new Master_info '' to hash table
2019-07-29 23:24:16 0 [Note] D:\MariaDB\bin\mysqld.exe: ready for connections.
Version: '10.3.12-MariaDB-log' socket: '' port: 3306 mariadb.org binary distribution
2019-07-29 23:24:31 0 [Note] InnoDB: Buffer pool(s) load completed at 190729 23:24:31
2019-07-29 23:25:12 65 [Note] Start binlog_dump to slave_server(2), pos(Master-bin.000616, 1808629)
2019-07-29 23:37:53 251 [Warning] Access denied for user 'zzdomainadmin'@'127.0.0.1' (using password: NO)
at 23:15:11 the following appeared in the application event log on the server
Faulting application mysqld.exe, version 10.3.12.0, time stamp 0x5c2f7f3f, faulting module ntdll.dll, version 6.0.6003.20562, time stamp 0x5cfa798d, exception code 0xc000000d, fault offset 0x00087471, process id 0x124, application start time 0x01d545acd61aec10.
There appears to be no hardware issue (it is running on a Virtual Machine under vmware ESXi), and all other VMs and other processes are ok; no ballooning memory; it had plenty of memory available etc...
The DB does run in Binlog mode and has a standby DB
I have done a mysqlcheck --all-databases and all appears to be ok
Can you urgently help please?
Is this a known bug and is it fixed in a later version of MariaDB and if so which version please?
Sorry for all the questions, I am panicking a great deal.
Experienced a crash of our primary MariaDB DB this evening at 23:15 , please can you help?
from the MariaDB log file the crash details are:-
{noformat}
190729 23:15:10 [ERROR] mysqld got exception 0xc000000d ;
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.
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.3.12-MariaDB-log
key_buffer_size=8388608
read_buffer_size=36864
max_used_connections=266
max_threads=65537
thread_count=270
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2381676 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
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...
ntdll.dll!EtwNotificationUnregister()
mysqld.exe!timer_callback()[threadpool_win.cc:419]
ntdll.dll!RtlIsCriticalSectionLockedByThread()
ntdll.dll!RtlSizeHeap()
kernel32.dll!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
2019-07-29 23:18:21 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
2019-07-29 23:18:21 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-07-29 23:18:21 0 [Note] InnoDB: Uses event mutexes
2019-07-29 23:18:21 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-07-29 23:18:21 0 [Note] InnoDB: Number of pools: 1
2019-07-29 23:18:21 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019-07-29 23:18:21 0 [Note] InnoDB: Initializing buffer pool, total size = 384M, instances = 1, chunk size = 128M
2019-07-29 23:18:21 0 [Note] InnoDB: Completed initialization of buffer pool
2019-07-29 23:18:21 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=150962067982
2019-07-29 23:18:22 0 [Note] InnoDB: Transaction 294057132 was in the XA prepared state.
2019-07-29 23:18:22 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo
2019-07-29 23:18:22 0 [Note] InnoDB: Trx id counter is 294057133
2019-07-29 23:18:22 0 [Note] InnoDB: Starting final batch to recover 18 pages from redo log.
2019-07-29 23:18:22 0 [Note] InnoDB: Last binlog file 'd:\MariaDB\master\logbin\Master-bin.000615', position 146245658
2019-07-29 23:18:26 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2019-07-29 23:18:26 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2019-07-29 23:18:26 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2019-07-29 23:18:26 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019-07-29 23:18:26 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-07-29 23:18:26 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-07-29 23:18:26 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
2019-07-29 23:18:26 0 [Note] InnoDB: 10.3.12 started; log sequence number 150962117583; transaction id 294057135
2019-07-29 23:18:26 0 [Note] InnoDB: Loading buffer pool(s) from D:\MariaDB\data\ib_buffer_pool
2019-07-29 23:18:26 0 [Note] Plugin 'FEEDBACK' is disabled.
2019-07-29 23:18:26 0 [Note] Recovering after a crash using d:/MariaDB/master/logbin/Master-bin
2019-07-29 23:18:35 0 [Note] InnoDB: Buffer pool(s) load completed at 190729 23:18:35
2019-07-29 23:18:44 0 [Note] Starting crash recovery...
2019-07-29 23:18:44 0 [Note] InnoDB: Starting recovery for XA transactions...
2019-07-29 23:18:44 0 [Note] InnoDB: Transaction 294057132 in prepared state after recovery
2019-07-29 23:18:44 0 [Note] InnoDB: Transaction contains changes to 1 rows
2019-07-29 23:18:44 0 [Note] InnoDB: 1 transactions in prepared state after recovery
2019-07-29 23:18:44 0 [Note] Found 1 prepared transaction(s) in InnoDB
2019-07-29 23:18:44 0 [Note] Crash recovery finished.
2019-07-29 23:18:44 0 [Note] Server socket created on IP: '::'.
2019-07-29 23:18:44 0 [Warning] 'user' entry 'root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:18:44 0 [Warning] 'proxies_priv' entry '@% root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:18:44 0 [Note] Reading of all Master_info entries succeded
2019-07-29 23:18:44 0 [Note] Added new Master_info '' to hash table
2019-07-29 23:18:44 0 [Note] D:\MariaDB\bin\mysqld.exe: ready for connections.
Version: '10.3.12-MariaDB-log' socket: '' port: 3306 mariadb.org binary distribution
2019-07-29 23:19:23 81 [Note] Start binlog_dump to slave_server(2), pos(Master-bin.000615, 146246161)
2019-07-29 23:19:52 90 [Warning] Access denied for user 'root'@'127.0.0.1' (using password: YES)
2019-07-29 23:24:11 0 [Note] D:\MariaDB\bin\mysqld.exe (initiated by: unknown): Normal shutdown
2019-07-29 23:24:11 0 [Note] Event Scheduler: Purging the queue. 0 events
2019-07-29 23:24:11 0 [Note] InnoDB: FTS optimize thread exiting.
2019-07-29 23:24:11 0 [Note] InnoDB: Starting shutdown...
2019-07-29 23:24:11 0 [Note] InnoDB: Dumping buffer pool(s) to D:\MariaDB\data\ib_buffer_pool
2019-07-29 23:24:11 0 [Note] InnoDB: Instance 0, restricted to 6144 pages due to innodb_buf_pool_dump_pct=25
2019-07-29 23:24:11 0 [Note] InnoDB: Buffer pool(s) dump completed at 190729 23:24:11
2019-07-29 23:24:12 0 [Note] InnoDB: Shutdown completed; log sequence number 150964259475; transaction id 294063316
2019-07-29 23:24:12 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019-07-29 23:24:12 0 [Note] D:\MariaDB\bin\mysqld.exe: Shutdown complete
2019-07-29 23:24:16 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
2019-07-29 23:24:16 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-07-29 23:24:16 0 [Note] InnoDB: Uses event mutexes
2019-07-29 23:24:16 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-07-29 23:24:16 0 [Note] InnoDB: Number of pools: 1
2019-07-29 23:24:16 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019-07-29 23:24:16 0 [Note] InnoDB: Initializing buffer pool, total size = 384M, instances = 1, chunk size = 128M
2019-07-29 23:24:16 0 [Note] InnoDB: Completed initialization of buffer pool
2019-07-29 23:24:16 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2019-07-29 23:24:16 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-07-29 23:24:16 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-07-29 23:24:16 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
2019-07-29 23:24:16 0 [Note] InnoDB: 10.3.12 started; log sequence number 150964259475; transaction id 294063318
2019-07-29 23:24:16 0 [Note] InnoDB: Loading buffer pool(s) from D:\MariaDB\data\ib_buffer_pool
2019-07-29 23:24:16 0 [Note] Plugin 'FEEDBACK' is disabled.
2019-07-29 23:24:16 0 [Note] Server socket created on IP: '::'.
2019-07-29 23:24:16 0 [Warning] 'user' entry 'root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:24:16 0 [Warning] 'proxies_priv' entry '@% root@jpdpt3' ignored in --skip-name-resolve mode.
2019-07-29 23:24:16 0 [Note] Reading of all Master_info entries succeded
2019-07-29 23:24:16 0 [Note] Added new Master_info '' to hash table
2019-07-29 23:24:16 0 [Note] D:\MariaDB\bin\mysqld.exe: ready for connections.
Version: '10.3.12-MariaDB-log' socket: '' port: 3306 mariadb.org binary distribution
2019-07-29 23:24:31 0 [Note] InnoDB: Buffer pool(s) load completed at 190729 23:24:31
2019-07-29 23:25:12 65 [Note] Start binlog_dump to slave_server(2), pos(Master-bin.000616, 1808629)
2019-07-29 23:37:53 251 [Warning] Access denied for user 'zzdomainadmin'@'127.0.0.1' (using password: NO)
{noformat}
at 23:15:11 the following appeared in the application event log on the server
{noformat}
Faulting application mysqld.exe, version 10.3.12.0, time stamp 0x5c2f7f3f, faulting module ntdll.dll, version 6.0.6003.20562, time stamp 0x5cfa798d, exception code 0xc000000d, fault offset 0x00087471, process id 0x124, application start time 0x01d545acd61aec10.
{noformat}
There appears to be no hardware issue (it is running on a Virtual Machine under vmware ESXi), and all other VMs and other processes are ok; no ballooning memory; it had plenty of memory available etc...
The DB does run in Binlog mode and has a standby DB
I have done a mysqlcheck --all-databases and all appears to be ok
Can you urgently help please?
Is this a known bug and is it fixed in a later version of MariaDB and if so which version please?
Sorry for all the questions, I am panicking a great deal.
I'm wondering if this would be possible for you to collect WER crash dumps, and send one if something like this happens again.
exception 0xc000000d is STATUS_INVALID_PARAMETER
timer_callback() that is in your stacktrace is called when idle timeout expires on connection, i.e usually every 8 hours for every connection
The function that crashes (i.e contains invalid parameters) seems to be SetThreadpoolTimer(timer, (PFILETIME)&c->timeout, 0, 1000); which is called when timeout is reset. I do not get yet, how there can be an invalid parameter.
Vladislav Vaintroub
added a comment - I'm wondering if this would be possible for you to collect WER crash dumps, and send one if something like this happens again.
exception 0xc000000d is STATUS_INVALID_PARAMETER
timer_callback() that is in your stacktrace is called when idle timeout expires on connection, i.e usually every 8 hours for every connection
The function that crashes (i.e contains invalid parameters) seems to be SetThreadpoolTimer(timer, (PFILETIME)&c->timeout, 0, 1000); which is called when timeout is reset. I do not get yet, how there can be an invalid parameter.
In some cases, callback functions might run after CloseThreadpoolTimer has been called. To prevent this behavior:
1.Call the SetThreadpoolTimer function with the pftDueTime parameter set to NULL and the msPeriod and msWindowLength parameters set to 0.
2.Call the WaitForThreadpoolTimerCallbacks function.
3.Call CloseThreadpoolTimer.
I guess, we hit "some cases" mentioned here. As we're missing 1. , starting with 10.2
Vladislav Vaintroub
added a comment - Hmm, I think I know what it could be
The documentation https://docs.microsoft.com/en-us/windows/win32/api/threadpoolapiset/nf-threadpoolapiset-closethreadpooltimer for CloseThreadpoolTimer says.
In some cases, callback functions might run after CloseThreadpoolTimer has been called. To prevent this behavior:
1.Call the SetThreadpoolTimer function with the pftDueTime parameter set to NULL and the msPeriod and msWindowLength parameters set to 0.
2.Call the WaitForThreadpoolTimerCallbacks function.
3.Call CloseThreadpoolTimer.
I guess, we hit "some cases" mentioned here. As we're missing 1. , starting with 10.2
Hi Vladislav, many thanks for your investigation and update to the Jira.
Is there a likelyhood of a fix now that you think it could be fixed?
I will enable WER on server where the crash happened so I can gather a dump should it occur again.
Stuart Slater
added a comment - Hi Vladislav, many thanks for your investigation and update to the Jira.
Is there a likelyhood of a fix now that you think it could be fixed?
I will enable WER on server where the crash happened so I can gather a dump should it occur again.
We have had a further occurrence of this entire Crash in our production data factory environment this evening; i believe this is the same issue.
I know this is fixed in 10.3.19; is there any chance of getting this fix early for Windows 32bit please?
as i don't have access to compile it myself, and what i am after is the fix in the usual win32bit zip file format please? as I don't think we can wait 5 weeks+ before release 10.3.19 is released given this 2nd occurrence of the crash.
2019-09-1121:51:320 [Note] Server socket created on IP: '::'.
2019-09-1121:51:320 [Warning] 'user' entry 'root@jpdpt3' ignored in --skip-name-resolve mode.
2019-09-1121:51:320 [Warning] 'proxies_priv' entry '@% root@jpdpt3' ignored in --skip-name-resolve mode.
2019-09-1121:51:320 [Note] Reading of all Master_info entries succeded
2019-09-1121:51:320 [Note] Added new Master_info '' to hash table
2019-09-1121:51:320 [Note] D:\MariaDB\bin\mysqld.exe: ready for connections.
Version: '10.3.12-MariaDB-log' socket: '' port: 3306 mariadb.org binary distribution
2019-09-1121:51:4683 [Note] Start binlog_dump to slave_server(2), pos(Master-bin.000704, 538405)
2019-09-1121:51:470 [Note] InnoDB: Buffer pool(s) load completed at 19091121:51:47
Stuart Slater
added a comment - We have had a further occurrence of this entire Crash in our production data factory environment this evening; i believe this is the same issue.
I know this is fixed in 10.3.19;
is there any chance of getting this fix early for Windows 32bit please?
as i don't have access to compile it myself, and what i am after is the fix in the usual win32bit zip file format please? as I don't think we can wait 5 weeks+ before release 10.3.19 is released given this 2nd occurrence of the crash.
many thanks for your help
This evenings crash details are:-
190911 21 : 48 : 34 [ERROR] mysqld got exception 0xc000000d ;
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.3 . 12 -MariaDB-log
key_buffer_size= 8388608
read_buffer_size= 36864
max_used_connections= 341
max_threads= 65537
thread_count= 307
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2381676 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
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...
ntdll.dll!EtwNotificationUnregister()
mysqld.exe!timer_callback()[threadpool_win.cc: 419 ]
ntdll.dll!RtlIsCriticalSectionLockedByThread()
ntdll.dll!RtlSizeHeap()
kernel32.dll!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Uses event mutexes
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Compressed tables use zlib 1.2 . 11
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Number of pools: 1
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Initializing buffer pool, total size = 384M, instances = 1 , chunk size = 128M
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Completed initialization of buffer pool
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN= 171950051107
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Transaction 334783073 was in the XA prepared state.
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Trx id counter is 334783074
2019 - 09 - 11 21 : 51 : 27 0 [Note] InnoDB: Starting final batch to recover 13 pages from redo log.
2019 - 09 - 11 21 : 51 : 28 0 [Note] InnoDB: Last binlog file 'd:\MariaDB\master\logbin\Master-bin.000704' , position 537903
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: 10.3 . 12 started; log sequence number 171950074662 ; transaction id 334783076
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Loading buffer pool(s) from D:\MariaDB\data\ib_buffer_pool
2019 - 09 - 11 21 : 51 : 32 0 [Note] Plugin 'FEEDBACK' is disabled.
2019 - 09 - 11 21 : 51 : 32 0 [Note] Recovering after a crash using d:/MariaDB/master/logbin/Master-bin
2019 - 09 - 11 21 : 51 : 32 0 [Note] Starting crash recovery...
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Starting recovery for XA transactions...
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Transaction 334783073 in prepared state after recovery
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: Transaction contains changes to 1 rows
2019 - 09 - 11 21 : 51 : 32 0 [Note] InnoDB: 1 transactions in prepared state after recovery
2019 - 09 - 11 21 : 51 : 32 0 [Note] Found 1 prepared transaction(s) in InnoDB
2019 - 09 - 11 21 : 51 : 32 0 [Note] Crash recovery finished.
2019 - 09 - 11 21 : 51 : 32 0 [Note] Server socket created on IP: '::' .
2019 - 09 - 11 21 : 51 : 32 0 [Warning] 'user' entry 'root@jpdpt3' ignored in --skip-name-resolve mode.
2019 - 09 - 11 21 : 51 : 32 0 [Warning] 'proxies_priv' entry '@% root@jpdpt3' ignored in --skip-name-resolve mode.
2019 - 09 - 11 21 : 51 : 32 0 [Note] Reading of all Master_info entries succeded
2019 - 09 - 11 21 : 51 : 32 0 [Note] Added new Master_info '' to hash table
2019 - 09 - 11 21 : 51 : 32 0 [Note] D:\MariaDB\bin\mysqld.exe: ready for connections.
Version: '10.3.12-MariaDB-log' socket: '' port: 3306 mariadb.org binary distribution
2019 - 09 - 11 21 : 51 : 46 83 [Note] Start binlog_dump to slave_server( 2 ), pos(Master-bin. 000704 , 538405 )
2019 - 09 - 11 21 : 51 : 47 0 [Note] InnoDB: Buffer pool(s) load completed at 190911 21 : 51 : 47
Vladislav Vaintroub
added a comment - slaterss Can you explain "you do not have access to compile yourself", please?
You should be able to
git clone https://github.com/mariadb/server -b 10.3
All software that is needed to setup build environment listed in https://mariadb.com/kb/en/library/Building_MariaDB_on_Windows/ , is free as well.
Thank you for your prompt reply;
unfortunately we are not able to install Compiler related s/w in our organisation unless it is on the approved list and done by our Corporate IT department.
Perl strawberry or activestate is not allowed.
Sorry; i guess i could try and do the build at home on my home PC; but just wondering if there is a nightly build i can be given access to such as mariadb-10.3.19-win32.zip ?
Stuart Slater
added a comment - Thank you for your prompt reply;
unfortunately we are not able to install Compiler related s/w in our organisation unless it is on the approved list and done by our Corporate IT department.
Perl strawberry or activestate is not allowed.
Sorry; i guess i could try and do the build at home on my home PC; but just wondering if there is a nightly build i can be given access to such as mariadb-10.3.19-win32.zip ?
Perl is only needed for running the test suite, the build itself does not depend on it. I guess a portable version of Strawberry Perl might work for you, if installs are prohibited.
Vladislav Vaintroub
added a comment - Yes, there is a build , I copied it to https://1drv.ms/u/s!AqT4tBcElQz_j4xBXKT7E_T5Dhr5iA?e=F82nEU
Perl is only needed for running the test suite, the build itself does not depend on it. I guess a portable version of Strawberry Perl might work for you, if installs are prohibited.
Stuart Slater
added a comment - That is very helpful; really appreciate all your help and understanding.
I can't seem to access the URL
https://1drv.ms/u/s!AqT4tBcElQz_j4xBXKT7E_T5Dhr5iA?e=F82nEU
it comes back with this site cannot be reached?
Vladislav Vaintroub
added a comment - It is OneDrive link, shared with everyone.
Here is a google drive link, shared with everyone as well https://drive.google.com/file/d/1h_R2RHGUU_vNkO7jIYSSdC-4cNZ9SiIh/view?usp=sharing
Hi, I see you have released 10.3.19 last night (5th November 2019)
However I cannot see that this MDEV-20206 in the change log; or the related one of MDEV-20970??
can you confirm that MDEV-20206 is fixed in 10.3.19 please?
Many thanks
Stuart Slater
added a comment - Hi, I see you have released 10.3.19 last night (5th November 2019)
However I cannot see that this MDEV-20206 in the change log; or the related one of MDEV-20970 ??
can you confirm that MDEV-20206 is fixed in 10.3.19 please?
Many thanks
Vladislav Vaintroub
added a comment - This commit https://github.com/mariadb/server/commit/2336e0b3944b73379f9d773b4e1b37cbc723bce4 is tagged mariadb-10.4.9 mariadb-10.3.19 mariadb-10.2.28
So yes, it is in 10.3.19
Vladislav Vaintroub
added a comment - but I'd suggest to hold your upgrades, 10.3.19 the release might need to be re-issued , because of https://jira.mariadb.org/browse/MDEV-20987
Is it a recurring problem? Can you locate the query which caused it? Do you have a minidump from the crash?