[MDEV-30829] InnoDB: Cannot close file <tablename>.ibd because of pending fsync Created: 2023-03-10  Updated: 2023-08-28  Resolved: 2023-08-28

Status: Closed
Project: MariaDB Server
Component/s: OTHER
Affects Version/s: 10.5.19
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Devang Assignee: Marko Mäkelä
Resolution: Incomplete Votes: 1
Labels: replication
Environment:

Ubuntu 20 LTS x86_64 with 64GB Physical RAM

Issue Links:
Relates
relates to MDEV-25215 Excessive logging "Cannot close file ... Closed
relates to MDEV-30775 Performance regression in fil_space_t... Closed
relates to MDEV-31049 fil_delete_tablespace() returns wrong... Closed
relates to MDEV-31347 fil_ibd_create() may hijack the file ... Closed

 Description   

Dear Engineer
Since we switched one of the replication slave machines to 10.5.19, we are observing the following strange messages in our MariaDB error log file.

2023-01-01 21:20:13 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-01 21:30:13 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-01 22:00:13 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-01 22:10:14 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-01 23:00:14 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-02  0:50:02 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-02  1:10:02 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-02  2:10:03 449813 [Note] InnoDB: Cannot close file ./cvt/specificroutes008.ibd because of pending fsync
 
2023-01-02  5:20:01 469053 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  5:20:06 469053 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  5:20:11 469053 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  5:40:07 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  5:50:07 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  6:10:07 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  6:20:07 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  7:00:08 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  7:10:08 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  7:30:09 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  9:00:10 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02  9:10:10 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02 10:50:12 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02 11:00:12 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-02 11:20:12 469671 [Note] InnoDB: Cannot close file ./cvt/log01.ibd because of pending fsync
 
2023-01-06  4:02:37 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  4:10:09 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  4:20:09 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  4:30:09 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  4:40:10 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  4:50:10 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  5:00:10 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  5:10:10 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  5:20:10 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  5:50:11 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  6:10:11 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-06  9:20:14 140075 [Note] InnoDB: Cannot close file ./cvt/standardroutes.ibd because of pending fsync
 
2023-01-08  4:10:01 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  4:20:01 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  4:50:02 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  5:00:02 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  5:20:02 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  5:50:03 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  6:00:03 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  6:10:03 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08  9:30:06 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08 13:20:11 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08 13:30:11 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08 15:50:14 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-08 18:10:01 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-09  2:40:10 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-01-09  2:50:10 262765 [Note] InnoDB: Cannot close file ./cvt/activesessionlog.ibd because of pending fsync
 
2023-02-04  4:10:02 1295717 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  4:20:02 1295717 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  4:30:02 1295717 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  4:40:02 1295717 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  4:50:03 1295717 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  6:10:04 1296239 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  6:20:04 1296239 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-04  6:52:17 1297925 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-05 13:20:05 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
 
2023-02-05 13:30:05 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
 
2023-02-05 14:10:06 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
 
2023-02-05 20:10:12 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
 
2023-02-05 23:10:00 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
 
2023-02-11  5:30:12 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  5:40:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  5:50:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  6:00:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  6:10:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  6:30:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  7:00:14 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  7:10:14 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  7:50:00 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11  8:10:00 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 10:30:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 10:40:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 14:10:06 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 14:20:06 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 15:00:07 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 15:10:07 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 15:40:08 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 18:10:10 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 18:20:10 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 20:20:12 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 20:50:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 21:20:14 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-11 22:20:00 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-12  0:10:01 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-12  1:10:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-12  1:20:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-12  2:10:03 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-12  2:40:04 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-12  3:20:04 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
 
2023-02-27  4:02:28 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:02:40 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:02:46 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:02:57 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:03:03 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:03:08 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:05:47 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:06:21 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:40:11 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  4:50:11 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  5:00:11 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  5:30:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  5:40:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  5:50:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  6:00:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  6:10:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  6:40:13 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-02-27  6:50:13 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
 
2023-03-06  4:02:33 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  4:10:09 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  4:20:09 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  5:00:10 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  5:50:11 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  6:00:11 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  6:10:11 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  9:40:14 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06  9:50:00 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06 11:10:01 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
 
2023-03-06 15:10:06 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync

