MySql инициализация при каждом запуске
От: CRT  
Дата: 05.05.23 10:02
Оценка:
Когда-то давно установил на компьютер MySQL 5.6.20 для тестов приложения.
zip архив для Windows, без инсталера.

Запускаю его командой
mysqld --console
запускается очень быстро


решил параллельно установить версию 8.0.33.
Опять без инсталера, zip архив


Это нормально что версия 8.0.33 каждый раз при запуске командой
mysqld --console
выдает
[InnoDB] InnoDB initialization has started.
[InnoDB] InnoDB initialization has ended.

и между started и ended аж целых 8 секунд?
В течении которых он ощутимо хрустит жестким диском. Баз данных я еще никаких не создавал. Там только системные.

Я же уже инициализировал его при установке командой mysqld --initialize-insecure --console
Почему он опять каждый раз при запуске пишет про инициализацию.


Версия 5.6.20 запускается почти мгновенно, никаких хрустов диском. И про инициализацию ничего не пишет
Отредактировано 05.05.2023 15:56 CRT . Предыдущая версия . Еще …
Отредактировано 05.05.2023 15:55 CRT . Предыдущая версия .
Re: MySql инициализация при каждом запуске
От: Anton Batenev Россия https://github.com/abbat
Дата: 05.05.23 15:26
Оценка:
Здравствуйте, CRT, Вы писали:

CRT> и между started и ended аж целых 8 секунд?

CRT> В течении которых он ощутимо хрустит жестким диском. Баз данных я еще никаких не создавал. Там только системные.

Проверь значение переменной innodb_temp_data_file_path — возможно каждый раз при старте у тебя создается "global temporary tablespace" большого размера.

Еще одно место, которое стоит посмотреть, это innodb_buffer_pool_load_at_startup и сопутствующие ей (innodb_buffer_pool_dump_at_shutdown, innodb_buffer_pool_dump_pct).
Re[2]: MySql инициализация при каждом запуске
От: CRT  
Дата: 05.05.23 17:46
Оценка:
Здравствуйте, Anton Batenev, Вы писали:

AB>Проверь значение переменной innodb_temp_data_file_path — возможно каждый раз при старте у тебя создается "global temporary tablespace" большого размера.


Проверил. Там значение по умолчанию: ibtmp1:12M:autoextend
и он действительно создает 12 МБ файл ibtmp1 каждый раз при запуске. Но разве так и не должно быть?

AB>Еще одно место, которое стоит посмотреть, это innodb_buffer_pool_load_at_startup и сопутствующие ей (innodb_buffer_pool_dump_at_shutdown, innodb_buffer_pool_dump_pct).


Там тоже значения по умолчанию:
innodb_buffer_pool_load_at_startup=1
innodb_buffer_pool_dump_pct=25
innodb_buffer_pool_dump_at_shutdown=1


в консоли при запуске выводит следующее:

2023-05-05T17:30:36.287665Z 0 [System] [MY-010116] [Server] d:\mysql-8.0.33-winx64\bin\mysqld.exe (mysqld 8.0.33) starting as process 8864
2023-05-05T17:30:36.315879Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-05-05T17:30:43.772398Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2023-05-05T17:30:45.128297Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2023-05-05T17:30:45.128461Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2023-05-05T17:30:45.684188Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060
2023-05-05T17:30:45.684507Z 0 [System] [MY-010931] [Server] d:\mysql-8.0.33-winx64\bin\mysqld.exe: ready for connections. Version: '8.0.33' socket: '' port: 3306 MySQL Community Server — GPL.

Re[3]: MySql инициализация при каждом запуске
От: Anton Batenev Россия https://github.com/abbat
Дата: 05.05.23 18:26
Оценка:
Здравствуйте, CRT, Вы писали:

CRT> в консоли при запуске выводит следующее:

CRT> 2023-05-05T17:30:36.315879Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
CRT> 2023-05-05T17:30:43.772398Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.

