Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.2.26, 10.2.29, 10.3.17, 10.3.20, 10.4.7, 10.4.10
-
None
-
Encountered on Windows, debugged on Windows.
Description
When upgrading to 10.4.7 and continuing on through 10.4.10 (and equivalent version of 10.2 and 10.3), if I have the RocksDB plugin enabled:
[mysqld]
|
...
|
plugin_load_add = ha_rocksdb
|
Then as soon as I start that instance (a service in my case), the CPU usage spikes to 50% and does not let up until I kill the process.
It may dip to 48-49%.
If I start a second instance, they both end up taking ~49-50% each, and the CPU is pegged at 100%.
If I start a third instance, the 3 generally end up using about ~32-33% each, and the CPU is pegged at 100%.
The instances were only using about 32M RAM, and zero activity was occurring on them.
I started Windows profiler, and attached it (and CPU stats gatherer), allowed it to run for 50 seconds, and analyzed. It showed that the CPU usage came from ha_rocksdb.dll.
I then commented out the RocksDB plugin:
#plugin_load_add = ha_rocksdb
|
Restarted MariaDB.
And then CPU was back to normal, roughly 0% in this case, since there was 0 activity.
Comment: It is easy to remove if you enabled the plugin via the config file: simply remove or comment out the line, as above, and restart MariaDB.
If you enabled it via the command line, then you need to uninstall it via the command line:
UNINSTALL SONAME 'ha_rocksdb';
|
However, this command is just hanging for me in this situation (i.e., when CPU is pegged out). It is essentially stuck. It did finally complete after about 20 minutes
Attachments
Activity
Did you have any data in RocksDB? Can you paste a hundred or so lines from $DATADIR/#rocksdb/LOG file ?
I started Windows profiler, and attached it (and CPU stats gatherer), allowed it to run for 50 seconds, and analyzed. It showed that the CPU usage came from ha_rocksdb.dll.
Did it show a stack trace (or something similar) where the time was spent? If it did, please post it here
Hello psergey, no I do not have any data in RocksDB, nor any rocksdb tables:
mysql> select * from information_schema.tables where engine like 'rocksdb';
|
Empty set (0.20 sec)
|
Here are the last 100 lines from $DATADIR/#rocksdb/LOG:
rocksdb.db.flush.micros P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0
|
rocksdb.sst.batch.size P50 : 0.000000 P95 : 0.000000 P99 : 0.000000 P100 : 0.000000 COUNT : 0 SUM : 0
|
2019/11/08-22:13:15.251191 1f78 [db_impl\db_impl.cc:908] SetOptions() on column family [default], inputs:
|
2019/11/08-22:13:15.251191 1f78 [db_impl\db_impl.cc:911] disable_auto_compactions: false
|
2019/11/08-22:13:15.251191 1f78 [db_impl\db_impl.cc:915] [default] SetOptions() succeeded
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:126] write_buffer_size: 67108864
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:128] max_write_buffer_number: 2
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:131] arena_block_size: 8388608
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:133] memtable_prefix_bloom_ratio: 0.000000
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:135] memtable_whole_key_filtering: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:138] memtable_huge_page_size: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:141] max_successive_merges: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:144] inplace_update_num_locks: 10000
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:147] prefix_extractor: nullptr
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:149] disable_auto_compactions: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:151] soft_pending_compaction_bytes_limit: 68719476736
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:153] hard_pending_compaction_bytes_limit: 274877906944
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:155] level0_file_num_compaction_trigger: 4
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:157] level0_slowdown_writes_trigger: 20
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:159] level0_stop_writes_trigger: 36
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:161] max_compaction_bytes: 1677721600
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:163] target_file_size_base: 67108864
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:165] target_file_size_multiplier: 1
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:167] max_bytes_for_level_base: 268435456
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:169] snap_refresh_nanos: 100000000
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:171] max_bytes_for_level_multiplier: 10.000000
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:173] ttl: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:175] periodic_compaction_seconds: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:189] max_bytes_for_level_multiplier_additional: 1, 1, 1, 1, 1, 1, 1
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:191] max_sequential_skip_in_iterations: 8
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:193] paranoid_file_checks: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:195] report_bg_io_stats: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:197] compression: 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:201] compaction_options_universal.size_ratio : 1
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:203] compaction_options_universal.min_merge_width : 2
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:205] compaction_options_universal.max_merge_width : -1
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:208] compaction_options_universal.max_size_amplification_percent : 200
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:211] compaction_options_universal.compression_size_percent : -1
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:213] compaction_options_universal.stop_style : 1
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:216] compaction_options_universal.allow_trivial_move : 0
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:220] compaction_options_fifo.max_table_files_size : 1073741824
|
2019/11/08-22:13:15.251191 1f78 [ions\cf_options.cc:222] compaction_options_fifo.allow_compaction : 0
|
2019/11/08-22:13:15.282391 1f78 [db_impl\db_impl.cc:908] SetOptions() on column family [__system__], inputs:
|
2019/11/08-22:13:15.282391 1f78 [db_impl\db_impl.cc:911] disable_auto_compactions: false
|
2019/11/08-22:13:15.282391 1f78 [db_impl\db_impl.cc:915] [__system__] SetOptions() succeeded
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:126] write_buffer_size: 67108864
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:128] max_write_buffer_number: 2
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:131] arena_block_size: 8388608
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:133] memtable_prefix_bloom_ratio: 0.000000
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:135] memtable_whole_key_filtering: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:138] memtable_huge_page_size: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:141] max_successive_merges: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:144] inplace_update_num_locks: 10000
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:147] prefix_extractor: nullptr
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:149] disable_auto_compactions: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:151] soft_pending_compaction_bytes_limit: 68719476736
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:153] hard_pending_compaction_bytes_limit: 274877906944
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:155] level0_file_num_compaction_trigger: 4
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:157] level0_slowdown_writes_trigger: 20
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:159] level0_stop_writes_trigger: 36
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:161] max_compaction_bytes: 1677721600
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:163] target_file_size_base: 67108864
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:165] target_file_size_multiplier: 1
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:167] max_bytes_for_level_base: 268435456
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:169] snap_refresh_nanos: 100000000
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:171] max_bytes_for_level_multiplier: 10.000000
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:173] ttl: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:175] periodic_compaction_seconds: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:189] max_bytes_for_level_multiplier_additional: 1, 1, 1, 1, 1, 1, 1
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:191] max_sequential_skip_in_iterations: 8
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:193] paranoid_file_checks: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:195] report_bg_io_stats: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:197] compression: 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:201] compaction_options_universal.size_ratio : 1
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:203] compaction_options_universal.min_merge_width : 2
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:205] compaction_options_universal.max_merge_width : -1
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:208] compaction_options_universal.max_size_amplification_percent : 200
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:211] compaction_options_universal.compression_size_percent : -1
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:213] compaction_options_universal.stop_style : 1
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:216] compaction_options_universal.allow_trivial_move : 0
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:220] compaction_options_fifo.max_table_files_size : 1073741824
|
2019/11/08-22:13:15.282391 1f78 [ions\cf_options.cc:222] compaction_options_fifo.allow_compaction : 0
|
2019/11/08-22:15:12.314198 1f78 [db_impl\db_impl_compaction_flush.cc:1318] [default] Manual flush start.
|
2019/11/08-22:15:12.314198 1f78 [db_impl\db_impl_compaction_flush.cc:1329] [default] Manual flush finished, status: OK
|
2019/11/08-22:15:12.314198 1f78 [db_impl\db_impl_compaction_flush.cc:1318] [__system__] Manual flush start.
|
2019/11/08-22:15:12.314198 1f78 [db_impl\db_impl_write.cc:1576] [__system__] New memtable created with log file: #198. Immutable memtables: 0.
|
2019/11/08-22:15:12.314198 e44 [db_impl\db_impl_compaction_flush.cc:105] [JOB 3] Syncing log #191
|
2019/11/08-22:15:12.314198 e44 (Original Log Time 2019/11/08-22:15:12.314198) [db_impl\db_impl_compaction_flush.cc:2124] Calling FlushMemTableToOutputFile with column family [__system__], flush slots available 1, compaction slots available 1, flush slots scheduled 1, compaction slots scheduled 0
|
2019/11/08-22:15:12.314198 e44 [flush_job.cc:320] [__system__] [JOB 3] Flushing memtable with next log file: 198
|
2019/11/08-22:15:12.314198 e44 EVENT_LOG_v1 {"time_micros": 1573269312314198, "job": 3, "event": "flush_started", "num_memtables": 1, "num_entries": 2, "num_deletes": 0, "total_data_size": 48, "memory_usage": 848, "flush_reason": "Manual Flush"}
|
2019/11/08-22:15:12.314198 e44 [flush_job.cc:349] [__system__] [JOB 3] Level-0 flush table #199: started
|
2019/11/08-22:15:12.329798 e44 EVENT_LOG_v1 {"time_micros": 1573269312329798, "cf_name": "__system__", "job": 3, "event": "table_file_creation", "file_number": 199, "file_size": 966, "table_properties": {"data_size": 56, "index_size": 34, "index_partitions": 0, "top_level_index_size": 0, "index_key_is_user_key": 0, "index_value_is_delta_encoded": 0, "filter_size": 0, "raw_key_size": 32, "raw_average_key_size": 16, "raw_value_size": 12, "raw_average_value_size": 6, "num_data_blocks": 1, "num_entries": 2, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 0, "filter_policy": "", "column_family_name": "__system__", "column_family_id": 1, "comparator": "RocksDB_SE_v3.10", "merge_operator": "Rdb_system_merge_op", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "NoCompression", "compression_options": "window_bits=-14; level=32767; strategy=0; max_dict_bytes=0; zstd_max_train_bytes=0; enabled=0; ", "creation_time": 1573269312, "oldest_key_time": 1573269195, "file_creation_time": 1573269312, "__indexstats__": "[...1 records...]"}}
|
2019/11/08-22:15:12.329798 e44 [flush_job.cc:390] [__system__] [JOB 3] Level-0 flush table #199: 966 bytes OK
|
2019/11/08-22:15:12.329798 e44 (Original Log Time 2019/11/08-22:15:12.329798) [memtable_list.cc:382] [__system__] Level-0 commit table #199 started
|
2019/11/08-22:15:12.329798 e44 (Original Log Time 2019/11/08-22:15:12.329798) [memtable_list.cc:430] [__system__] Level-0 commit table #199: memtable #1 done
|
2019/11/08-22:15:12.329798 e44 (Original Log Time 2019/11/08-22:15:12.329798) EVENT_LOG_v1 {"time_micros": 1573269312329798, "job": 3, "event": "flush_finished", "output_compression": "NoCompression", "lsm_state": [3, 1, 0, 0, 0, 0, 0], "immutable_memtables": 0}
|
2019/11/08-22:15:12.329798 e44 (Original Log Time 2019/11/08-22:15:12.329798) [db_impl\db_impl_compaction_flush.cc:205] [__system__] Level summary: files[3 1 0 0 0 0 0] max score 0.75
|
2019/11/08-22:15:12.329798 e44 [db_impl\db_impl_files.cc:353] [JOB 3] Try to delete WAL files size 60, prev total WAL file size 60, number of live WAL files 2.
|
2019/11/08-22:15:12.329798 1f78 [db_impl\db_impl_compaction_flush.cc:1329] [__system__] Manual flush finished, status: OK
|
2019/11/08-22:15:12.329798 1f78 [db_impl\db_impl.cc:394] Shutdown: canceling all background work
|
Stack trace from debugger (after adding in ha_rocksdb.pdb, and re-creating issue):
Sure, it is easy to reproduce. I can every time I enable RocksDB in these newer versions:
plugin_load_add = ha_rocksdb
|
Then restart and monitor the CPU usage.
I just performed this with a fresh 10.4.10 Win64. Created the datadir fresh usingt mysql_install_db. Then started the instance without ha_rocksdb, and it started fine, and did not consume CPU. Then I stopped, added the above option, and restarted, and the CPU spikes to 50%.
I even disabled rocksdb again (stopped the instance, remove the option, restart, verify rocksdb is not enabled, and CPU is low), then issued:
INSTALL SONAME 'ha_rocksdb';
|
The command runs fast, and then the CPU spikes to 50% within a few seconds.
Not sure if it matter at all, but when I try to uninstall the plugin dynamically:
MariaDB [(none)]> UNINSTALL SONAME 'ha_rocksdb';
|
While the command takes a long time to complete, during this time, the CPU usage of mysqld drops to 25% (instead of 50%).
MariaDB [(none)]> UNINSTALL SONAME 'ha_rocksdb';
|
Query OK, 0 rows affected (13 min 50.954 sec)
|
And mysqld CPU usage drops back to near 0% once the command completes.
Ok, I had tried with the official 10.4.10 binary:
- Added plugin_load_add=ha_rocksdb into my.cnf
- Started the server (CPU load is 0%)
- Verified the plugin is loaded, created a rocksdb table. Cpu load is still 0%.
Re-ran the same with the provided datadir. The result was the same - CPU load remained 0%.
I re-ran the debug session and captured as much info as possible:
CPU Debug Info (let run for ~30 seconds):
Function Name Total CPU [unit, %] Self CPU [unit, %] Module
|
+ mysqld.exe (PID: 9476) 42910 (100.00 %) 0 (0.00 %) mysqld.exe
|
| - rocksdb::port::WindowsThread::Data::ThreadProc 42868 (99.90 %) 0 (0.00 %) ha_rocksdb.dll
|
| - ucrtbase.dll!0x0007fef7ffc1ae 42868 (99.90 %) 0 (0.00 %) ucrtbase.dll
|
| - std::_Func_impl_no_alloc<std::_Binder<std::_Unforced,<lambda_e7fdb2a9eb03358eecf49f1389987e73> >,void>::_Do_call 42865 (99.90 %) 389 (0.91 %) ha_rocksdb.dll
|
| - rocksdb::port::WinEnvIO::NowMicros 33742 (78.63 %) 9394 (21.89 %) ha_rocksdb.dll
|
| - rocksdb::InstrumentedCondVar::TimedWait 8512 (19.84 %) 2258 (5.26 %) ha_rocksdb.dll
|
| - rocksdb::port::CondVar::TimedWait 5976 (13.93 %) 2209 (5.15 %) ha_rocksdb.dll
|
| - rocksdb::port::WinEnv::NowMicros 217 (0.51 %) 217 (0.51 %) ha_rocksdb.dll
|
| - rocksdb::`anonymous namespace'::stats_for_report 192 (0.45 %) 192 (0.45 %) ha_rocksdb.dll
|
| - __security_check_cookie 171 (0.40 %) 171 (0.40 %) ha_rocksdb.dll
|
| - _Query_perf_counter 96 (0.22 %) 96 (0.22 %) ha_rocksdb.dll
|
| - rocksdb::InstrumentedCondVar::TimedWaitInternal 85 (0.20 %) 85 (0.20 %) ha_rocksdb.dll
|
| - _Query_perf_frequency 83 (0.19 %) 83 (0.19 %) ha_rocksdb.dll
|
| - _Xtime_get_ticks 53 (0.12 %) 53 (0.12 %) ha_rocksdb.dll
|
| - [Unwalkable] 42 (0.10 %) 0 (0.00 %) Multiple modules
|
Then I attached debugger (let run for ~30 seconds) then "break all":
Threads:
Not Flagged 10024 0 Main Thread Main Thread sechost.dll!000007fefe98affb
|
Not Flagged 5876 0 Worker Thread ntdll.dll thread ntdll.dll!0000000076d0186a
|
Not Flagged 3812 0 Worker Thread sechost.dll thread mysqld.exe!NTService::ServiceMain
|
Not Flagged 8688 0 Worker Thread ucrtbase.dll thread mysqld.exe!handle_connections_win
|
Not Flagged 2052 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 8528 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 9468 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 5308 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 4592 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 852 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 4804 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 6080 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 3560 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 7152 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 2336 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 5792 0 Worker Thread mysqld.exe!io_handler_thread mysqld.exe!os_aio_windows_handler
|
Not Flagged 6664 0 Worker Thread mysqld.exe!buf_flush_page_cleaner_coordinator mysqld.exe!os_event::timed_wait
|
Not Flagged 6284 0 Worker Thread mysqld.exe!lock_wait_timeout_thread mysqld.exe!os_event::timed_wait
|
Not Flagged 7272 0 Worker Thread mysqld.exe!srv_error_monitor_thread mysqld.exe!os_event::timed_wait
|
Not Flagged 1668 0 Worker Thread mysqld.exe!srv_monitor_thread mysqld.exe!os_event::timed_wait
|
Not Flagged 9124 0 Worker Thread mysqld.exe!dict_stats_thread mysqld.exe!os_event::timed_wait
|
Not Flagged 2564 0 Worker Thread mysqld.exe!fts_optimize_thread mysqld.exe!os_event::timed_wait
|
Not Flagged 5020 0 Worker Thread mysqld.exe!srv_master_thread mysqld.exe!srv_master_sleep
|
Not Flagged 6248 0 Worker Thread mysqld.exe!srv_purge_coordinator_thread [Inline Frame] mysqld.exe!os_event::wait
|
Not Flagged 3700 0 Worker Thread mysqld.exe!srv_worker_thread [Inline Frame] mysqld.exe!os_event::wait
|
Not Flagged 7596 0 Worker Thread mysqld.exe!srv_worker_thread [Inline Frame] mysqld.exe!os_event::wait
|
Not Flagged 7664 0 Worker Thread mysqld.exe!srv_worker_thread [Inline Frame] mysqld.exe!os_event::wait
|
Not Flagged 6036 0 Worker Thread mysqld.exe!buf_dump_thread [Inline Frame] mysqld.exe!os_event::wait
|
Not Flagged 10028 0 Worker Thread mysqld.exe!btr_defragment_thread mysqld.exe!btr_defragment_thread
|
Not Flagged 6004 0 Worker Thread mysqld.exe!buf_resize_thread [Inline Frame] mysqld.exe!os_event::wait
|
Not Flagged 9176 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 7112 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 6656 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 1780 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 7824 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 9704 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 9764 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 8400 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 9080 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 8772 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 5264 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 7364 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 8008 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 2480 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 9308 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 6160 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 6724 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 8584 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 3204 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 4528 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 6500 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 6520 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 5968 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 3656 0 Worker Thread ntdll.dll thread ntdll.dll!0000000076d02bba
|
Not Flagged 3456 0 Worker Thread ntdll.dll thread ntdll.dll!0000000076d02bba
|
Not Flagged 6792 0 Worker Thread ucrtbase.dll thread msvcp140.dll!000007fef811640d
|
Not Flagged 6124 0 Worker Thread ucrtbase.dll thread msvcp140.dll!000007fef811640d
|
Not Flagged 4768 0 Worker Thread ucrtbase.dll thread msvcp140.dll!000007fef811640d
|
Not Flagged > 2316 0 Worker Thread ucrtbase.dll thread [Inline Frame] ha_rocksdb.dll!std::chrono::steady_clock::now
|
Not Flagged 3696 0 Worker Thread ucrtbase.dll thread msvcp140.dll!000007fef80f32ff
|
Not Flagged 9048 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 3732 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Not Flagged 5184 0 Worker Thread ucrtbase.dll thread mysqld.exe!pthread_cond_timedwait
|
Thread 4768 Call Stack ("mutex") - 1st thread above 2316:
[External Code]
|
> [Inline Frame] ha_rocksdb.dll!std::condition_variable::wait(std::unique_lock<std::mutex> &) Line 603 C++ <<-- "mutex"
|
ha_rocksdb.dll!rocksdb::ThreadPoolImpl::Impl::BGThread(unsigned __int64 thread_id) Line 197 C++ <<-- "threadpool_imp.cc"
|
ha_rocksdb.dll!rocksdb::ThreadPoolImpl::Impl::BGThreadWrapper(void * arg) Line 309 C++ <<-- "threadpool_imp.cc"
|
[Inline Frame] ha_rocksdb.dll!std::_Func_class<void>::operator()() Line 1049 C++ <<-- "functional"
|
ha_rocksdb.dll!rocksdb::port::WindowsThread::Data::ThreadProc(void * arg) Line 170 C++ <<-- "win_thread.cc"
|
[External Code]
|
Thread 2316 Call Stack ("chrono not found") - thread with the arrow:
> [Inline Frame] ha_rocksdb.dll!std::chrono::steady_clock::now() Line 575 C++ <<-- "chrono"
|
ha_rocksdb.dll!rocksdb::port::WinEnvIO::NowMicros() Line 982 C++ <<-- "env_win.cc"
|
[External Code]
|
[Inline Frame] ha_rocksdb.dll!std::_Func_class<void>::operator()() Line 1049 C++ <<-- "functional"
|
ha_rocksdb.dll!rocksdb::port::WindowsThread::Data::ThreadProc(void * arg) Line 170 C++ <<-- "win_thread.cc"
|
[External Code]
|
Thread 3696 Call Stack ("chrono not found") - 1st thread below 2316:
[External Code]
|
> [Inline Frame] ha_rocksdb.dll!std::chrono::steady_clock::now() Line 571 C++ <<-- "chrono"
|
ha_rocksdb.dll!rocksdb::port::WinEnvIO::NowMicros() Line 982 C++ <<-- "env_win.cc"
|
[External Code]
|
[Inline Frame] ha_rocksdb.dll!std::_Func_class<void>::operator()() Line 1049 C++ <<-- "functional"
|
ha_rocksdb.dll!rocksdb::port::WindowsThread::Data::ThreadProc(void * arg) Line 170 C++ <<-- "win_thread.cc"
|
[External Code]
|
Thread 9048 Call Stack ("my_wincond.c") - 2nd thread below 2316:
[External Code]
|
> mysqld.exe!pthread_cond_timedwait(_RTL_CONDITION_VARIABLE * cond, _RTL_CRITICAL_SECTION * mutex, const timespec * abstime) Line 85 C <<-- "my_wincond.c"
|
[Inline Frame] ha_rocksdb.dll!inline_mysql_cond_timedwait(st_mysql_cond * that, st_mysql_mutex *) Line 1215 C++ <<-- "mysql_thread.h"
|
ha_rocksdb.dll!myrocks::Rdb_background_thread::run() Line 13521 C++ <<-- "ha_rocksdb.cc"
|
ha_rocksdb.dll!myrocks::Rdb_thread::thread_func(void * const thread_ptr) Line 35 C++ <<-- "rdb_threads.cc"
|
mysqld.exe!pthread_start(void * p) Line 62 C <<-- "my_winthread.c"
|
[External Code]
|
Thread 3732 Call Stack ("my_wincond.c") - 3rd thread below 2316:
[External Code]
|
> mysqld.exe!pthread_cond_timedwait(_RTL_CONDITION_VARIABLE * cond, _RTL_CRITICAL_SECTION * mutex, const timespec * abstime) Line 85 C <<-- "my_wincond.c"
|
[Inline Frame] ha_rocksdb.dll!inline_mysql_cond_timedwait(st_mysql_cond * that, st_mysql_mutex *) Line 1215 C++ <<-- "mysql_thread.h"
|
ha_rocksdb.dll!myrocks::Rdb_drop_index_thread::run() Line 11581 C++ <<-- "ha_rocksdb.cc"
|
ha_rocksdb.dll!myrocks::Rdb_thread::thread_func(void * const thread_ptr) Line 35 C++ <<-- "rdb_threads.cc"
|
mysqld.exe!pthread_start(void * p) Line 62 C <<-- "my_winthread.c"
|
[External Code]
|
Thread 5184 Call Stack ("my_wincond.c") - 4th and final thread below 2316:
[External Code]
|
> mysqld.exe!pthread_cond_timedwait(_RTL_CONDITION_VARIABLE * cond, _RTL_CRITICAL_SECTION * mutex, const timespec * abstime) Line 85 C <<-- "my_wincond.c"
|
[Inline Frame] ha_rocksdb.dll!inline_mysql_cond_timedwait(st_mysql_cond *) Line 1215 C++ <<-- "mysql_thread.h"
|
ha_rocksdb.dll!myrocks::Rdb_manual_compaction_thread::run() Line 13614 C++ <<-- "ha_rocksdb.cc"
|
ha_rocksdb.dll!myrocks::Rdb_thread::thread_func(void * const thread_ptr) Line 35 C++ <<-- "rdb_threads.cc"
|
mysqld.exe!pthread_start(void * p) Line 62 C <<-- "my_winthread.c"
|
[External Code]
|
Well, I guess that helped. I got to searching on some of those functions, and ran across this:
https://github.com/facebook/rocksdb/issues/5552
"100% CPU - Regression for Window 7 in WinEnvIO::NowMicros()"
It sounds like it was fixed here: https://github.com/facebook/rocksdb/pull/5557 (merged on Jul 15, 2019).
10.4.7 (when this started) was released on Jul 31, 2019, so perhaps this fix did not make the merge (of upstream bugs fixed in MDEV-19795) with MariaDB in time.
I suspect it started as a result of one of the changes that were incorporated here:
MDEV-19795