As you can see every time the table name (IBD) is getting changed?
We are not sure "Is it a bug or some kind of config error or hardware-related issue or what?"
Even do not know if it is affecting the replication quality or not.
One thing we can say is that it is only pointing to an InnoDB table while we have lots of MyISAM tables too.

Below I am placing the current configuration file too

[client]
 
port=3306
 
socket=/run/mysqld/mysqld.sock
 
 
 
[mysqld-safe]
 
socket=/run/mysqld/mysqld.sock
 
nice=0
 
log-error=/var/log/mysqld.log
 
pid-file=/data/mysqld.pid
 
 
 
[mysqld]
 
user=mysql
 
socket=/run/mysqld/mysqld.sock
 
bind-address=0.0.0.0
 
port=3306
 
basedir=/usr
 
datadir=/data
 
pid-file=/data/mysqld.pid
 
log-error=/var/log/mysqld.log
 
performance-schema=0
 
sql-mode=""
 
log-warnings=0
 
#slow-query-log = 1
 
#long-query-time = 3
 
#slow-query_log-file = /var/log/mysqld-slow.log
 
#long-query-time=1
 
max-connections=100
 
tmpdir=/tmp/
 
bulk-insert-buffer-size=256M
 
innodb-file-per-table = 1
 
innodb-data-home-dir=/data
 
innodb-data-file-path=ibdata1:1G:autoextend
 
innodb-buffer-pool-size=10G
 
innodb-log-file-size=1G
 
innodb-log-buffer-size=1G
 
innodb_stats_persistent=0
 
preload-buffer-size=1M
 
sort-buffer-size=1M
 
myisam-sort-buffer-size=1M
 
key-buffer-size=4G
 
thread-stack=8M
 
bulk-insert-buffer-size=2M
 
innodb-flush-log-at-trx-commit=2
 
table-cache=512
 
query-cache-size=96M
 
query-cache-type=1
 
query-cache-limit=1M
 
join-buffer-size=1M
 
tmp-table-size=64M
 
max-heap-table-size=64M
 
read-buffer-size=2M
 
read-rnd-buffer-size=2M
 
bulk-insert-buffer-size=2M
 
myisam-sort-buffer-size=2M
 
myisam-max-sort-file-size=2M
 
myisam-repair-threads=1
 
#log-bin-trust-function-creators=1
 
interactive-timeout=5000
 
wait-timeout=5000
 
log-bin = /backup/mysqlbinlog/teak15-bin
 
log-bin-index = /backup/mysqlbinlog/teak15-bin-index
 
expire-logs-days = 30
 
server-id = 15
 
innodb-fast-shutdown=0
 
innodb-force-recovery=0
 
max-allowed-packet=256M
 
binlog-format = STATEMENT
 
log-slave-updates=1
 
binlog-ignore-db=information_schema
 
binlog-ignore-db=mysql
 
binlog-ignore-db=performance_schema
 
binlog-ignore-db=test
 
replicate-ignore-db=information_schema
 
replicate-ignore-db=mysql
 
replicate-ignore-db=performance_schema
 
replicate-ignore-db=test
 
default-tmp-storage-engine=MyISAM
 
optimizer-switch='rowid_filter=off'
 
 
 
[mysqldump]
 
quick
 
quote-names
 
max-allowed-packet=256M

please help us
thanks
Devang

 Comments   
Comment by Devang [ 2023-03-10 ]

================= Complete Log File ==============