Отключи `innodb_buffer_pool_load_at_startup` и попробуй ключ запуска: --verbose=2|3|4 возможно станет понятнее с чем это связано.

З.Ы. Между MySQL 5.6 и 8.х лежит целая пропасть — это практически две разных БД по некоторым параметрам (а тем более в версии под Windows).
Re[4]: MySql инициализация при каждом запуске
От: CRT  
Дата: 07.05.23 15:36
Оценка:
Здравствуйте, Anton Batenev, Вы писали:

AB>Отключи `innodb_buffer_pool_load_at_startup` и попробуй ключ запуска: --verbose=2|3|4 возможно станет понятнее с чем это связано.


mysqld не понимает --verbose, но понимает --log_error_verbosity=3

самая задержка примерно здесь (чтобы короче строки были, оставил только время, даты убрал)

15:06:30.206925Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace '.\undo_001'.
15:06:30.234720Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace '.\undo_002'.
15:06:30.257561Z 1 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
15:06:30.257889Z 1 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 6930
15:06:35.888321Z 1 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete
15:06:35.889013Z 1 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 2 thread: 5631264 ms.
15:06:35.889867Z 1 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
15:06:35.890701Z 1 [Note] [MY-012265] [InnoDB] Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
15:06:36.155079Z 1 [Note] [MY-012266] [InnoDB] File '.\ibtmp1' size is now 12 MB.
15:06:36.197782Z 1 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:'.\#innodb_temp\'
15:06:36.869882Z 1 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
15:06:36.880050Z 0 [Note] [MY-011953] [InnoDB] Page cleaner took 7171ms to flush 0 and evict 0 pages
15:06:36.891173Z 1 [Note] [MY-012976] [InnoDB] 8.0.33 started; log sequence number 20077259
15:06:36.900241Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.



  Полный лог
