maria-developers team mailing list archive
-
maria-developers team
-
Mailing list archive
-
Message #07253
tokudb database - generated "should never happen" status when mysql log partition ENOSP
While doing a database load from a mysqldump stuck on an insert in tokudb, and yes it was because the log partition was out of space.
Things that stuck out for me that may indicate a small bug are from the status below.
| TokuDB | context: promotion blocked by a partial eviction (should never happen) | 4 |
| TokuDB | memory: number of realloc operations that failed | 8026 |
It did clear up well and the row was inserted after I purged the log partition space so well done Tokudb devs on your fault tolerance coding.
I'm unsure if "should never happen" is a) run out of log space or b) a bit of code that shouldn't be reached but at least now you may have a test mechanism for once instance of it.
Anyway, I have a client happily testing away now. Thanks folks.
mysql Ver 15.1 Distrib 10.0.10-MariaDB, for Linux (x86_64) using readline 5.1
from mysql log:
140514 17:03:34 [Warning] mysqld: Disk is full writing '/var/mysql_log/mysql-bin.000319' (Errcode: 28 "No space left on device"). Waiting for someone to free space... (E
xpect up to 60 secs delay for server to continue after freeing disk space)
140514 17:03:34 [Warning] mysqld: Retry in 60 secs. Message reprinted in 600 secs
140514 17:13:34 [Warning] mysqld: Retry in 60 secs. Message reprinted in 600 secs
140514 17:23:34 [Warning] mysqld: Retry in 60 secs. Message reprinted in 600 secs
+----+-------------+-----------+-------------+---------+-------+----------------------------------+----------------------------------------------------------------------
-------------------------------+----------+
| Id | User | Host | db | Command | Time | State | Info
| Progress |
+----+-------------+-----------+-------------+---------+-------+----------------------------------+----------------------------------------------------------------------
-------------------------------+----------+
| 3 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 4 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 5 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 6 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 7 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 8 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 9 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 10 | system user | | NULL | Connect | 80612 | Waiting for work from SQL thread | NULL
| 0.000 |
| 19 | openquery | localhost | database | Query | 54442 | query end | INSERT INTO `event_log` VALUES (97705498,'InsertEmail','emails',55446
77,'insert',1,1,'Inserted emai | 0.000 |
| 24 | root | localhost | NULL | Query | 0 | init | show processlist
| 0.000 |
A strace on mysql shows it blocking waiting a database response:
Process 17215 attached - interrupt to quit
recvfrom(3, ^C <unfinished ...>
mysql 17215 root 3u unix 0xffff880238c3ccc0 0t0 91711 socket
$ free -m
total used free shared buffers cached
Mem: 7872 7588 283 0 84 2639
-/+ buffers/cache: 4864 3007
Swap: 4095 32 4063
| Type | Name | Status |
+--------+---------------------------------------------------------------------------------+---------------------------------------------------+
| TokuDB | disk free space | more than 10 percent of total file system space |
| TokuDB | time of environment creation | Thu May 8 14:20:17 2014 |
| TokuDB | time of engine startup | Wed May 14 09:47:21 2014 |
| TokuDB | time now | Thu May 15 08:09:06 2014 |
| TokuDB | db opens | 2120 |
| TokuDB | db closes | 2115 |
| TokuDB | num open dbs now | 5 |
| TokuDB | max open dbs | 8 |
| TokuDB | period, in ms, that recovery log is automatically fsynced | 0 |
| TokuDB | dictionary inserts | 1106176 |
| TokuDB | dictionary inserts fail | 0 |
| TokuDB | dictionary deletes | 0 |
| TokuDB | dictionary deletes fail | 0 |
| TokuDB | dictionary updates | 0 |
| TokuDB | dictionary updates fail | 0 |
| TokuDB | dictionary broadcast updates | 0 |
| TokuDB | dictionary broadcast updates fail | 0 |
| TokuDB | dictionary multi inserts - | 435962932 |
| TokuDB | dictionary multi inserts fail | 0 |
| TokuDB | dictionary multi deletes | 0 |
| TokuDB | dictionary multi deletes fail | 0 |
| TokuDB | dictionary updates multi | 0 |
| TokuDB | dictionary updates multi fail | 0 |
| TokuDB | le: max committed xr | 1 |
| TokuDB | le: max provisional xr | 2 |
| TokuDB | le: expanded | 0 |
| TokuDB | le: max memsize | 221572 |
| TokuDB | le: size of leafentries before garbage collection (during message application) | 41114858339 |
| TokuDB | le: size of leafentries after garbage collection (during message application) | 27522765394 |
| TokuDB | le: size of leafentries before garbage collection (outside message application) | 0 |
| TokuDB | le: size of leafentries after garbage collection (outside message application) | 0 |
| TokuDB | checkpoint: period | 60 |
| TokuDB | checkpoint: footprint | 0 |
| TokuDB | checkpoint: last checkpoint began | Thu May 15 08:08:22 2014 |
| TokuDB | checkpoint: last complete checkpoint began | Thu May 15 08:08:22 2014 |
| TokuDB | checkpoint: last complete checkpoint ended | Thu May 15 08:08:22 2014 |
| TokuDB | checkpoint: last complete checkpoint LSN | 1070082148 |
| TokuDB | checkpoint: checkpoints taken | 1342 |
| TokuDB | checkpoint: checkpoints failed | 0 |
| TokuDB | checkpoint: waiters now | 0 |
| TokuDB | checkpoint: waiters max | 0 |
| TokuDB | checkpoint: non-checkpoint client wait on mo lock | 90 |
| TokuDB | checkpoint: non-checkpoint client wait on cs lock | 0 |
| TokuDB | checkpoint: checkpoint begin time | 1917971 |
| TokuDB | checkpoint: long checkpoint begin time | 0 |
| TokuDB | checkpoint: long checkpoint begin count | 0 |
| TokuDB | cachetable: miss | 1322 |
| TokuDB | cachetable: miss time | 4962726 |
| TokuDB | cachetable: prefetches | 0 |
| TokuDB | cachetable: size current | 4120684939 |
| TokuDB | cachetable: size limit | 4540038553 |
| TokuDB | cachetable: size writing | 0 |
| TokuDB | cachetable: size nonleaf | 1813805 |
| TokuDB | cachetable: size leaf | 4117928808 |
| TokuDB | cachetable: size rollback | 942326 |
| TokuDB | cachetable: size cachepressure | 0 |
| TokuDB | cachetable: evictions | 8353 |
| TokuDB | cachetable: cleaner executions | 84011 |
| TokuDB | cachetable: cleaner period | 1 |
| TokuDB | cachetable: cleaner iterations | 5 |
| TokuDB | cachetable: number of waits on cache pressure | 0 |
| TokuDB | cachetable: time waiting on cache pressure | 0 |
| TokuDB | cachetable: number of long waits on cache pressure | 0 |
| TokuDB | cachetable: long time waiting on cache pressure | 0 |
| TokuDB | locktree: memory size | 998714 |
| TokuDB | locktree: memory size limit | 515913472 |
| TokuDB | locktree: number of times lock escalation ran | 0 |
| TokuDB | locktree: time spent running escalation (seconds) | 0.000000 |
| TokuDB | locktree: latest post-escalation memory size | 0 |
| TokuDB | locktree: number of locktrees open now | 7 |
| TokuDB | locktree: number of pending lock requests | 0 |
| TokuDB | locktree: number of locktrees eligible for the STO | 4 |
| TokuDB | locktree: number of times a locktree ended the STO early | 1 |
| TokuDB | locktree: time spent ending the STO early (seconds) | 0.000023 |
| TokuDB | locktree: number of wait locks | 0 |
| TokuDB | locktree: time waiting for locks | 0 |
| TokuDB | locktree: number of long wait locks | 0 |
| TokuDB | locktree: long time waiting for locks | 0 |
| TokuDB | locktree: number of lock timeouts | 0 |
| TokuDB | locktree: number of waits on lock escalation | 0 |
| TokuDB | locktree: time waiting on lock escalation | 0 |
| TokuDB | locktree: number of long waits on lock escalation | 0 |
| TokuDB | locktree: long time waiting on lock escalation | 0 |
| TokuDB | brt: dictionary updates | 0 |
| TokuDB | brt: dictionary broadcast updates | 0 |
| TokuDB | brt: descriptor set | 762 |
| TokuDB | brt: messages ignored by leaf due to msn | 57 |
| TokuDB | brt: total search retries due to TRY_AGAIN | 0 |
| TokuDB | brt: searches requiring more tries than the height of the tree | 0 |
| TokuDB | brt: searches requiring more tries than the height of the tree plus three | 0 |
| TokuDB | brt: leaf nodes flushed to disk (not for checkpoint) | 1967 |
| TokuDB | brt: leaf nodes flushed to disk (not for checkpoint) (bytes) | 227559424 |
| TokuDB | brt: leaf nodes flushed to disk (not for checkpoint) (uncompressed bytes) | 1063643246 |
| TokuDB | brt: leaf nodes flushed to disk (not for checkpoint) (seconds) | 0.226403 |
| TokuDB | brt: nonleaf nodes flushed to disk (not for checkpoint) | 415 |
| TokuDB | brt: nonleaf nodes flushed to disk (not for checkpoint) (bytes) | 71771648 |
| TokuDB | brt: nonleaf nodes flushed to disk (not for checkpoint) (uncompressed bytes) | 395425640 |
| TokuDB | brt: nonleaf nodes flushed to disk (not for checkpoint) (seconds) | 0.059398 |
| TokuDB | brt: leaf nodes flushed to disk (for checkpoint) | 25362 |
| TokuDB | brt: leaf nodes flushed to disk (for checkpoint) (bytes) | 11588382720 |
| TokuDB | brt: leaf nodes flushed to disk (for checkpoint) (uncompressed bytes) | 79354297571 |
| TokuDB | brt: leaf nodes flushed to disk (for checkpoint) (seconds) | 19.527512 |
| TokuDB | brt: nonleaf nodes flushed to disk (for checkpoint) | 13204 |
| TokuDB | brt: nonleaf nodes flushed to disk (for checkpoint) (bytes) | 6687771648 |
| TokuDB | brt: nonleaf nodes flushed to disk (for checkpoint) (uncompressed bytes) | 37172345456 |
| TokuDB | brt: nonleaf nodes flushed to disk (for checkpoint) (seconds) | 9.359899 |
| TokuDB | brt: uncompressed / compressed bytes written (leaf) | UNKNOWN STATUS TYPE: 6 |
| TokuDB | brt: uncompressed / compressed bytes written (nonleaf) | UNKNOWN STATUS TYPE: 6 |
| TokuDB | brt: uncompressed / compressed bytes written (overall) | UNKNOWN STATUS TYPE: 6 |
| TokuDB | brt: nonleaf node partial evictions | 2426 |
| TokuDB | brt: nonleaf node partial evictions (bytes) | 1054888296 |
| TokuDB | brt: leaf node partial evictions | 939879 |
| TokuDB | brt: leaf node partial evictions (bytes) | 85283668848 |
| TokuDB | brt: leaf node full evictions | 7520 |
| TokuDB | brt: leaf node full evictions (bytes) | 8930465418 |
| TokuDB | brt: nonleaf node full evictions | 833 |
| TokuDB | brt: nonleaf node full evictions (bytes) | 1299130100 |
| TokuDB | brt: leaf nodes created | 13124 |
| TokuDB | brt: nonleaf nodes created | 1702 |
| TokuDB | brt: leaf nodes destroyed | 33549 |
| TokuDB | brt: nonleaf nodes destroyed | 14037 |
| TokuDB | brt: bytes of messages injected at root (all trees) | 17383788945 |
| TokuDB | brt: bytes of messages flushed from h1 nodes to leaves | 16664820099 |
| TokuDB | brt: bytes of messages currently in trees (estimate) | 718968846 |
| TokuDB | brt: messages injected at root | 315361635 |
| TokuDB | brt: broadcast messages injected at root | 0 |
| TokuDB | brt: basements decompressed as a target of a query | 117 |
| TokuDB | brt: basements decompressed for prelocked range | 0 |
| TokuDB | brt: basements decompressed for prefetch | 0 |
| TokuDB | brt: basements decompressed for write | 0 |
| TokuDB | brt: buffers decompressed as a target of a query | 0 |
| TokuDB | brt: buffers decompressed for prelocked range | 0 |
| TokuDB | brt: buffers decompressed for prefetch | 0 |
| TokuDB | brt: buffers decompressed for write | 2335 |
| TokuDB | brt: pivots fetched for query | 0 |
| TokuDB | brt: pivots fetched for query (bytes) | 0 |
| TokuDB | brt: pivots fetched for query (seconds) | 0.000000 |
| TokuDB | brt: pivots fetched for prefetch | 0 |
| TokuDB | brt: pivots fetched for prefetch (bytes) | 0 |
| TokuDB | brt: pivots fetched for prefetch (seconds) | 0.000000 |
| TokuDB | brt: pivots fetched for write | 83 |
| TokuDB | brt: pivots fetched for write (bytes) | 1603584 |
| TokuDB | brt: pivots fetched for write (seconds) | 0.002097 |
| TokuDB | brt: basements fetched as a target of a query | 1 |
| TokuDB | brt: basements fetched as a target of a query (bytes) | 18944 |
| TokuDB | brt: basements fetched as a target of a query (seconds) | 0.005276 |
| TokuDB | brt: basements fetched for prelocked range | 0 |
| TokuDB | brt: basements fetched for prelocked range (bytes) | 0 |
| TokuDB | brt: basements fetched for prelocked range (seconds) | 0.000000 |
| TokuDB | brt: basements fetched for prefetch | 0 |
| TokuDB | brt: basements fetched for prefetch (bytes) | 0 |
| TokuDB | brt: basements fetched for prefetch (seconds) | 0.000000 |
| TokuDB | brt: basements fetched for write | 404989 |
| TokuDB | brt: basements fetched for write (bytes) | 4425263104 |
| TokuDB | brt: basements fetched for write (seconds) | 53.357637 |
| TokuDB | brt: buffers fetched as a target of a query | 0 |
| TokuDB | brt: buffers fetched as a target of a query (bytes) | 0 |
| TokuDB | brt: buffers fetched as a target of a query (seconds) | 0.000000 |
| TokuDB | brt: buffers fetched for prelocked range | 0 |
| TokuDB | brt: buffers fetched for prelocked range (bytes) | 0 |
| TokuDB | brt: buffers fetched for prelocked range (seconds) | 0.000000 |
| TokuDB | brt: buffers fetched for prefetch | 0 |
| TokuDB | brt: buffers fetched for prefetch (bytes) | 0 |
| TokuDB | brt: buffers fetched for prefetch (seconds) | 0.000000 |
| TokuDB | brt: buffers fetched for write | 11 |
| TokuDB | brt: buffers fetched for write (bytes) | 638976 |
| TokuDB | brt: buffers fetched for write (seconds) | 0.000278 |
| TokuDB | brt: leaf compression to memory (seconds) | 1477.724851 |
| TokuDB | brt: leaf serialization to memory (seconds) | 87.135551 |
| TokuDB | brt: leaf decompression to memory (seconds) | 90.436941 |
| TokuDB | brt: leaf deserialization to memory (seconds) | 41.760601 |
| TokuDB | brt: nonleaf compression to memory (seconds) | 1029.340933 |
| TokuDB | brt: nonleaf serialization to memory (seconds) | 81.296623 |
| TokuDB | brt: nonleaf decompression to memory (seconds) | 0.892839 |
| TokuDB | brt: nonleaf deserialization to memory (seconds) | 27.050535 |
| TokuDB | brt: promotion: roots split | 325 |
| TokuDB | brt: promotion: leaf roots injected into | 2814368 |
| TokuDB | brt: promotion: h1 roots injected into | 10001676 |
| TokuDB | brt: promotion: injections at depth 0 | 600030 |
| TokuDB | brt: promotion: injections at depth 1 | 109518474 |
| TokuDB | brt: promotion: injections at depth 2 | 210903125 |
| TokuDB | brt: promotion: injections at depth 3 | 41645566 |
| TokuDB | brt: promotion: injections lower than depth 3 | 61585869 |
| TokuDB | brt: promotion: stopped because of a nonempty buffer | 80468647 |
| TokuDB | brt: promotion: stopped at height 1 | 3640 |
| TokuDB | brt: promotion: stopped because the child was locked or not at all in memory | 1046 |
| TokuDB | brt: promotion: stopped because the child was not fully in memory | 0 |
| TokuDB | brt: promotion: stopped anyway, after locking the child | 829 |
| TokuDB | brt flusher: total nodes potentially flushed by cleaner thread | 3842 |
| TokuDB | brt flusher: height-one nodes flushed by cleaner thread | 3729 |
| TokuDB | brt flusher: height-greater-than-one nodes flushed by cleaner thread | 113 |
| TokuDB | brt flusher: nodes cleaned which had empty buffers | 47 |
| TokuDB | brt flusher: nodes dirtied by cleaner thread | 4921 |
| TokuDB | brt flusher: max bytes in a buffer flushed by cleaner thread | 4192627 |
| TokuDB | brt flusher: min bytes in a buffer flushed by cleaner thread | 47 |
| TokuDB | brt flusher: total bytes in buffers flushed by cleaner thread | 2729286154 |
| TokuDB | brt flusher: max workdone in a buffer flushed by cleaner thread | 299 |
| TokuDB | brt flusher: min workdone in a buffer flushed by cleaner thread | 0 |
| TokuDB | brt flusher: total workdone in buffers flushed by cleaner thread | 2893 |
| TokuDB | brt flusher: times cleaner thread tries to merge a leaf | 0 |
| TokuDB | brt flusher: cleaner thread leaf merges in progress | 0 |
| TokuDB | brt flusher: cleaner thread leaf merges successful | 0 |
| TokuDB | brt flusher: nodes dirtied by cleaner thread leaf merges | 0 |
| TokuDB | brt flusher: total number of flushes done by flusher threads or cleaner threads | 16402 |
| TokuDB | brt flusher: number of in memory flushes | 16402 |
| TokuDB | brt flusher: number of flushes that read something off disk | 0 |
| TokuDB | brt flusher: number of flushes that triggered another flush in child | 46 |
| TokuDB | brt flusher: number of flushes that triggered 1 cascading flush | 46 |
| TokuDB | brt flusher: number of flushes that triggered 2 cascading flushes | 0 |
| TokuDB | brt flusher: number of flushes that triggered 3 cascading flushes | 0 |
| TokuDB | brt flusher: number of flushes that triggered 4 cascading flushes | 0 |
| TokuDB | brt flusher: number of flushes that triggered 5 cascading flushes | 0 |
| TokuDB | brt flusher: number of flushes that triggered over 5 cascading flushes | 0 |
| TokuDB | brt flusher: leaf node splits | 11403 |
| TokuDB | brt flusher: nonleaf node splits | 1377 |
| TokuDB | brt flusher: leaf node merges | 0 |
| TokuDB | brt flusher: nonleaf node merges | 0 |
| TokuDB | brt flusher: leaf node balances | 0 |
| TokuDB | hot: operations ever started | 0 |
| TokuDB | hot: operations successfully completed | 0 |
| TokuDB | hot: operations aborted | 0 |
| TokuDB | hot: max number of flushes from root ever required to optimize a tree | 0 |
| TokuDB | txn: begin | 37595 |
| TokuDB | txn: begin read only | 0 |
| TokuDB | txn: successful commits | 36850 |
| TokuDB | txn: aborts | 744 |
| TokuDB | logger: next LSN | 1070082158 |
| TokuDB | logger: writes | 68032 |
| TokuDB | logger: writes (bytes) | 34317134044 |
| TokuDB | logger: writes (uncompressed bytes) | 34317134044 |
| TokuDB | logger: writes (seconds) | 31.415003 |
| TokuDB | logger: count | 2 |
| TokuDB | indexer: number of indexers successfully created | 0 |
| TokuDB | indexer: number of calls to toku_indexer_create_indexer() that failed | 0 |
| TokuDB | indexer: number of calls to indexer->build() succeeded | 0 |
| TokuDB | indexer: number of calls to indexer->build() failed | 0 |
| TokuDB | indexer: number of calls to indexer->close() that succeeded | 0 |
| TokuDB | indexer: number of calls to indexer->close() that failed | 0 |
| TokuDB | indexer: number of calls to indexer->abort() | 0 |
| TokuDB | indexer: number of indexers currently in existence | 0 |
| TokuDB | indexer: max number of indexers that ever existed simultaneously | 0 |
| TokuDB | loader: number of loaders successfully created | 253 |
| TokuDB | loader: number of calls to toku_loader_create_loader() that failed | 0 |
| TokuDB | loader: number of calls to loader->put() succeeded | 169016 |
| TokuDB | loader: number of calls to loader->put() failed | 0 |
| TokuDB | loader: number of calls to loader->close() that succeeded | 253 |
| TokuDB | loader: number of calls to loader->close() that failed | 0 |
| TokuDB | loader: number of calls to loader->abort() | 0 |
| TokuDB | loader: number of loaders currently in existence | 0 |
| TokuDB | loader: max number of loaders that ever existed simultaneously | 1 |
| TokuDB | memory: number of malloc operations | 0 |
| TokuDB | memory: number of free operations | 0 |
| TokuDB | memory: number of realloc operations | 0 |
| TokuDB | memory: number of malloc operations that failed | 0 |
| TokuDB | memory: number of realloc operations that failed | 8026 |
| TokuDB | memory: number of bytes requested | 0 |
| TokuDB | memory: number of bytes used (requested + overhead) | 0 |
| TokuDB | memory: number of bytes freed | 0 |
| TokuDB | memory: estimated maximum memory footprint | 0 |
| TokuDB | memory: mallocator version | 3.3.1-0-g9ef9d9e8c271cdf14f664b871a8f98c827714784 |
| TokuDB | memory: mmap threshold | 4194304 |
| TokuDB | filesystem: ENOSPC redzone state | 0 |
| TokuDB | filesystem: threads currently blocked by full disk | 0 |
| TokuDB | filesystem: number of operations rejected by enospc prevention (red zone) | 0 |
| TokuDB | filesystem: most recent disk full | Thu Jan 1 10:00:00 1970 |
| TokuDB | filesystem: number of write operations that returned ENOSPC | 0 |
| TokuDB | filesystem: fsync time | 2719206294 |
| TokuDB | filesystem: fsync count | 77695 |
| TokuDB | filesystem: long fsync time | 855218368 |
| TokuDB | filesystem: long fsync count | 424 |
| TokuDB | context: tree traversals blocked by a full fetch | 0 |
| TokuDB | context: tree traversals blocked by a partial fetch | 0 |
| TokuDB | context: tree traversals blocked by a full eviction | 0 |
| TokuDB | context: tree traversals blocked by a partial eviction | 0 |
| TokuDB | context: tree traversals blocked by a message injection | 0 |
| TokuDB | context: tree traversals blocked by a message application | 0 |
| TokuDB | context: tree traversals blocked by a flush | 0 |
| TokuDB | context: tree traversals blocked by a the cleaner thread | 0 |
| TokuDB | context: tree traversals blocked by something uninstrumented | 0 |
| TokuDB | context: promotion blocked by a full fetch (should never happen) | 0 |
| TokuDB | context: promotion blocked by a partial fetch (should never happen) | 0 |
| TokuDB | context: promotion blocked by a full eviction (should never happen) | 0 |
| TokuDB | context: promotion blocked by a partial eviction (should never happen) | 4 |
| TokuDB | context: promotion blocked by a message injection | 1067 |
| TokuDB | context: promotion blocked by a message application | 0 |
| TokuDB | context: promotion blocked by a flush | 0 |
| TokuDB | context: promotion blocked by the cleaner thread | 121 |
| TokuDB | context: promotion blocked by something uninstrumented | 0 |
| TokuDB | context: something uninstrumented blocked by something uninstrumented | 0 |
| TokuDB | handlerton: primary key bytes inserted | 26774483883 |
--
--
Daniel Black, Engineer @ Open Query (http://openquery.com.au)
Remote expertise & maintenance for MySQL/MariaDB server environments.