2023-02-04 6:52:41 0 [Note] InnoDB: Uses event mutexes
2023-02-04 6:52:41 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2023-02-04 6:52:41 0 [Note] InnoDB: Number of pools: 1
2023-02-04 6:52:41 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
2023-02-04 6:52:41 0 [Note] InnoDB: Using Linux native AIO
2023-02-04 6:52:41 0 [Note] InnoDB: Initializing buffer pool, total size = 10737418240, chunk size = 134217728
2023-02-04 6:52:41 0 [Note] InnoDB: Completed initialization of buffer pool
2023-02-04 6:52:41 0 [Note] InnoDB: 128 rollback segments are active.
2023-02-04 6:52:41 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2023-02-04 6:52:41 0 [Note] InnoDB: Setting file '/data/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2023-02-04 6:52:41 0 [Note] InnoDB: File '/data/ibtmp1' size is now 12 MB.
2023-02-04 6:52:41 0 [Note] InnoDB: 10.5.18 started; log sequence number 197055562984; transaction id 228259782
2023-02-04 6:52:41 0 [Note] InnoDB: Loading buffer pool(s) from /data/ib_buffer_pool
2023-02-04 6:52:41 0 [Note] Server socket created on IP: '0.0.0.0'.
2023-02-04 6:52:41 0 [Warning] Neither -relay-log nor --relay-log-index were used; so replication may break when this MariaDB server acts as a replica and has its hostname changed. Please use 'log-basename=#' or '-relay-log=mysqld-relay-bin' to avoid this problem.
2023-02-04 6:52:41 5 [Note] Slave I/O thread: Start asynchronous replication to master 'repluser@teak19:3306' in log 'teak19-bin.002180' at position 596645262
2023-02-04 6:52:41 0 [Note] /usr/sbin/mariadbd: ready for connections.
Version: '10.5.18-MariaDB-1:10.5.18+maria~ubu2004-log' socket: '/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
2023-02-04 6:52:41 5 [Note] Slave I/O thread: connected to master 'repluser@teak19:3306',replication started in log 'teak19-bin.002180' at position 596645262
2023-02-04 6:52:51 0 [Note] InnoDB: Buffer pool(s) load completed at 230204 6:52:51
2023-02-05 4:00:01 6 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002181' at position 324209372
2023-02-05 4:00:01 6 [Note] master was teak19:3306
2023-02-05 13:20:05 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
2023-02-05 13:30:05 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
2023-02-05 14:10:06 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
2023-02-05 20:10:12 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
2023-02-05 23:10:00 29055 [Note] InnoDB: Cannot close file ./cvt/transactivitysc027.ibd because of pending fsync
2023-02-06 4:00:01 29055 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002182' at position 106154613
2023-02-06 4:00:01 29055 [Note] master was teak19:3306
2023-02-06 20:09:53 0 [Note] /usr/sbin/mariadbd (initiated by: unknown): Normal shutdown
2023-02-06 20:09:53 0 [Note] Event Scheduler: Purging the queue. 0 events
2023-02-06 20:09:53 60597 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002183' at position 15820497
2023-02-06 20:09:53 60597 [Note] master was teak19:3306
2023-02-06 20:09:53 5 [Note] Slave I/O thread exiting, read up to log 'teak19-bin.002183', position 15820497
2023-02-06 20:09:53 5 [Note] master was teak19:3306
2023-02-06 20:09:53 0 [Note] InnoDB: FTS optimize thread exiting.
2023-02-06 20:09:53 0 [Note] InnoDB: to purge 7 transactions
2023-02-06 20:09:53 0 [Note] InnoDB: Starting shutdown...
2023-02-06 20:09:53 0 [Note] InnoDB: Dumping buffer pool(s) to /data/ib_buffer_pool
2023-02-06 20:09:53 0 [Note] InnoDB: Restricted to 161300 pages due to innodb_buf_pool_dump_pct=25
2023-02-06 20:09:53 0 [Note] InnoDB: Buffer pool(s) dump completed at 230206 20:09:53
2023-02-06 20:09:56 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2023-02-06 20:09:56 0 [Note] InnoDB: Shutdown completed; log sequence number 198269566202; transaction id 234727080
2023-02-06 20:09:56 0 [Note] /usr/sbin/mariadbd: Shutdown complete