D:\mysql-8.0.33-winx64>bin\mysqld --console --log_error_verbosity=3
15:06:29.635264Z 0 [Note] [MY-013667] [Server] Error-log destination "stderr" is not a file. Can not restore error log messages from previous run.
15:06:29.314928Z 0 [Note] [MY-013847] [Server] Using jemalloc.dll for my_malloc and ut::malloc etc.
15:06:29.624496Z 0 [Note] [MY-010098] [Server] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
15:06:29.624599Z 0 [Note] [MY-010949] [Server] Basedir set to D:\mysql-8.0.33-winx64\.
15:06:29.624618Z 0 [System] [MY-010116] [Server] D:\mysql-8.0.33-winx64\bin\mysqld.exe (mysqld 8.0.33) starting as process 4832
15:06:29.655102Z 0 [Note] [MY-012366] [InnoDB] Using Windows native AIO
15:06:29.655645Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.
15:06:29.655990Z 0 [Note] [MY-010747] [Server] Plugin 'ndbcluster' is disabled.
15:06:29.656270Z 0 [Note] [MY-010747] [Server] Plugin 'ndbinfo' is disabled.
15:06:29.656588Z 0 [Note] [MY-010747] [Server] Plugin 'ndb_transid_mysql_connection_map' is disabled.
15:06:29.661309Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
15:06:29.661402Z 1 [Note] [MY-013546] [InnoDB] Atomic write enabled
15:06:29.662841Z 1 [Note] [MY-012944] [InnoDB] Uses event mutexes
15:06:29.662904Z 1 [Note] [MY-012945] [InnoDB] _mm_lfence() and _mm_sfence() are used for memory barrier
15:06:29.663311Z 1 [Note] [MY-012948] [InnoDB] Compressed tables use zlib 1.2.13
15:06:29.669743Z 1 [Note] [MY-012951] [InnoDB] Using software crc32.
15:06:29.671581Z 1 [Note] [MY-012203] [InnoDB] Directories to scan '.\'
15:06:29.672043Z 1 [Note] [MY-012204] [InnoDB] Scanning '.\'
15:06:29.685581Z 1 [Note] [MY-012208] [InnoDB] Completed space ID check of 5 files.
15:06:29.687778Z 1 [Note] [MY-012955] [InnoDB] Initializing buffer pool, total size = 128.000000M, instances = 1, chunk size =128.000000M
15:06:29.698797Z 1 [Note] [MY-012957] [InnoDB] Completed initialization of buffer pool
15:06:29.728874Z 1 [Note] [MY-013532] [InnoDB] Using '.\#ib_16384_0.dblwr' for doublewrite
15:06:29.744309Z 1 [Note] [MY-013532] [InnoDB] Using '.\#ib_16384_1.dblwr' for doublewrite
15:06:29.919220Z 1 [Note] [MY-013566] [InnoDB] Double write buffer files: 2
15:06:29.919369Z 1 [Note] [MY-013565] [InnoDB] Double write buffer pages per instance: 4
15:06:29.921768Z 1 [Note] [MY-013532] [InnoDB] Using '.\#ib_16384_0.dblwr' for doublewrite
15:06:29.922112Z 1 [Note] [MY-013532] [InnoDB] Using '.\#ib_16384_1.dblwr' for doublewrite
15:06:30.031230Z 1 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 20077249 in redo log file .\#innodb_redo\#ib_redo6.
15:06:30.042967Z 1 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 20077135, whereas checkpoint_lsn = 20077249 and start_lsn = 20077056
15:06:30.063066Z 1 [Note] [MY-013083] [InnoDB] Log background threads are being started...
15:06:30.198367Z 1 [Note] [MY-012532] [InnoDB] Applying a batch of 0 redo log records ...
15:06:30.200421Z 1 [Note] [MY-012535] [InnoDB] Apply batch completed!
15:06:30.206925Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace '.\undo_001'.
15:06:30.234720Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace '.\undo_002'.
15:06:30.257561Z 1 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
15:06:30.257889Z 1 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 6930
15:06:35.888321Z 1 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete
15:06:35.889013Z 1 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 2 thread: 5631264 ms.
15:06:35.889867Z 1 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
15:06:35.890701Z 1 [Note] [MY-012265] [InnoDB] Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
15:06:36.155079Z 1 [Note] [MY-012266] [InnoDB] File '.\ibtmp1' size is now 12 MB.
15:06:36.197782Z 1 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:'.\#innodb_temp\'
15:06:36.869882Z 1 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
15:06:36.880050Z 0 [Note] [MY-011953] [InnoDB] Page cleaner took 7171ms to flush 0 and evict 0 pages
15:06:36.891173Z 1 [Note] [MY-012976] [InnoDB] 8.0.33 started; log sequence number 20077259
15:06:36.900241Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
15:06:36.935383Z 1 [Note] [MY-011089] [Server] Data dictionary restarting version '80023'.
15:06:37.394207Z 1 [Note] [MY-012357] [InnoDB] Reading DD tablespace files
15:06:37.401051Z 1 [Note] [MY-012356] [InnoDB] Scanned 7 tablespaces. Validated 7.
15:06:37.440551Z 1 [Note] [MY-010006] [Server] Using data dictionary with version '80023'.
15:06:37.463683Z 0 [Note] [MY-011332] [Server] Plugin mysqlx reported: 'IPv6 is available'
15:06:37.464049Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. bind-address: '::' port: 33060'
15:06:37.521160Z 0 [Note] [MY-010856] [Server] Failed to open the crashed binlog file when source server is recovering it.
15:06:37.536127Z 0 [Note] [MY-013911] [Server] Crash recovery finished in binlog engine. No attempts to commit, rollback or prepare any transactions.
15:06:37.536298Z 0 [Note] [MY-013911] [Server] Crash recovery finished in InnoDB engine. No attempts to commit, rollback or prepare any transactions.
15:06:37.541868Z 0 [Note] [MY-012487] [InnoDB] DDL log recovery : begin
15:06:37.543053Z 0 [Note] [MY-012488] [InnoDB] DDL log recovery : end
15:06:37.544282Z 0 [Note] [MY-011946] [InnoDB] Loading buffer pool(s) from D:\mysql-8.0.33-winx64\data\ib_buffer_pool
15:06:37.557816Z 0 [Note] [MY-011946] [InnoDB] Buffer pool(s) load completed at 230507 18:06:37
15:06:37.768943Z 0 [Note] [MY-010913] [Server] You have not provided a mandatory server-id. Servers in a replication topology must have unique server-ids. Please refer to the proper server start-up parameters documentation.
15:06:37.809648Z 0 [Note] [MY-010182] [Server] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
15:06:37.811074Z 0 [Note] [MY-010304] [Server] Skipping generation of SSL certificates as certificate files are present in data directory.
15:06:37.813504Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
15:06:37.813706Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
15:06:37.814381Z 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --sha256_password_auto_generate_rsa_keys as key files are present in data directory.
15:06:37.814676Z 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --caching_sha2_password_auto_generate_rsa_keys as key files are present in data directory.
15:06:37.815510Z 0 [Note] [MY-010252] [Server] Server hostname (bind-address): '*'; port: 3306
15:06:37.815747Z 0 [Note] [MY-010253] [Server] IPv6 is available.
15:06:37.815990Z 0 [Note] [MY-010264] [Server] — '::' resolves to '::';
15:06:37.816489Z 0 [Note] [MY-010251] [Server] Server socket created on IP: '::'.
15:06:37.885615Z 0 [Note] [MY-011025] [Repl] Failed to start replica threads for channel ''.
15:06:37.929100Z 0 [Note] [MY-011240] [Server] Plugin mysqlx reported: 'Using SSL configuration from MySQL Server'
15:06:37.930319Z 0 [Note] [MY-011243] [Server] Plugin mysqlx reported: 'Using OpenSSL for TLS connections'
15:06:37.931413Z 0 [System] [MY-010931] [Server] D:\mysql-8.0.33-winx64\bin\mysqld.exe: ready for connections. Version: '8.0.33' socket: '' port: 3306 MySQL Community Server — GPL.
15:06:37.932211Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060
15:06:37.933396Z 5 [Note] [MY-010051] [Server] Event Scheduler: scheduler thread started with id 5
Re[5]: MySql инициализация при каждом запуске
От: Sinclair Россия https://github.com/evilguest/
Дата: 29.11.23 05:55
Оценка:
Здравствуйте, CRT, Вы писали:

