[MDEV-29530] .frm was lost after database was not shutdown normally Created: 2022-09-14  Updated: 2022-10-17  Resolved: 2022-10-17

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

Type: Bug Priority: Major
Reporter: Johann Natividad Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: None


 Description   

Our server shutdown abnormally after no space left on the device, then after recovery, a certain .frm file was lost and some tables are corrupted.

2022-08-23 12:00:05 7fbfc83dcf00 InnoDB: Error: Write to file ./new_meeting_master_hanpda/te_groupware_businesstrips.ibd failed at offset 65536.
 
2022-08-23 12:00:05 7fbfc83dcf00  InnoDB: Assertion failure in thread 140461674974976 in file fil0fil.cc line 5910
 
2022-08-23 12:00:10 139691168835456 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-08-23 12:00:10 139691168835456 [Note] /home/db/mariadb/bin/mysqld (mysqld 10.1.14-MariaDB) starting as process 8800 ...
 
2022-08-23 12:00:11 7f0c627f2780 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
 
2022-08-23 12:00:11 139691168835456 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2022-08-23 12:00:11 139691168835456 [Note] InnoDB: The InnoDB memory heap is disabled
 
2022-08-23 12:00:11 139691168835456 [Note] InnoDB: Mutexes and rw_locks use GCC atom80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
 
2022-08-23 12:00:17 139691168835456 [Note] InnoDB: 128 rollback segment(s) are active.
 
2022-08-23 12:00:17 139691168835456 [Note] InnoDB: Waiting for purge to start
 
2022-08-23 12:00:17 139691168835456 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.29-76.2 started; log sequence number 1445603599479
 
2022-08-23 12:00:17 139689705051904 [Note] InnoDB: Dumping buffer pool(s) not yet started
 
2022-08-23 12:00:17 139691168835456 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-08-23 12:00:17 139691168835456 [Note] Recovering after a crash using tc.log
 
2022-08-23 12:00:17 139691168835456 [Note] Starting crash recovery...
 
2022-08-23 12:00:17 139691168835456 [Note] Crash recovery finished.
 
2022-08-23 12:00:17 139691168835456 [Note] Server socket created on IP: '0.0.0.0'.
 
2022-08-23 12:00:17 139691168714496 [ERROR] mysqld: Error writing file '/home/db/mariadb/data/mariadb.pid' (Errcode: 28 "No space left on device")
 
2022-08-23 12:00:17 139691168714496 [ERROR] Can't start server: can't create PID file: No space left on device
 
2022-08-23 12:00:18 140375693252480 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-08-23 12:00:18 140375693252480 [Note] /home/db/mariadb/bin/mysqld (mysqld 10.1.14-MariaDB) starting as process 8931 ...
 
2022-08-23 12:00:18 7fabc354d780 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: The InnoDB memory heap is disabled
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: Memory barrier is not used
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: Compressed tables use zlib 1.2.7
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: Using Linux native AIO
 
2022-08-23 12:00:18 140375693252480 [Note] InnoDB: Using SSE crc32 instructions
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Initializing buffer pool, size = 256.0M
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Completed initialization of buffer pool
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Highest supported file format is Barracuda.
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: The log sequence numbers 974895060676 and 974895060676 in ibdata files do not match the log sequence number 1445603599489 in the ib_logfiles!
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Database was not shutdown normally!
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Starting crash recovery.
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Reading tablespace information from the .ibd files...
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Restoring possible half-written data pages
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: from the doublewrite buffer...
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: 128 rollback segment(s) are active.
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB: Waiting for purge to start
 
2022-08-23 12:00:19 140375693252480 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.29-76.2 started; log sequence number 1445603599489
 
2022-08-23 12:00:19 140374232241920 [Note] InnoDB: Dumping buffer pool(s) not yet started
 
2022-08-23 12:00:19 140375693252480 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-08-23 12:00:19 140375693252480 [Note] Recovering after a crash using tc.log
 
2022-08-23 12:00:19 140375693252480 [Note] Starting crash recovery...
 
2022-08-23 12:00:19 140375693252480 [Note] Crash recovery finished.
 
2022-08-23 12:00:20 140375693252480 [Note] Server socket created on IP: '0.0.0.0'.
 
2022-08-23 12:00:20 140375693131520 [ERROR] mysqld: Error writing file '/home/db/InnoDB: Error: trying to load index PRIMARY for table new_meeting_master_hanpda/te_groupware_businesstrips
 
2022-08-23 12:10:35 139829580807936 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:11:35 139829580533504 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:12:35 139829580533504 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:13:35 139829580259072 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:14:35 139829579984640 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:15:35 139829544644352 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:16:35 139829579984640 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:17:35 139829579710208 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 12:18:35 139829579984640 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm fInnoDB: Error: trying to load index PRIMARY for table new_meeting_master_hanpda/te_groupware_businesstrips
 
2022-08-23 13:48:35 139829580807936 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 13:49:35 139829544644352 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 13:50:35 139829579984640 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2022-08-23 13:51:35 139829579984640 [Warning] InnoDB: Cannot open table new_meeting_master_hanpda/te_groupware_businesstrips from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.



 Comments   
Comment by Sergei Golubchik [ 2022-09-14 ]

it's highly unlikely that an .frm file was actually lost. These files are written once and are never modified after that.
More likely that an .frm file was never written in the first place, because of "no space left on the device".

Comment by Johann Natividad [ 2022-09-15 ]

The .frm file is an active table.

What we do not understand is why .frm will be deleted from the disk after service crash? Or is it a bug?

Comment by Sergei Golubchik [ 2022-09-15 ]

.frm can be deleted in only two cases:

  • DROP TABLE
  • ALTER TABLE, and in this case .frm is not deleted outright, but first new .frm is created under a temporary name, old .frm is renamed to a backup name, new .frm is renamed into its place, and only then old .frm is deleted.

That is, for an .frm file to simply disappear it could only be a DROP TABLE. Or you had the whole system going down and on startup fcsk repaired the filesystem and as a result some files went missing. Depends on the filesystem, I think I've had something similar on JFS.

Comment by Johann Natividad [ 2022-09-16 ]

Thanks Sergei for the explanation, but, that is not the case.

  • The incident happened in the middle of the night, and its a production database. No one touches the database except me. (So im sure I dont drop incidentally the table).
  • The missing .frm happened only after the crash recovery.
  • Crash recovery happened in just a few seconds only (so its impossible to perform fcsk task)
Comment by Sergei Golubchik [ 2022-10-17 ]

10.1.14 is 6.5 years old. Whatever bugs it had is likely no longer relevant.

Normally, I'd ask to repeat the bug on a supported MariaDB version, but considering the nature of the bug, it seems unlikely, so I'm going to close it now.

But, of course, if you will repeat it on a supported MariaDB version — please, leave a comment here and I'll reopen it again.

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