Data loss after hardware fault
Posted by: Tobia Bea
Date: November 15, 2014 08:15AM
Date: November 15, 2014 08:15AM
I'm experiencing some troubles with data loss after power or hardware fault of a innodb/mysql installation in desktop PC computer. Db is used by a web application used every days.
These are the facts
- 5/nov application worked properly and stored some data.
- 6/nov application worked properly and stored some data.
- 7/nov application worked properly and stored some data.
- 8/nov application worked properly and stored some data.
- 9/nov application worked properly and stored some data.
- 11/nov at power on the user noticed some hdd problem after some power restart the S.O. was loaded and the application started.
Database was accessible, but there were data only before the 6/nov.
In the 9/nov backup I found everything but I really did not understand how I can lose so much data. Mind that I did not find any other corruption in the file system.
I got same problem in another installation with a frequent power off.
My question is, in this case what was fault in innodb? I think that can not be log files because it could not rollback few days of data store in many committed transaction. Maybe there was a fault in the tablespace.
In this case how to find this problem? Is there a way to query innodb to notice that? Is there any other way to increare innodb safety like double writes?
Now I'm working with default "server" configuration made by installer with innodb_flush_log_at_trx_commit=1 and innodb_doublewrite=ON
I already posted a similiar topic but now I have some new data to analyze the problem because I'm logging the innodb engine status for every startup and shutdown:
LOG OF SHUTDOWN ON LAST GOOD DAY:
=====================================
2014-11-09 17:00:33 1244 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 47 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 13 srv_active, 0 srv_shutdown, 192 srv_idle
srv_master_thread log flush and writes: 205
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 5
OS WAIT ARRAY INFO: signal count 5
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 5, rounds 150, OS waits 5
RW-excl spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 mutex, 30.00 RW-shared, 0.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 747099
Purge done for trx's n:o < 747017 undo n:o < 0 state: running but idle
History list length 247
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 747098, not started
MySQL thread id 111, OS thread handle 0x1244, query id 1128 localhost 127.0.0.1 user_java init
show engine innodb status
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (write thread)
I/O thread 7 state: wait Windows aio (write thread)
I/O thread 8 state: wait Windows aio (write thread)
I/O thread 9 state: wait Windows aio (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
561 OS file reads, 221 OS file writes, 19 OS fsyncs
0.02 reads/s, 16384 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 170267, node heap has 1 buffer(s)
1.91 hash searches/s, 2.47 non-hash searches/s
---
LOG
---
Log sequence number 12560426
Log flushed up to 12560426
Pages flushed up to 12560426
Last checkpoint at 12560426
0 pending log writes, 0 pending chkp writes
13 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 43565056; in additional pool allocated 0
Dictionary memory allocated 152626
Buffer pool size 2624
Free buffers 2097
Database pages 526
Old database pages 214
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 526, created 0, written 206
0.02 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 526, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread id 2844, state: sleeping
Number of rows inserted 0, updated 1, deleted 0, read 15974
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 161.04 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
FIRST STARTUP AFTER DATA LOSS
=====================================
2014-11-11 20:30:49 1c4 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 26 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 1 srv_active, 0 srv_shutdown, 146 srv_idle
srv_master_thread log flush and writes: 147
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 3
OS WAIT ARRAY INFO: signal count 3
Mutex spin waits 1, rounds 30, OS waits 1
RW-shared spins 2, rounds 60, OS waits 2
RW-excl spins 0, rounds 0, OS waits 0
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 0.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 757772
Purge done for trx's n:o < 757769 undo n:o < 0 state: running but idle
History list length 249
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 757771, not started
MySQL thread id 1, OS thread handle 0x1c4, query id 17 localhost 127.0.0.1 user_java init
show engine innodb status
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (write thread)
I/O thread 7 state: wait Windows aio (write thread)
I/O thread 8 state: wait Windows aio (write thread)
I/O thread 9 state: wait Windows aio (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
425 OS file reads, 6 OS file writes, 6 OS fsyncs
0.62 reads/s, 16384 avg bytes/read, 0.04 writes/s, 0.04 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 170267, node heap has 0 buffer(s)
0.00 hash searches/s, 1.77 non-hash searches/s
---
LOG
---
Log sequence number 12561052
Log flushed up to 12561052
Pages flushed up to 12560837
Last checkpoint at 12560837
0 pending log writes, 0 pending chkp writes
9 log i/o's done, 0.04 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 43565056; in additional pool allocated 0
Dictionary memory allocated 38281
Buffer pool size 2624
Free buffers 2214
Database pages 410
Old database pages 0
Modified db pages 3
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 410, created 0, written 1
0.46 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 897 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 410, unzip_LRU len: 0
I/O sum[0]:cur[12], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread id 3592, state: sleeping
Number of rows inserted 0, updated 1, deleted 0, read 19
0.00 inserts/s, 0.04 updates/s, 0.00 deletes/s, 0.73 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
These are the facts
- 5/nov application worked properly and stored some data.
- 6/nov application worked properly and stored some data.
- 7/nov application worked properly and stored some data.
- 8/nov application worked properly and stored some data.
- 9/nov application worked properly and stored some data.
- 11/nov at power on the user noticed some hdd problem after some power restart the S.O. was loaded and the application started.
Database was accessible, but there were data only before the 6/nov.
In the 9/nov backup I found everything but I really did not understand how I can lose so much data. Mind that I did not find any other corruption in the file system.
I got same problem in another installation with a frequent power off.
My question is, in this case what was fault in innodb? I think that can not be log files because it could not rollback few days of data store in many committed transaction. Maybe there was a fault in the tablespace.
In this case how to find this problem? Is there a way to query innodb to notice that? Is there any other way to increare innodb safety like double writes?
Now I'm working with default "server" configuration made by installer with innodb_flush_log_at_trx_commit=1 and innodb_doublewrite=ON
I already posted a similiar topic but now I have some new data to analyze the problem because I'm logging the innodb engine status for every startup and shutdown:
LOG OF SHUTDOWN ON LAST GOOD DAY:
=====================================
2014-11-09 17:00:33 1244 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 47 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 13 srv_active, 0 srv_shutdown, 192 srv_idle
srv_master_thread log flush and writes: 205
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 5
OS WAIT ARRAY INFO: signal count 5
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 5, rounds 150, OS waits 5
RW-excl spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 mutex, 30.00 RW-shared, 0.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 747099
Purge done for trx's n:o < 747017 undo n:o < 0 state: running but idle
History list length 247
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 747098, not started
MySQL thread id 111, OS thread handle 0x1244, query id 1128 localhost 127.0.0.1 user_java init
show engine innodb status
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (write thread)
I/O thread 7 state: wait Windows aio (write thread)
I/O thread 8 state: wait Windows aio (write thread)
I/O thread 9 state: wait Windows aio (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
561 OS file reads, 221 OS file writes, 19 OS fsyncs
0.02 reads/s, 16384 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 170267, node heap has 1 buffer(s)
1.91 hash searches/s, 2.47 non-hash searches/s
---
LOG
---
Log sequence number 12560426
Log flushed up to 12560426
Pages flushed up to 12560426
Last checkpoint at 12560426
0 pending log writes, 0 pending chkp writes
13 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 43565056; in additional pool allocated 0
Dictionary memory allocated 152626
Buffer pool size 2624
Free buffers 2097
Database pages 526
Old database pages 214
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 526, created 0, written 206
0.02 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 526, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread id 2844, state: sleeping
Number of rows inserted 0, updated 1, deleted 0, read 15974
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 161.04 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
FIRST STARTUP AFTER DATA LOSS
=====================================
2014-11-11 20:30:49 1c4 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 26 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 1 srv_active, 0 srv_shutdown, 146 srv_idle
srv_master_thread log flush and writes: 147
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 3
OS WAIT ARRAY INFO: signal count 3
Mutex spin waits 1, rounds 30, OS waits 1
RW-shared spins 2, rounds 60, OS waits 2
RW-excl spins 0, rounds 0, OS waits 0
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 0.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 757772
Purge done for trx's n:o < 757769 undo n:o < 0 state: running but idle
History list length 249
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 757771, not started
MySQL thread id 1, OS thread handle 0x1c4, query id 17 localhost 127.0.0.1 user_java init
show engine innodb status
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (write thread)
I/O thread 7 state: wait Windows aio (write thread)
I/O thread 8 state: wait Windows aio (write thread)
I/O thread 9 state: wait Windows aio (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
425 OS file reads, 6 OS file writes, 6 OS fsyncs
0.62 reads/s, 16384 avg bytes/read, 0.04 writes/s, 0.04 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 170267, node heap has 0 buffer(s)
0.00 hash searches/s, 1.77 non-hash searches/s
---
LOG
---
Log sequence number 12561052
Log flushed up to 12561052
Pages flushed up to 12560837
Last checkpoint at 12560837
0 pending log writes, 0 pending chkp writes
9 log i/o's done, 0.04 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 43565056; in additional pool allocated 0
Dictionary memory allocated 38281
Buffer pool size 2624
Free buffers 2214
Database pages 410
Old database pages 0
Modified db pages 3
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 410, created 0, written 1
0.46 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 897 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 410, unzip_LRU len: 0
I/O sum[0]:cur[12], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread id 3592, state: sleeping
Number of rows inserted 0, updated 1, deleted 0, read 19
0.00 inserts/s, 0.04 updates/s, 0.00 deletes/s, 0.73 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
Subject
Views
Written By
Posted
Sorry, you can't reply to this topic. It has been closed.
Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.