Hartmut Holzgraefe added a comment - 2018-07-18 10:55 Upstream report: https://jira.percona.com/browse/PS-4610

Hartmut Holzgraefe added a comment - 2018-07-18 10:54 I added a warning to the parameter documentation for now, needs to be removed when this gets fixed: https://mariadb.com/kb/en/library/tokudb-system-variables/#tokudb_fsync_log_period

Elena Stepanova added a comment - 2018-07-11 17:19 - edited It doesn't seem to be related to a particular value, just some race condition. The test case below causes it reliably for me on all of 10.x and Percona Server 5.7.13. Values where it crashes are always different. Run with --mysqld=--plugin-load=ha_tokudb.so --let $period= 1000   while ($period < 2000) { eval SET GLOBAL tokudb_fsync_log_period = $period; --echo # $period worked --sleep 0.1 --inc $period } 10.0 a2c0376e0 /data/src/10.0/storage/tokudb/PerconaFT/util/minicron.cc:104 r=22 (Invalid argument)mysqld: /data/src/10.0/storage/tokudb/PerconaFT/util/minicron.cc:105: void* minicron_do(void*): Assertion `r==0 || r==110' failed. 180711 20:22:32 [ERROR] mysqld got signal 6 ;   #6 0x00007f9429fac266 in __assert_fail_base (fmt=0x7f942a0e4f18 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f9422996231 "r==0 || r==110", file=file@entry=0x7f94229961e8 "/data/src/10.0/storage/tokudb/PerconaFT/util/minicron.cc", line=line@entry=105, function=function@entry=0x7f94229962d0 <minicron_do(void*)::__PRETTY_FUNCTION__> "void* minicron_do(void*)") at assert.c:92 #7 0x00007f9429fac312 in __GI___assert_fail (assertion=0x7f9422996231 "r==0 || r==110", file=0x7f94229961e8 "/data/src/10.0/storage/tokudb/PerconaFT/util/minicron.cc", line=105, function=0x7f94229962d0 <minicron_do(void*)::__PRETTY_FUNCTION__> "void* minicron_do(void*)") at assert.c:101 #8 0x00007f9422929393 in minicron_do (pv=0x7f94294161c8) at /data/src/10.0/storage/tokudb/PerconaFT/util/minicron.cc:105 #9 0x0000000000a0295e in pfs_spawn_thread (arg=0x7f942942adf0) at /data/src/10.0/storage/perfschema/pfs.cc:1861 #10 0x00007f942bc40064 in start_thread (arg=0x7f940c3e1700) at pthread_create.c:309 #11 0x00007f942a06662d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 10.3 934d5f95d /data/src/10.3/storage/tokudb/PerconaFT/util/minicron.cc:104 r=22 (Invalid argument)/data/src/10.3/storage/tokudb/PerconaFT/util/minicron.cc:105 minicron_do: Assertion `r==0 || r==ETIMEDOUT' failed (errno=0) : Success Backtrace: (Note: toku_do_assert=0x0x7f0024616f07) /data/bld/10.3/lib/plugin/ha_tokudb.so(_Z19db_env_do_backtraceP8_IO_FILE+0x26)[0x7f0024616a97] /data/bld/10.3/lib/plugin/ha_tokudb.so(+0x1c8c74)[0x7f0024616c74] /data/bld/10.3/lib/plugin/ha_tokudb.so(_Z24toku_do_assert_zero_failmPKcS0_S0_ii+0x0)[0x7f0024616d73] /data/bld/10.3/lib/plugin/ha_tokudb.so(+0x19b259)[0x7f00245e9259] /data/bld/10.3/bin/mysqld(+0xbcfd73)[0x7f002beaad73] /lib/x86_64-linux-gnu/libpthread.so.0(+0x8064)[0x7f002aea3064] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f00292f662d] Engine status: BUILD_ID = 0 Env panic code: 18446744073709551615 Env panic string: /data/src/10.3/storage/tokudb/PerconaFT/util/minicron.cc:105 minicron_do: Assertion `r==0 || r==ETIMEDOUT' failed (errno=0)   time of environment creation: Wed Jul 11 20:25:14 2018 time of engine startup: Wed Jul 11 20:25:14 2018 time now: Wed Jul 11 20:25:24 2018 db opens: 0 db closes: 0 num open dbs now: 0 max open dbs: 0 period, in ms, that recovery log is automatically fsynced: 1093 dictionary inserts: 3 dictionary inserts fail: 0 dictionary deletes: 0 dictionary deletes fail: 0 dictionary updates: 0 dictionary updates fail: 0 dictionary broadcast updates: 0 dictionary broadcast updates fail: 0 dictionary multi inserts: 0 dictionary multi inserts fail: 0 dictionary multi deletes: 0 dictionary multi deletes fail: 0 dictionary updates multi: 0 dictionary updates multi fail: 0 le: max committed xr: 1 le: max provisional xr: 1 le: expanded: 0 le: max memsize: 30 le: size of leafentries before garbage collection (during message application): 0 le: size of leafentries after garbage collection (during message application): 0 le: size of leafentries before garbage collection (outside message application): 0 le: size of leafentries after garbage collection (outside message application): 0 checkpoint: period: 60 checkpoint: footprint: 0 checkpoint: last checkpoint began: Wed Jul 11 20:25:14 2018 checkpoint: last complete checkpoint began: Wed Jul 11 20:25:14 2018 checkpoint: last complete checkpoint ended: Wed Jul 11 20:25:15 2018 checkpoint: time spent during checkpoint (begin and end phases): 1 checkpoint: time spent during last checkpoint (begin and end phases): 1 checkpoint: last complete checkpoint LSN: 8 checkpoint: checkpoints taken : 1 checkpoint: checkpoints failed: 0 checkpoint: waiters now: 0 checkpoint: waiters max: 0 checkpoint: non-checkpoint client wait on mo lock: 0 checkpoint: non-checkpoint client wait on cs lock: 0 checkpoint: checkpoint begin time: 53 checkpoint: long checkpoint begin time: 0 checkpoint: long checkpoint begin count: 0 checkpoint: checkpoint end time: 401375 checkpoint: long checkpoint end time: 0 checkpoint: long checkpoint end count: 0 cachetable: miss: 0 cachetable: miss time: 0 cachetable: prefetches: 0 cachetable: size current: 1509 cachetable: size limit: 8908830720 cachetable: size writing: 0 cachetable: size nonleaf: 0 cachetable: size leaf: 1301 cachetable: size rollback: 208 cachetable: size cachepressure: 0 cachetable: size currently cloned data for checkpoint: 0 cachetable: evictions: 0 cachetable: cleaner executions: 10 cachetable: cleaner period: 1 cachetable: cleaner iterations: 5 cachetable: number of waits on cache pressure: 0 cachetable: time waiting on cache pressure: 0 cachetable: number of long waits on cache pressure: 0 cachetable: long time waiting on cache pressure: 0 cachetable: client pool: number of threads in pool: 8 cachetable: client pool: number of currently active threads in pool: 0 cachetable: client pool: number of currently queued work items: 0 cachetable: client pool: largest number of queued work items: 0 cachetable: client pool: total number of work items processed: 0 cachetable: client pool: total execution time of processing work items: 0 cachetable: cachetable pool: number of threads in pool: 16 cachetable: cachetable pool: number of currently active threads in pool: 0 cachetable: cachetable pool: number of currently queued work items: 0 cachetable: cachetable pool: largest number of queued work items: 0 cachetable: cachetable pool: total number of work items processed: 0 cachetable: cachetable pool: total execution time of processing work items: 0 cachetable: checkpoint pool: number of threads in pool: 2 cachetable: checkpoint pool: number of currently active threads in pool: 0 cachetable: checkpoint pool: number of currently queued work items: 0 cachetable: checkpoint pool: largest number of queued work items: 0 cachetable: checkpoint pool: total number of work items processed: 0 cachetable: checkpoint pool: total execution time of processing work items: 0 locktree: memory size: 0 locktree: memory size limit: 1046494976 locktree: number of times lock escalation ran: 0 locktree: time spent running escalation (seconds): 0.000000 locktree: latest post-escalation memory size: 0 locktree: number of locktrees open now: 2 locktree: number of pending lock requests: 0 locktree: number of locktrees eligible for the STO: 0 locktree: number of times a locktree ended the STO early: 0 locktree: time spent ending the STO early (seconds): 0.000000 locktree: number of wait locks: 0 locktree: time waiting for locks: 0 locktree: number of long wait locks: 0 locktree: long time waiting for locks: 0 locktree: number of lock timeouts: 0 locktree: number of waits on lock escalation: 0 locktree: time waiting on lock escalation: 0 locktree: number of long waits on lock escalation: 0 locktree: long time waiting on lock escalation: 0 ft: dictionary updates: 0 ft: dictionary broadcast updates: 0 ft: descriptor set: 0 ft: messages ignored by leaf due to msn: 0 ft: total search retries due to TRY_AGAIN: 0 ft: searches requiring more tries than the height of the tree: 0 ft: searches requiring more tries than the height of the tree plus three: 0 ft: leaf nodes flushed to disk (not for checkpoint): 0 ft: leaf nodes flushed to disk (not for checkpoint) (bytes): 0 ft: leaf nodes flushed to disk (not for checkpoint) (uncompressed bytes): 0 ft: leaf nodes flushed to disk (not for checkpoint) (seconds): 0.000000 ft: nonleaf nodes flushed to disk (not for checkpoint): 0 ft: nonleaf nodes flushed to disk (not for checkpoint) (bytes): 0 ft: nonleaf nodes flushed to disk (not for checkpoint) (uncompressed bytes): 0 ft: nonleaf nodes flushed to disk (not for checkpoint) (seconds): 0.000000 ft: leaf nodes flushed to disk (for checkpoint): 3 ft: leaf nodes flushed to disk (for checkpoint) (bytes): 1536 ft: leaf nodes flushed to disk (for checkpoint) (uncompressed bytes): 435 ft: leaf nodes flushed to disk (for checkpoint) (seconds): 0.000008 ft: nonleaf nodes flushed to disk (for checkpoint): 0 ft: nonleaf nodes flushed to disk (for checkpoint) (bytes): 0 ft: nonleaf nodes flushed to disk (for checkpoint) (uncompressed bytes): 0 ft: nonleaf nodes flushed to disk (for checkpoint) (seconds): 0.000000 ft: uncompressed / compressed bytes written (leaf): UNKNOWN STATUS TYPE: 6 ft: uncompressed / compressed bytes written (nonleaf): UNKNOWN STATUS TYPE: 6 ft: uncompressed / compressed bytes written (overall): UNKNOWN STATUS TYPE: 6 ft: nonleaf node partial evictions: 0 ft: nonleaf node partial evictions (bytes): 0 ft: leaf node partial evictions: 0 ft: leaf node partial evictions (bytes): 0 ft: leaf node full evictions: 0 ft: leaf node full evictions (bytes): 0 ft: nonleaf node full evictions: 0 ft: nonleaf node full evictions (bytes): 0 ft: leaf nodes created: 3 ft: nonleaf nodes created: 0 ft: leaf nodes destroyed: 0 ft: nonleaf nodes destroyed: 0 ft: bytes of messages injected at root (all trees): 0 ft: bytes of messages flushed from h1 nodes to leaves: 0 ft: bytes of messages currently in trees (estimate): 0 ft: messages injected at root: 0 ft: broadcast messages injected at root: 0 ft: basements decompressed as a target of a query: 0 ft: basements decompressed for prelocked range: 0 ft: basements decompressed for prefetch: 0 ft: basements decompressed for write: 0 ft: buffers decompressed as a target of a query: 0 ft: buffers decompressed for prelocked range: 0 ft: buffers decompressed for prefetch: 0 ft: buffers decompressed for write: 0 ft: pivots fetched for query: 0 ft: pivots fetched for query (bytes): 0 ft: pivots fetched for query (seconds): 0.000000 ft: pivots fetched for prefetch: 0 ft: pivots fetched for prefetch (bytes): 0 ft: pivots fetched for prefetch (seconds): 0.000000 ft: pivots fetched for write: 0 ft: pivots fetched for write (bytes): 0 ft: pivots fetched for write (seconds): 0.000000 ft: basements fetched as a target of a query: 0 ft: basements fetched as a target of a query (bytes): 0 ft: basements fetched as a target of a query (seconds): 0.000000 ft: basements fetched for prelocked range: 0 ft: basements fetched for prelocked range (bytes): 0 ft: basements fetched for prelocked range (seconds): 0.000000 ft: basements fetched for prefetch: 0 ft: basements fetched for prefetch (bytes): 0 ft: basements fetched for prefetch (seconds): 0.000000 ft: basements fetched for write: 0 ft: basements fetched for write (bytes): 0 ft: basements fetched for write (seconds): 0.000000 ft: buffers fetched as a target of a query: 0 ft: buffers fetched as a target of a query (bytes): 0 ft: buffers fetched as a target of a query (seconds): 0.000000 ft: buffers fetched for prelocked range: 0 ft: buffers fetched for prelocked range (bytes): 0 ft: buffers fetched for prelocked range (seconds): 0.000000 ft: buffers fetched for prefetch: 0 ft: buffers fetched for prefetch (bytes): 0 ft: buffers fetched for prefetch (seconds): 0.000000 ft: buffers fetched for write: 0 ft: buffers fetched for write (bytes): 0 ft: buffers fetched for write (seconds): 0.000000 ft: leaf compression to memory (seconds): 0.000729 ft: leaf serialization to memory (seconds): 0.000012 ft: leaf decompression to memory (seconds): 0.000000 ft: leaf deserialization to memory (seconds): 0.000000 ft: nonleaf compression to memory (seconds): 0.000000 ft: nonleaf serialization to memory (seconds): 0.000000 ft: nonleaf decompression to memory (seconds): 0.000000 ft: nonleaf deserialization to memory (seconds): 0.000000 ft: promotion: roots split: 0 ft: promotion: leaf roots injected into: 3 ft: promotion: h1 roots injected into: 0 ft: promotion: injections at depth 0: 0 ft: promotion: injections at depth 1: 0 ft: promotion: injections at depth 2: 0 ft: promotion: injections at depth 3: 0 ft: promotion: injections lower than depth 3: 0 ft: promotion: stopped because of a nonempty buffer: 0 ft: promotion: stopped at height 1: 0 ft: promotion: stopped because the child was locked or not at all in memory: 0 ft: promotion: stopped because the child was not fully in memory: 0 ft: promotion: stopped anyway, after locking the child: 0 ft: basement nodes deserialized with fixed-keysize: 0 ft: basement nodes deserialized with variable-keysize: 0 ft: promotion: succeeded in using the rightmost leaf shortcut: 0 ft: promotion: tried the rightmost leaf shorcut but failed (out-of-bounds): 0 ft: promotion: tried the rightmost leaf shorcut but failed (child reactive): 0 ft: cursor skipped deleted leaf entries: 0 ft flusher: total nodes potentially flushed by cleaner thread: 0 ft flusher: height-one nodes flushed by cleaner thread: 0 ft flusher: height-greater-than-one nodes flushed by cleaner thread: 0 ft flusher: nodes cleaned which had empty buffers: 0 ft flusher: nodes dirtied by cleaner thread: 0 ft flusher: max bytes in a buffer flushed by cleaner thread: 0 ft flusher: min bytes in a buffer flushed by cleaner thread: 18446744073709551615 ft flusher: total bytes in buffers flushed by cleaner thread: 0 ft flusher: max workdone in a buffer flushed by cleaner thread: 0 ft flusher: min workdone in a buffer flushed by cleaner thread: 18446744073709551615 ft flusher: total workdone in buffers flushed by cleaner thread: 0 ft flusher: times cleaner thread tries to merge a leaf: 0 ft flusher: cleaner thread leaf merges in progress: 0 ft flusher: cleaner thread leaf merges successful: 0 ft flusher: nodes dirtied by cleaner thread leaf merges: 0 ft flusher: total number of flushes done by flusher threads or cleaner threads: 0 ft flusher: number of in memory flushes: 0 ft flusher: number of flushes that read something off disk: 0 ft flusher: number of flushes that triggered another flush in child: 0 ft flusher: number of flushes that triggered 1 cascading flush: 0 ft flusher: number of flushes that triggered 2 cascading flushes: 0 ft flusher: number of flushes that triggered 3 cascading flushes: 0 ft flusher: number of flushes that triggered 4 cascading flushes: 0 ft flusher: number of flushes that triggered 5 cascading flushes: 0 ft flusher: number of flushes that triggered over 5 cascading flushes: 0 ft flusher: leaf node splits: 0 ft flusher: nonleaf node splits: 0 ft flusher: leaf node merges: 0 ft flusher: nonleaf node merges: 0 ft flusher: leaf node balances: 0 hot: operations ever started: 0 hot: operations successfully completed: 0 hot: operations aborted: 0 hot: max number of flushes from root ever required to optimize a tree: 0 txn: begin: 1 txn: begin read only: 0 txn: successful commits: 1 txn: aborts: 0 logger: next LSN: 12 logger: writes: 5 logger: writes (bytes): 694 logger: writes (uncompressed bytes): 694 logger: writes (seconds): 0.000061 logger: number of long logger write operations: 0 indexer: number of indexers successfully created: 0 indexer: number of calls to toku_indexer_create_indexer() that failed: 0 indexer: number of calls to indexer->build() succeeded: 0 indexer: number of calls to indexer->build() failed: 0 indexer: number of calls to indexer->close() that succeeded: 0 indexer: number of calls to indexer->close() that failed: 0 indexer: number of calls to indexer->abort(): 0 indexer: number of indexers currently in existence: 0 indexer: max number of indexers that ever existed simultaneously: 0 loader: number of loaders successfully created: 0 loader: number of calls to toku_loader_create_loader() that failed: 0 loader: number of calls to loader->put() succeeded: 0 loader: number of calls to loader->put() failed: 0 loader: number of calls to loader->close() that succeeded: 0 loader: number of calls to loader->close() that failed: 0 loader: number of calls to loader->abort(): 0 loader: number of loaders currently in existence: 0 loader: max number of loaders that ever existed simultaneously: 0 memory: number of malloc operations: 0 memory: number of free operations: 0 memory: number of realloc operations: 0 memory: number of malloc operations that failed: 0 memory: number of realloc operations that failed: 0 memory: number of bytes requested: 0 memory: number of bytes used (requested + overhead): 0 memory: number of bytes freed: 0 memory: largest attempted allocation size: 0 memory: size of the last failed allocation attempt: 0 memory: estimated maximum memory footprint: 0 memory: mallocator version: 3.6.0-0-g46c0af68bd248b04df75e4f92d5fb804c3d75340 memory: mmap threshold: 4194304 filesystem: ENOSPC redzone state: 1 filesystem: threads currently blocked by full disk: 0 filesystem: number of operations rejected by enospc prevention (red zone): 0 filesystem: most recent disk full: Thu Jan 1 02:00:00 1970 filesystem: number of write operations that returned ENOSPC: 0 filesystem: fsync time: 587898 filesystem: fsync count: 15 filesystem: long fsync time: 0 filesystem: long fsync count: 0 context: tree traversals blocked by a full fetch: 0 context: tree traversals blocked by a partial fetch: 0 context: tree traversals blocked by a full eviction: 0 context: tree traversals blocked by a partial eviction: 0 context: tree traversals blocked by a message injection: 0 context: tree traversals blocked by a message application: 0 context: tree traversals blocked by a flush: 0 context: tree traversals blocked by a the cleaner thread: 0 context: tree traversals blocked by something uninstrumented: 0 context: promotion blocked by a full fetch (should never happen): 0 context: promotion blocked by a partial fetch (should never happen): 0 context: promotion blocked by a full eviction (should never happen): 0 context: promotion blocked by a partial eviction (should never happen): 0 context: promotion blocked by a message injection: 0 context: promotion blocked by a message application: 0 context: promotion blocked by a flush: 0 context: promotion blocked by the cleaner thread: 0 context: promotion blocked by something uninstrumented: 0 context: something uninstrumented blocked by something uninstrumented: 0   Memory usage: Arena 0: system bytes = 3084288 in use bytes = 2956560 Arena 1: system bytes = 135168 in use bytes = 2368 Arena 2: system bytes = 1204224 in use bytes = 799728 Arena 3: system bytes = 135168 in use bytes = 103136 Arena 4: system bytes = 135168 in use bytes = 4800 Arena 5: system bytes = 135168 in use bytes = 7376 Arena 6: system bytes = 135168 in use bytes = 2320 Arena 7: system bytes = 135168 in use bytes = 12064 Total (incl. mmap): system bytes = 199077888 in use bytes = 197866720 max mmap regions = 53 max mmap bytes = 224395264 180711 20:25:24 [ERROR] mysqld got signal 6 ;   #5 0x00007f0029244448 in __GI_abort () at abort.c:89 #6 0x00007f0024616c79 in toku_do_backtrace_abort () at /data/src/10.3/storage/tokudb/PerconaFT/portability/toku_assert.cc:147 #7 0x00007f0024616d73 in toku_do_assert_fail (expr_as_string=0x7f0024649bf1 "r==0 || r==ETIMEDOUT", function=0x7f0024649c84 <minicron_do(void*)::__FUNCTION__> "minicron_do", file=0x7f0024649ba8 "/data/src/10.3/storage/tokudb/PerconaFT/util/minicron.cc", line=105, caller_errno=0) at /data/src/10.3/storage/tokudb/PerconaFT/portability/toku_assert.cc:168 #8 0x00007f00245e9259 in minicron_do (pv=0x7f002e5ef5b0) at /data/src/10.3/storage/tokudb/PerconaFT/util/minicron.cc:105 #9 0x00007f002beaad73 in pfs_spawn_thread (arg=0x7f002e60c090) at /data/src/10.3/storage/perfschema/pfs.cc:1862 #10 0x00007f002aea3064 in start_thread (arg=0x7f0009adb700) at pthread_create.c:309 #11 0x00007f00292f662d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111