CRT>самая задержка примерно здесь (чтобы короче строки были, оставил только время, даты убрал)


CRT>

CRT>15:06:30.206925Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace '.\undo_001'.
CRT>15:06:30.234720Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace '.\undo_002'.
CRT>15:06:30.257561Z 1 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
CRT>15:06:30.257889Z 1 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 6930
CRT>15:06:35.888321Z 1 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete
CRT>
15:06:35.889013Z 1 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 2 thread: 5631264 ms.
CRT>15:06:35.889867Z 1 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
CRT>15:06:35.890701Z 1 [Note] [MY-012265] [InnoDB] Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
CRT>15:06:36.155079Z 1 [Note] [MY-012266] [InnoDB] File '.\ibtmp1' size is now 12 MB.
CRT>15:06:36.197782Z 1 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:'.\#innodb_temp\'
CRT>15:06:36.869882Z 1 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
CRT>15:06:36.880050Z 0 [Note] [MY-011953] [InnoDB] Page cleaner took 7171ms to flush 0 and evict 0 pages
CRT>15:06:36.891173Z 1 [Note] [MY-012976] [InnoDB] 8.0.33 started; log sequence number 20077259
CRT>15:06:36.900241Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.


Выглядит похоже на https://bugs.mysql.com/bug.php?id=108586
Какое значение у innodb_redo_log_capacity?
Уйдемте отсюда, Румата! У вас слишком богатые погреба.
 
Подождите ...
Wait...
Пока на собственное сообщение не было ответов, его можно удалить.