2023-02-06 20:09:56 0 [Note] InnoDB: Uses event mutexes
2023-02-06 20:09:56 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2023-02-06 20:09:56 0 [Note] InnoDB: Number of pools: 1
2023-02-06 20:09:56 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
2023-02-06 20:09:56 0 [Note] InnoDB: Using Linux native AIO
2023-02-06 20:09:56 0 [Note] InnoDB: Initializing buffer pool, total size = 10737418240, chunk size = 134217728
2023-02-06 20:09:57 0 [Note] InnoDB: Completed initialization of buffer pool
2023-02-06 20:09:57 0 [Note] InnoDB: 128 rollback segments are active.
2023-02-06 20:09:57 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2023-02-06 20:09:57 0 [Note] InnoDB: Setting file '/data/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2023-02-06 20:09:57 0 [Note] InnoDB: File '/data/ibtmp1' size is now 12 MB.
2023-02-06 20:09:57 0 [Note] InnoDB: 10.5.18 started; log sequence number 198269566202; transaction id 234727065
2023-02-06 20:09:57 0 [Note] InnoDB: Loading buffer pool(s) from /data/ib_buffer_pool
2023-02-06 20:09:57 0 [Note] Server socket created on IP: '0.0.0.0'.
2023-02-06 20:09:57 0 [Warning] Neither -relay-log nor --relay-log-index were used; so replication may break when this MariaDB server acts as a replica and has its hostname changed. Please use 'log-basename=#' or '-relay-log=mysqld-relay-bin' to avoid this problem.
2023-02-06 20:09:57 5 [Note] Slave I/O thread: Start asynchronous replication to master 'repluser@teak19:3306' in log 'teak19-bin.002183' at position 15820497
2023-02-06 20:09:57 0 [Note] /usr/sbin/mariadbd: ready for connections.
Version: '10.5.18-MariaDB-1:10.5.18+maria~ubu2004-log' socket: '/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
2023-02-06 20:09:57 5 [Note] Slave I/O thread: connected to master 'repluser@teak19:3306',replication started in log 'teak19-bin.002183' at position 15820497
2023-02-06 20:10:06 0 [Note] InnoDB: Buffer pool(s) load completed at 230206 20:10:06
2023-02-07 4:00:01 6 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002183' at position 517543426
2023-02-07 4:00:01 6 [Note] master was teak19:3306
2023-02-08 4:00:01 17489 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002184' at position 960208324
2023-02-08 4:00:01 17489 [Note] master was teak19:3306
2023-02-09 4:00:01 72861 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002186' at position 482666422
2023-02-09 4:00:01 72861 [Note] master was teak19:3306
2023-02-10 4:00:01 131918 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002188' at position 463524334
2023-02-10 4:00:01 131918 [Note] master was teak19:3306
2023-02-11 4:00:02 209557 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002190' at position 772373142
2023-02-11 4:00:02 209557 [Note] master was teak19:3306
2023-02-11 5:30:12 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 5:40:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 5:50:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 6:00:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 6:10:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 6:30:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 7:00:14 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 7:10:14 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 7:50:00 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 8:10:00 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 10:30:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 10:40:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 14:10:06 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 14:20:06 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 15:00:07 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 15:10:07 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 15:40:08 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 18:10:10 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 18:20:10 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 20:20:12 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 20:50:13 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 21:20:14 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-11 22:20:00 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 0:10:01 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 1:10:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 1:20:02 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 2:10:03 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 2:40:04 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 3:20:04 297501 [Note] InnoDB: Cannot close file ./cvt/deliveryaddress.ibd because of pending fsync
2023-02-12 4:00:01 297501 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002191' at position 505560569
2023-02-12 4:00:01 297501 [Note] master was teak19:3306
2023-02-12 19:55:27 327641 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002191' at position 954478187
2023-02-12 19:55:27 327641 [Note] master was teak19:3306
2023-02-14 4:00:01 349216 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002193' at position 873421792
2023-02-14 4:00:01 349216 [Note] master was teak19:3306
2023-02-15 4:00:01 421242 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002195' at position 229652500
2023-02-15 4:00:01 421242 [Note] master was teak19:3306
2023-02-16 4:00:01 475431 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002196' at position 743261716
2023-02-16 4:00:01 475431 [Note] master was teak19:3306
2023-02-17 4:00:01 531778 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002198' at position 715496122
2023-02-17 4:00:01 531778 [Note] master was teak19:3306
2023-02-18 4:00:01 607281 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002201' at position 30157775
2023-02-18 4:00:01 607281 [Note] master was teak19:3306
2023-02-19 4:00:01 695913 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002201' at position 849164294
2023-02-19 4:00:01 695913 [Note] master was teak19:3306
2023-02-20 3:02:57 725946 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002202' at position 210420559
2023-02-20 3:02:57 725946 [Note] master was teak19:3306
2023-02-20 19:49:17 746453 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002203' at position 348836533
2023-02-20 19:49:17 746453 [Note] master was teak19:3306
2023-02-22 4:00:01 792267 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002205' at position 163571652
2023-02-22 4:00:01 792267 [Note] master was teak19:3306
2023-02-23 4:00:01 862423 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002206' at position 727845843
2023-02-23 4:00:01 862423 [Note] master was teak19:3306
2023-02-24 4:00:01 919996 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002208' at position 737673540
2023-02-24 4:00:01 919996 [Note] master was teak19:3306
2023-02-25 4:00:01 998170 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002210' at position 1057783776
2023-02-25 4:00:01 998170 [Note] master was teak19:3306
2023-02-26 4:00:01 1086523 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002211' at position 801420553
2023-02-26 4:00:01 1086523 [Note] master was teak19:3306
2023-02-26 20:28:21 1116945 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002212' at position 75381769
2023-02-26 20:28:21 1116945 [Note] master was teak19:3306
2023-02-27 4:02:28 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:02:40 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:02:46 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:02:57 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:03:03 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:03:08 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:05:47 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:06:21 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:40:11 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 4:50:11 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 5:00:11 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 5:30:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 5:40:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 5:50:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 6:00:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 6:10:12 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 6:40:13 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-27 6:50:13 1134307 [Note] InnoDB: Cannot close file ./cvt/transactivity005.ibd because of pending fsync
2023-02-28 4:00:02 1134307 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002213' at position 886992029
2023-02-28 4:00:02 1134307 [Note] master was teak19:3306
2023-03-01 4:00:01 1200559 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002215' at position 370314333
2023-03-01 4:00:01 1200559 [Note] master was teak19:3306
2023-03-02 4:00:01 1260748 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002216' at position 968741430
2023-03-02 4:00:01 1260748 [Note] master was teak19:3306
2023-03-03 4:00:01 1320145 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002218' at position 920805230
2023-03-03 4:00:01 1320145 [Note] master was teak19:3306
2023-03-03 4:07:10 1396685 [ERROR] Slave SQL: Error 'Can't create table `cvt`.`tmp_scan_trd41` (errno: 28 "No space left on device")' on query. Default database: 'cvt'. Query: 'CREATE /TRD41/ TEMPORARY TABLE tmp_scan_trd41 (
prod_desc varchar(100) NOT NULL,
datesked DATE NOT NULL DEFAULT '0000-00-00',
quantity BIGINT(5) NOT NULL

)', Gtid 0-19-9232202501, Internal MariaDB error code: 1005
2023-03-03 4:07:10 1396685 [Warning] Slave: Can't create table `cvt`.`tmp_scan_trd41` (errno: 28 "No space left on device") Error_code: 1005
2023-03-03 4:07:10 1396685 [Warning] Slave: Disk full (/tmp/#sql-temptable-19b159-154fcd-d.MYI); waiting for someone to free some space... (errno: 28 "No space left on device") Error_code: 1021
2023-03-03 4:07:10 1396685 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'teak19-bin.002218' position 930682471
2023-03-03 4:07:10 1396685 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002218' at position 930682471
2023-03-03 4:07:10 1396685 [Note] master was teak19:3306
2023-03-03 5:01:22 5 [ERROR] Error reading packet from server: Lost connection to server during query (server_errno=2013)
2023-03-03 5:01:22 5 [Note] Slave I/O thread exiting, read up to log 'teak19-bin.002218', position 984644432
2023-03-03 5:01:22 5 [Note] master was teak19:3306
2023-03-03 5:01:22 1397037 [Note] Slave I/O thread: Start asynchronous replication to master 'repluser@teak19:3306' in log 'teak19-bin.002218' at position 984644432
2023-03-03 5:01:22 1397037 [Note] Slave I/O thread: connected to master 'repluser@teak19:3306',replication started in log 'teak19-bin.002218' at position 984644432
2023-03-03 20:07:10 1397038 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002220' at position 672704329
2023-03-03 20:07:10 1397038 [Note] master was teak19:3306
2023-03-03 20:53:10 1397037 [Note] Slave: received end packet from server, apparent master shutdown:
2023-03-03 20:53:10 1397037 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'teak19-bin.002220' at position 674822978
2023-03-03 20:53:10 1397037 [ERROR] Slave I/O: error reconnecting to master 'repluser@teak19:3306' - retry-time: 60 maximum-retries: 86400 message: Can't connect to server on 'teak19' (111 "Connection refused"), Internal MariaDB error code: 2003
2023-03-03 21:04:34 1397037 [Note] Slave: received end packet from server, apparent master shutdown:
2023-03-03 21:04:34 1397037 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'teak19-bin.002221' at position 359
2023-03-03 21:04:34 1397037 [ERROR] Slave I/O: error reconnecting to master 'repluser@teak19:3306' - retry-time: 60 maximum-retries: 86400 message: Can't connect to server on 'teak19' (111 "Connection refused"), Internal MariaDB error code: 2003
2023-03-04 4:02:58 1467234 [Warning] Could not remove temporary table: '/tmp/#sql-temptable-19b159-6-0', error: 2
2023-03-04 7:51:05 1467234 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002222' at position 569278929
2023-03-04 7:51:05 1467234 [Note] master was teak19:3306
2023-03-04 7:51:05 1397037 [Note] Slave I/O thread exiting, read up to log 'teak19-bin.002222', position 569278929
2023-03-04 7:51:05 1397037 [Note] master was teak19:3306
2023-03-05 4:05:52 1487651 [Note] Slave SQL thread exiting, replication stopped in log 'FIRST' at position 0
2023-03-05 4:05:52 1487651 [Note] master was teak19:3306
2023-03-05 19:20:44 1489689 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='teak19', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='teak19', master_port='3306', master_log_file='teak19-bin.002220', master_log_pos='674822978'.
2023-03-05 19:20:47 1489690 [Note] Slave I/O thread: Start asynchronous replication to master 'repluser@teak19:3306' in log 'teak19-bin.002220' at position 674822978
2023-03-05 19:20:47 1489690 [Note] Slave I/O thread: connected to master 'repluser@teak19:3306',replication started in log 'teak19-bin.002220' at position 674822978
2023-03-06 4:00:01 1489691 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002224' at position 28575140
2023-03-06 4:00:01 1489691 [Note] master was teak19:3306
2023-03-06 4:02:33 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 4:10:09 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 4:20:09 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 5:00:10 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 5:50:11 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 6:00:11 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 6:10:11 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 9:40:14 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 9:50:00 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 11:10:01 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-06 15:10:06 1568412 [Note] InnoDB: Cannot close file ./cvt/specificproduct.ibd because of pending fsync
2023-03-07 4:00:01 1568412 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002225' at position 313618356
2023-03-07 4:00:01 1568412 [Note] master was teak19:3306
2023-03-07 21:52:05 1489690 [Note] Slave: received end packet from server, apparent master shutdown:
2023-03-07 21:52:05 1489690 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'teak19-bin.002226' at position 273582920
2023-03-07 21:52:05 1489690 [ERROR] Slave I/O: error reconnecting to master 'repluser@teak19:3306' - retry-time: 60 maximum-retries: 86400 message: Can't connect to server on 'teak19' (111 "Connection refused"), Internal MariaDB error code: 2003
2023-03-08 4:00:01 1617577 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002227' at position 493109378
2023-03-08 4:00:01 1617577 [Note] master was teak19:3306
2023-03-09 4:00:01 1671885 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002228' at position 1006531182
2023-03-09 4:00:01 1671885 [Note] master was teak19:3306
2023-03-10 4:00:01 1727959 [Note] Slave SQL thread exiting, replication stopped in log 'teak19-bin.002230' at position 889991041
2023-03-10 4:00:01 1727959 [Note] master was teak19:3306

Comment by Marko Mäkelä [ 2023-03-10 ]

I do not see anything really out of the ordinary here. Excessive logging was fixed in MDEV-25215. Have you tried using a larger InnoDB buffer pool or log size, to reduce the minimum frequency of log checkpoints? Is it possible to configure innodb_open_files to be larger?

Possibly this would be improved by MDEV-30775.

Comment by Marko Mäkelä [ 2023-08-04 ]

I just realized that frequent closing and re-opening of InnoDB files could cause corruption due to a bug like MDEV-31347 or MDEV-31049.

Generated at Thu Feb 08 10:19:13 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.