[MDEV-24227] mysql_install_db hangs for ~45 minutes Created: 2020-11-17  Updated: 2021-05-25  Resolved: 2021-05-25

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.5.8
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Anton Serbulov Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: hang, need_feedback
Environment:

Microsoft Windows Server 2019 Datacenter
10.5.8-MariaDB for Win64 on AMD64 (mariadb.org binary distribution)

Attachments: Microsoft Word FlushBuffersFile.CSV     Microsoft Word WriteFile.CSV     PNG File mysqld_procmon_events.png     Text File stacktraces.txt    
Issue Links:
Relates
relates to MDEV-24188 Hang in buf_page_create() after reusi... Closed

 Description   

Steps to reproduce
Initializing the MariaDB data directory

C:\Users\Administrator>C:\mariadb-10.5.8-winx64\bin\mysql_install_db.exe --datadir=C:\db
 
Running bootstrap
 
2020-11-17 11:39:15 0 [Note] C:\mariadb-10.5.8-winx64\bin\mysqld.exe (mysqld 10.5.8-MariaDB) starting as process 2504 ...

Actual Result
The process hangs for ~ 45 minutes.

In the log file:

InnoDB: using atomic writes.
 
2020-11-17 11:39:16 0 [Note] InnoDB: The first innodb_system data file 'ibdata1' did not exist. A new tablespace will be created!
 
2020-11-17 11:39:16 0 [Note] InnoDB: Uses event mutexes
 
2020-11-17 11:39:16 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2020-11-17 11:39:16 0 [Note] InnoDB: Number of pools: 1
 
2020-11-17 11:39:16 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
 
2020-11-17 11:39:16 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
 
2020-11-17 11:39:16 0 [Note] InnoDB: Completed initialization of buffer pool
 
2020-11-17 11:39:16 0 [Note] InnoDB: Setting file '.\ibdata1' size to 12 MB. Physically writing the file full; Please wait ...
 
2020-11-17 11:39:16 0 [Note] InnoDB: File '.\ibdata1' size is now 12 MB.
 
2020-11-17 11:39:16 0 [Note] InnoDB: Setting log file .\ib_logfile101 size to 100663296 bytes
 
2020-11-17 12:14:23 0 [Note] InnoDB: Renaming log file .\ib_logfile101 to .\ib_logfile0
 
2020-11-17 12:14:23 0 [Note] InnoDB: New log file created, LSN=1204865
 
2020-11-17 12:14:23 0 [Note] InnoDB: Doublewrite buffer not found: creating new
 
2020-11-17 12:14:24 0 [Note] InnoDB: Doublewrite buffer created
 
2020-11-17 12:14:24 0 [Note] InnoDB: 128 rollback segments are active.
 
2020-11-17 12:14:24 0 [Note] InnoDB: Creating foreign key constraint system tables.
 
2020-11-17 12:14:24 0 [Note] InnoDB: Creating tablespace and datafile system tables.
 
2020-11-17 12:14:24 0 [Note] InnoDB: Creating sys_virtual system tables.
 
2020-11-17 12:14:24 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2020-11-17 12:14:24 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2020-11-17 12:14:24 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
 
2020-11-17 12:14:24 0 [Note] InnoDB: 10.5.8 started; log sequence number 0; transaction id 7
 
2020-11-17 12:14:24 0 [Note] Plugin 'FEEDBACK' is disabled.



 Comments   
Comment by Marko Mäkelä [ 2020-11-17 ]

I suspect that this is due to MDEV-24188. Is this repeatable with a recent development snapshot of 10.5, where that hang has been fixed?

Comment by Anton Serbulov [ 2020-11-17 ]

Where can I download the binary distribution of the recent 10.5 development snapshot?

Comment by Marko Mäkelä [ 2020-11-17 ]

wlad, can you please help skvoboo get Windows executables of a 10.5 development snapshot? In the usual place I only see them for various GNU/Linux distributions.

Comment by Vladislav Vaintroub [ 2020-11-17 ]

well, mysql_install_db.exe is tested every single time on buildbot, and we'd have noticed if something does not work repeatably.
skvoboo, I think the best would be to provide a memory dump of the mysqld process which is started by mysql_install_db.exe during the hang (you can do that from task manager with right-click and "create dump file")

In the meantime, was there anything interesting in procmon output, that I failed to detect yet?

Comment by Anton Serbulov [ 2020-11-17 ]

The full memory dump of the mysqld process: ftp.askmonty.org/private/mysqld.exe_201117_114801.zip

Comment by Vladislav Vaintroub [ 2020-11-17 ]

Thanks. It looks like WriteFile with Flush would hang on some reason, for which I'd rather put blame on Windows than to our software. That said, I can't reproduce anything like that.
Is C:\ formatted as NTFS? Are you able to reproduce it on more than a single machine?

Comment by Anton Serbulov [ 2020-11-20 ]

You're right.
The issue seems to be related to our environment.
Thanks.

Comment by Vladislav Vaintroub [ 2020-11-20 ]

skvoboo. Thanks, I'd still like to reproduce it elsewhere. In 10.5.7, we're using "lighter" version of FlushFileBuffers, courtesy of MDEV-24037 . I was wondering about specific circumstances that could make it misbehave. On the other hand, it also might be the first version, where WriteFile and flushing happen at the same time, this is not absolutely optimal on Windows, as I tested before, yet should not lead to 45 minute waits.

Comment by Marko Mäkelä [ 2021-03-24 ]

skvoboo, would MariaDB 10.5.9 work for you? I wonder if this could have been caused by MDEV-24275.

Comment by Anton Serbulov [ 2021-03-26 ]

The issue is still persists on our environment.

Comment by Elena Stepanova [ 2021-04-25 ]

skvoboo,

So, if you have verified that the issue is specific to your environment, can you provide the details of the environment which cause it, so that wlad would be able to reproduce it elsewhere?

Comment by Anton Serbulov [ 2021-04-26 ]

Our environment: Parallels Cloud Server 6.0

Comment by Vladislav Vaintroub [ 2021-04-26 ]

skvoboo, if the issue persists in your environment, and nowhere else, perhaps, you like to talk to Parallels Cloud Server people about it.

Comment by Vladislav Vaintroub [ 2021-05-25 ]

Seems to be not our bug, but related to exotic environment. No storage related system call should take 45 minutes.

Generated at Thu Feb 08 09:28:23 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.