[MDEV-5100] TokuDB core dump when restoring dump per table in concurrency Created: 2013-10-04  Updated: 2013-11-06  Due: 2013-11-04  Resolved: 2013-11-06

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: 5.5.33a
Fix Version/s: None

Type: Bug Priority: Major
Reporter: VAROQUI Stephane Assignee: Elena Stepanova
Resolution: Not a Bug Votes: 0
Labels: tokudb


 Description   

Oct 4 14:25:21 tyrebase-galera01-pp mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Oct 4 14:26:52 tyrebase-galera01-pp mysqld_safe: Starting mysqld daemon with databases from /home/mysql/data
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: 131004 14:26:53 [Warning] Using unique option prefix myisam_recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: 131004 14:26:53 InnoDB: The InnoDB memory heap is disabled
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: 131004 14:26:53 InnoDB: Mutexes and rw_locks use GCC atomic builtins
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: 131004 14:26:53 InnoDB: Compressed tables use zlib 1.2.7
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: 131004 14:26:53 InnoDB: Using Linux native AIO
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: 131004 14:26:53 InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 1 failed.
Oct 4 14:26:53 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 2 failed.
Oct 4 14:26:54 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 3 failed.
Oct 4 14:26:54 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 4 failed.
Oct 4 14:26:55 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 5 failed.
Oct 4 14:26:55 tyrebase-galera01-pp mysqld: 131004 14:26:55 InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
Oct 4 14:26:55 tyrebase-galera01-pp mysqld: InnoDB: You can disable Linux Native AIO by setting innodb_use_native_aio = 0 in my.cnf
Oct 4 14:26:55 tyrebase-galera01-pp mysqld: InnoDB: Warning: Linux Native AIO disabled because os_aio_linux_create_io_ctx() failed. To get rid of this warning you can try increasing system fs.aio-max-nr to 1048576 or larger or setting innodb_use_native_aio = 0 in my.cnf
Oct 4 14:26:55 tyrebase-galera01-pp mysqld: 131004 14:26:55 InnoDB: Initializing buffer pool, size = 8.0G
Oct 4 14:26:56 tyrebase-galera01-pp mysqld: 131004 14:26:56 InnoDB: Completed initialization of buffer pool
Oct 4 14:26:56 tyrebase-galera01-pp mysqld: 131004 14:26:56 InnoDB: highest supported file format is Barracuda.
Oct 4 14:26:56 tyrebase-galera01-pp mysqld: 131004 14:26:56 InnoDB: Waiting for the background threads to start
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 Percona XtraDB (http://www.percona.com) 5.5.33a-MariaDB-31.1 started; log sequence number 89826632242
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 [Note] Plugin 'FEEDBACK' is disabled.
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 [Note] Server socket created on IP: '0.0.0.0'.
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 [Warning] 'user' entry 'root@node-sql-01' ignored in --skip-name-resolve mode.
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 [Warning] 'proxies_priv' entry '@ root@node-sql-01' ignored in --skip-name-resolve mode.
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 [Note] Event Scheduler: Loaded 0 events
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: 131004 14:26:57 [Note] /usr/sbin/mysqld: ready for connections.
Oct 4 14:26:57 tyrebase-galera01-pp mysqld: Version: '5.5.33a-MariaDB-1~wheezy-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23683]: Upgrading MySQL tables if necessary.
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23688]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23688]: Looking for 'mysql' as: /usr/bin/mysql
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23688]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23688]: This installation of MySQL is already upgraded to 5.5.33a-MariaDB, use --force if you still need to run mysql_upgrade
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23702]: Checking for insecure root accounts.
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23707]: WARNING: mysql.user contains 3 root accounts without password!
Oct 4 14:26:58 tyrebase-galera01-pp /etc/mysql/debian-start[23708]: Triggering myisam-recover for all MyISAM tables
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /home/buildbot/buildbot/build/mariadb-5.5.33a/storage/tokudb/ft-index/portability/memory.cc:333 toku_xmalloc: Assertion `p' failed (errno=12)
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: : Cannot allocate memory
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Backtrace: (Note: toku_do_assert=0x0x7f589f95c300)
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0x132138)[0x7f589f95c138]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0x1322f7)[0x7f589f95c2f7]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(_Z12toku_xmallocm+0x158)[0x7f589f95ad18]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(_Z23mempool_malloc_from_omtPPN4toku3omtIPvS1_Lb0EEEP7mempoolmPS1_+0x79)[0x7f589f8e92d9]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(_Z7le_packP3ulePmPP9leafentryPPN4toku3omtIPvS7_Lb0EEEP7mempoolPS7_+0xa5)[0x7f589f930705]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(_Z23toku_le_garbage_collectP9leafentryPS0_PmPPN4toku3omtIPvS5_Lb0EEEP7mempoolPS5_RKNS4_ImmLb0EEERKNS4_I20referenced_xid_tuplePSF_Lb0EEESE_mPl+0x40f)[0x7f589f9324cf]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0xb7b45)[0x7f589f8e1b45]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(_Z23toku_bnc_flush_to_childP2ftP24ftnode_nonleaf_childinfoP6ftnodem+0x293)[0x7f589f8f6613]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0xb4c3b)[0x7f589f8dec3b]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0xb50f3)[0x7f589f8df0f3]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0x10cf3c)[0x7f589f936f3c]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f5c00b87b50]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f5bff4aba7d]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Engine status:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: BUILD_ID = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Env panic code: 12
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Env panic string: /home/buildbot/buildbot/build/mariadb-5.5.33a/storage/tokudb/ft-index/portability/memory.cc:333 toku_xmalloc: Assertion `p' failed (errno=12)
Oct 4 14:36:10 tyrebase-galera01-pp mysqld:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: time of environment creation: Fri Oct 4 14:26:57 2013
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: time of engine startup: Fri
Oct 4 14:26:57 2013
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: time now: Fri Oct 4 14:36:10 2013
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: db opens: 2823
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: db closes: 2787
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: num open dbs now: 35
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: max open dbs: 727
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: period, in ms, that recovery log is automatically fsynced: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary inserts: 4469546
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary inserts fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary deletes: 100
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary deletes fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary updates: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary updates fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary broadcast updates: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary broadcast updates fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary multi inserts: 123460683
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary multi inserts fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary multi deletes: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary multi deletes fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary updates multi: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: dictionary updates multi fail: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: le: max committed xr: 23
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: le: max provisional xr: 2
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: le: expanded: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: le: max memsize: 32978
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: period: 60
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: footprint: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: last checkpoint began : Fri Oct 4 14:34:55 2013
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: last complete checkpoint began : Fri Oct 4 14:34:55 2013
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: last complete checkpoint ended: Fri Oct 4 14:35:22 2013
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: last complete checkpoint LSN: 29681091
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: checkpoints taken : 8
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: checkpoints failed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: waiters now: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: waiters max: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: non-checkpoint client wait on mo lock: 4
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: checkpoint: non-checkpoint client wait on cs lock: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: miss: 1388
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: miss time: 127560
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: prefetches: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size current: 9459039314
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size limit: 17442459648
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size writing: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size nonleaf: 526214167
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size leaf: 8927764049
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size rollback: 5061098
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: size cachepressure: 525997376
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: evictions: 3428
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: cleaner executions: 723
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: cleaner period: 1
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: cachetable: cleaner iterations: 5
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: memory size: 5154614
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: memory size limit: 2113198592
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: number of times lock escalation ran: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: time spent running escalation (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: latest post-escalation memory size: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: number of locktrees open now: 38
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: number of pending lock requests: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: number of locktrees eligible for the STO: 17
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: number of times a locktree ended the STO early: 6
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: locktree: time spent ending the STO early (seconds): 0.000043
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: dictionary updates: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: dictionary broadcast updates: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: descriptor set: 1102
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: messages ignored by leaf due to msn: 83
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: total search retries due to TRY_AGAIN: 411
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: searches requiring more tries than the height of the tree: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: searches requiring more tries than the height of the tree plus three: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (not for checkpoint): 2118
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (not for checkpoint) (bytes): 426222080
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (not for checkpoint) (uncompressed bytes): 427877484
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (not for checkpoint) (seconds): 0.542134
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (not for checkpoint): 276
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (not for checkpoint) (bytes): 145920
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (not for checkpoint) (uncompressed bytes): 85293
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (not for checkpoint) (seconds): 0.059306
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (for checkpoint): 2508
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (for checkpoint) (bytes): 8031217664
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (for checkpoint) (uncompressed bytes): 8030480317
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes flushed to disk (for checkpoint) (seconds): 7.000245
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (for checkpoint): 372
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (for checkpoint) (bytes): 832871936
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (for checkpoint) (uncompressed bytes): 832746722
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes flushed to disk (for checkpoint) (seconds): 1.050986
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf node partial evictions: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf node partial evictions (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf node partial evictions: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf node partial evictions (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf node full evictions: 3093
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf node full evictions (bytes): 676521846
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf node full evictions: 335
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf node full evictions (bytes): 1658157
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes created: 3510
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes created: 348
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf nodes destroyed: 6018
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf nodes destroyed: 707
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: bytes of messages injected at root (all trees): 6336879734
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: bytes of messages flushed from h1 nodes to leaves: 6045807755
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: bytes of messages currently in trees (estimate): 291071979
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: messages injected at root: 114631255
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: broadcast messages injected at root: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements decompressed as a target of a query: 20
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements decompressed for prelocked range: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements decompressed for prefetch: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements decompressed for write: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers decompressed as a target of a query: 274
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers decompressed for prelocked range: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers decompressed for prefetch: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers decompressed for write: 4
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for query: 411
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for query (bytes): 312320
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for query (seconds): 0.000544
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for prefetch: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for prefetch (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for prefetch (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for write: 353
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for write (bytes): 3464704
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: pivots fetched for write (seconds): 0.002646
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched as a target of a query: 411
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched as a target of a query (bytes): 411136
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched as a target of a query (seconds): 0.000248
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for prelocked range: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for prelocked range (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for prelocked range (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for prefetch: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for prefetch (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for prefetch (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for write: 734
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for write (bytes): 55394816
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: basements fetched for write (seconds): 0.020069
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched as a target of a query: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched as a target of a query (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched as a target of a query (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for prelocked range: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for prelocked range (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for prelocked range (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for prefetch: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for prefetch (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for prefetch (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for write: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for write (bytes): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: buffers fetched for write (seconds): 0.000000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf compression to memory (seconds): 5.697197
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf serialization to memory (seconds): 10.385861
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf decompression to memory (seconds): 0.028298
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: leaf deserialization to memory (seconds): 0.081111
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf compression to memory (seconds): 0.645868
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf serialization to memory (seconds): 1.546849
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf decompression to memory (seconds): 0.000436
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: nonleaf deserialization to memory (seconds): 0.001538
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: roots split: 243
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: leaf roots injected into: 4409369
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: h1 roots injected into: 31462605
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: injections at depth 0: 226
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: injections at depth 1: 87521288
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: injections at depth 2: 4549674
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: injections at depth 3: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: injections lower than depth 3: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: stopped because of a nonempty buffer: 68241671
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: stopped at height 1: 3115
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: stopped because the child was locked or not at all in memory: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: stopped because the child was not fully in memory: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt: promotion: stopped anyway, after locking the child: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: total nodes potentially flushed by cleaner thread: 191
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: height-one nodes flushed by cleaner thread: 191
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: height-greater-than-one nodes flushed by cleaner thread: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: nodes cleaned which had empty buffers: 1
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: nodes dirtied by cleaner thread: 116
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: max bytes in a buffer flushed by cleaner thread: 4192848
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: min bytes in a buffer flushed by cleaner thread: 43
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: total bytes in buffers flushed by cleaner thread: 185455099
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: max workdone in a buffer flushed by cleaner thread: 1220
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: min workdone in a buffer flushed by cleaner thread: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: total workdone in buffers flushed by cleaner thread: 2552
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: times cleaner thread tries to merge a leaf: 3
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: cleaner thread leaf merges in progress: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: cleaner thread leaf merges successful: 3
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: nodes dirtied by cleaner thread leaf merges: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: total number of flushes done by flusher threads or cleaner threads: 4639
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of in memory flushes: 4639
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that read something off disk: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered another flush in child: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered 1 cascading flush: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered 2 cascading flushes: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered 3 cascading flushes: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered 4 cascading flushes: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered 5 cascading flushes: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: number of flushes that triggered over 5 cascading flushes: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: leaf node splits: 1682
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: nonleaf node splits: 105
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: leaf node merges: 3
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: nonleaf node merges: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: brt flusher: leaf node balances: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: hot: operations ever started: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: hot: operations successfully completed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: hot: operations aborted: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: hot: max number of flushes from root ever required to optimize a tree: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: txn: begin: 8485
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: txn: begin read only: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: txn: successful commits: 7966
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: txn: aborts: 515
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: next LSN: 34214640
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: ilock count: 34231026
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: olock count: 38406
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: swap count: 8193
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: writes: 8193
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: writes (bytes): 4062371134
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: writes (uncompressed bytes): 4062371134
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: logger: writes (seconds): 4.703714
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of indexers successfully created: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of calls to toku_indexer_create_indexer() that failed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of calls to indexer->build() succeeded: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of calls to indexer->build() failed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of calls to indexer->close() that succeeded: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of calls to indexer->close() that failed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of calls to indexer->abort(): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: number of indexers currently in existence: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: indexer: max number of indexers that ever existed simultaneously: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of loaders successfully created: 167
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of calls to toku_loader_create_loader() that failed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of calls to loader->put() succeeded: 583759
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of calls to loader->put() failed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of calls to loader->close() that succeeded: 166
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of calls to loader->close() that failed: 1
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of calls to loader->abort(): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: number of loaders currently in existence: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: loader: max number of loaders that ever existed simultaneously: 2
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of malloc operations: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of free operations: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of realloc operations: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of malloc operations that failed: 1
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of realloc operations that failed: 572
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of bytes requested: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of bytes used (requested + overhead): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: number of bytes freed: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: estimated maximum memory footprint: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: mallocator version: 3.3.1-0-g9ef9d9e8c271cdf14f664b871a8f98c827714784
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: memory: mmap threshold: 4194304
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: ENOSPC redzone state: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: threads currently blocked by full disk: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: number of operations rejected by enospc prevention (red zone): 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: most recent disk full: Thu Jan 1 01:00:00 1970
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: number of write operations that returned ENOSPC: 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: fsync time: 116546683
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: filesystem: fsync count: 16796
Oct 4 14:36:10 tyrebase-galera01-pp mysqld:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Memory usage:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Arena 0:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: system bytes = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: in use bytes = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Total (incl. mmap):
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: system bytes = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: in use bytes = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: max mmap regions = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: max mmap bytes = 0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: 131004 14:36:10 [ERROR] mysqld got signal 6 ;
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: This could be because you hit a bug. It is also possible that this binary
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Oct 4 14:36:10 tyrebase-galera01-pp mysqld:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs
Oct 4 14:36:10 tyrebase-galera01-pp mysqld:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: We will try our best to scrape up some info that will hopefully help
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: diagnose the problem, but since we have already crashed,
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: something is definitely wrong and this may fail.
Oct 4 14:36:10 tyrebase-galera01-pp mysqld:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Server version: 5.5.33a-MariaDB-1~wheezy-log
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: key_buffer_size=4294967296
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: read_buffer_size=262144
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: max_used_connections=8
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: max_threads=302
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: thread_count=5
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: It is possible that mysqld could use up to
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 9224959 K bytes of memory
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Hope that's ok; if not, decrease some variables in the equation.
Oct 4 14:36:10 tyrebase-galera01-pp mysqld:
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Thread pointer: 0x0x0
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: Attempting backtrace. You can use the following information to find out
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: where mysqld died. If you see no messages after this, something went
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: terribly wrong...
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: stack_bottom = 0x0 thread_stack 0x48000
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: (my_addr_resolve failure: fork)
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2b) [0x7f5c0185924b]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x422) [0x7f5c01494552]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf030) [0x7f5c00b90030]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35) [0x7f5bff403475]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180) [0x7f5bff4066f0]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0x13223b) [0x7f589f95c23b]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0x1322f7) [0x7f589f95c2f7]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(toku_xmalloc(unsigned long)+0x158) [0x7f589f95ad18]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(mempool_malloc_from_omt(toku::omt<void*, void*, false>**, mempool*, unsigned long, void**)+0x79) [0x7f589f8e92d9]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(le_pack(ule*, unsigned long*, leafentry**, toku::omt<void*, void*, false>**, mempool*, void**)+0xa5) [0x7f589f930705]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(toku_le_garbage_collect(leafentry*, leafentry**, unsigned long*, toku::omt<void*, void*, false>**, mempool*, void**, toku::omt<unsigned long, unsigned long, false> const&, toku::omt<referenced_xid_tuple, referenced_xid_tuple*, false> const&, toku::omt<unsigned long, unsigned long, false> const&, unsigned long, long*)+0x40f) [0x7f589f9324cf]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0xb7b45) [0x7f589f8e1b45]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(toku_bnc_flush_to_child(ft*, ftnode_nonleaf_childinfo*, ftnode*, unsigned long)+0x293) [0x7f589f8f6613]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0xb4c3b) [0x7f589f8dec3b]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0xb50f3) [0x7f589f8df0f3]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /usr/lib/mysql/plugin/ha_tokudb.so(+0x10cf3c) [0x7f589f936f3c]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50) [0x7f5c00b87b50]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f5bff4aba7d]
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Oct 4 14:36:10 tyrebase-galera01-pp mysqld: information that should help you find out what is causing the crash.
Oct 4 14:36:11 tyrebase-galera01-pp mysqld_safe: Number of processes running now: 0
Oct 4 14:36:11 tyrebase-galera01-pp mysqld_safe: mysqld restarted
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: 131004 14:36:11 [Warning] Using unique option prefix myisam_recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: 131004 14:36:11 InnoDB: The InnoDB memory heap is disabled
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: 131004 14:36:11 InnoDB: Mutexes and rw_locks use GCC atomic builtins
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: 131004 14:36:11 InnoDB: Compressed tables use zlib 1.2.7
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: 131004 14:36:11 InnoDB: Using Linux native AIO
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: 131004 14:36:11 InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 1 failed.
Oct 4 14:36:11 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 2 failed.
Oct 4 14:36:12 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 3 failed.
Oct 4 14:36:12 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 4 failed.
Oct 4 14:36:13 tyrebase-galera01-pp mysqld: InnoDB: Warning: io_setup() attempt 5 failed.
Oct 4 14:36:13 tyrebase-galera01-pp mysqld: 131004 14:36:13 InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
Oct 4 14:36:13 tyrebase-galera01-pp mysqld: InnoDB: You can disable Linux Native AIO by setting innodb_use_native_aio = 0 in my.cnf
Oct 4 14:36:13 tyrebase-galera01-pp mysqld: InnoDB: Warning: Linux Native AIO disabled because os_aio_linux_create_io_ctx() failed. To get rid of this warning you can try increasing system fs.aio-max-nr to 1048576 or larger or setting innodb_use_native_aio = 0 in my.cnf
Oct 4 14:36:13 tyrebase-galera01-pp mysqld: 131004 14:36:13 InnoDB: Initializing buffer pool, size = 8.0G
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: 131004 14:36:14 InnoDB: Completed initialization of buffer pool
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: 131004 14:36:14 InnoDB: highest supported file format is Barracuda.
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: InnoDB: The log sequence number in ibdata files does not match
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: InnoDB: the log sequence number in the ib_logfiles!
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: 131004 14:36:14 InnoDB: Database was not shut down normally!
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: InnoDB: Starting crash recovery.
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: InnoDB: Reading tablespace information from the .ibd files...
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
Oct 4 14:36:14 tyrebase-galera01-pp mysqld: InnoDB: buffer...
Oct 4 14:36:15 tyrebase-galera01-pp mysqld: InnoDB: Last MySQL binlog file position 0 89527186, file name /home/mysql/log/mariadb-bin.000292
Oct 4 14:36:15 tyrebase-galera01-pp mysqld: 131004 14:36:15 InnoDB: Waiting for the background threads to start
Oct 4 14:36:16 tyrebase-galera01-pp mysqld: 131004 14:36:16 Percona XtraDB (http://www.percona.com) 5.5.33a-MariaDB-31.1 started; log sequence number 89840613172
Oct 4 14:36:16 tyrebase-galera01-pp mysqld: 131004 14:36:16 [Note] Plugin 'FEEDBACK' is disabled.
Oct 4 14:36:16 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:16 2013 Tokudb recovery starting in env /home/mysql/data/
Oct 4 14:36:16 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:16 2013 Tokudb recovery scanning backward from 34211374
Oct 4 14:36:27 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:27 2013 Tokudb recovery bw_end_checkpoint at 30973324 timestamp 1380890122509303 xid 29681091 (bw_newer)
Oct 4 14:36:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:31 2013 Tokudb recovery scanning backward from 34211374 at 29823374 (bw_between)
Oct 4 14:36:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:31 2013 Tokudb recovery bw_begin_checkpoint at 29681091 timestamp 1380890095618809 (bw_between)
Oct 4 14:36:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:31 2013 Tokudb recovery turning around at begin checkpoint 29681091 time 26890494
Oct 4 14:36:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:31 2013 Tokudb recovery starts scanning forward to 34211374 from 29681091 left 4530283 (fw_between)
Oct 4 14:36:46 tyrebase-galera01-pp mysqld: Fri Oct 4 14:36:46 2013 Tokudb recovery scanning forward to 34211374 at 30084091 left 4127283 (fw_between)
Oct 4 14:37:01 tyrebase-galera01-pp mysqld: Fri Oct 4 14:37:01 2013 Tokudb recovery scanning forward to 34211374 at 30500091 left 3711283 (fw_between)
Oct 4 14:37:16 tyrebase-galera01-pp mysqld: Fri Oct 4 14:37:16 2013 Tokudb recovery scanning forward to 34211374 at 30875091 left 3336283 (fw_between)
Oct 4 14:37:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:37:31 2013 Tokudb recovery scanning forward to 34211374 at 31244091 left 2967283 (fw_newer)
Oct 4 14:37:46 tyrebase-galera01-pp mysqld: Fri Oct 4 14:37:46 2013 Tokudb recovery scanning forward to 34211374 at 31614091 left 2597283 (fw_newer)
Oct 4 14:38:01 tyrebase-galera01-pp mysqld: Fri Oct 4 14:38:01 2013 Tokudb recovery scanning forward to 34211374 at 31952091 left 2259283 (fw_newer)
Oct 4 14:38:16 tyrebase-galera01-pp mysqld: Fri Oct 4 14:38:16 2013 Tokudb recovery scanning forward to 34211374 at 32327091 left 1884283 (fw_newer)
Oct 4 14:38:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:38:31 2013 Tokudb recovery scanning forward to 34211374 at 32681091 left 1530283 (fw_newer)
Oct 4 14:38:46 tyrebase-galera01-pp mysqld: Fri Oct 4 14:38:46 2013 Tokudb recovery scanning forward to 34211374 at 33032091 left 1179283 (fw_newer)
Oct 4 14:39:01 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:01 2013 Tokudb recovery scanning forward to 34211374 at 33404091 left 807283 (fw_newer)
Oct 4 14:39:16 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:16 2013 Tokudb recovery scanning forward to 34211374 at 33754091 left 457283 (fw_newer)
Oct 4 14:39:31 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:31 2013 Tokudb recovery scanning forward to 34211374 at 34083091 left 128283 (fw_newer)
Oct 4 14:39:36 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:36 2013 Tokudb recovery has 4 live transactions
Oct 4 14:39:37 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:37 2013 Tokudb recovery closing 38 dictionaries
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:48 2013 Tokudb recovery making a checkpoint
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: Fri Oct 4 14:39:48 2013 Tokudb recovery done
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Note] Recovering after a crash using /home/mysql/log/mariadb-bin
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Note] Starting crash recovery...
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Note] Crash recovery finished.
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Note] Server socket created on IP: '0.0.0.0'.
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Warning] 'user' entry 'root@node-sql-01' ignored in --skip-name-resolve mode.
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Warning] 'proxies_priv' entry '@ root@node-sql-01' ignored in --skip-name-resolve mode.
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Note] Event Scheduler: Loaded 0 events
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: 131004 14:39:48 [Note] /usr/sbin/mysqld: ready for connections.
Oct 4 14:39:48 tyrebase-galera01-pp mysqld: Version: '5.5.33a-MariaDB-1~wheezy-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution

Version Debian

kernel version: Linux node-sql-01 3.2.0-4-amd64 #1 SMP Debian 3.2.46-1+deb7u1 x86_64 GNU/Linux

[mysqld]
user   	 = mysql
pid-file    = /var/run/mysqld/mysqld.pid
socket   	 = /var/run/mysqld/mysqld.sock
character_set_server   = utf8 #LOMG
collation_server   	= utf8_general_ci #LOMG
port   	 = 3306
basedir   	 = /usr
datadir   	 = /home/mysql/data #LOMG
tmpdir   	 = /home/mysql/tmp #LOMG
lc_messages_dir    = /usr/share/mysql
lc_messages    = en_US
skip-external-locking
skip-name-resolve #LOMG
# * Fine Tuning
connect_timeout   	 = 10 #LOMG
wait_timeout   	 = 28800 #LOMG
max_allowed_packet    = 16M #168M LOMG
thread_cache_size   = 128
sort_buffer_size    = 16M #SVA
bulk_insert_buffer_size    = 1G #SVA /!\ can be high on small servers
key_cache_block_size = 4096 #SVA
# * MyISAM
myisam_recover  	= BACKUP
#open-files-limit    = 2000
myisam_sort_buffer_size    = 1G #SVA /!\ can be high on small servers
concurrent_insert    = 2
# * Query Cache Configuration
# Cache only tiny result sets, so we can fit more in the query cache.
query_cache_size   	 = 128M #SVA
#query_cache_type   	 = DEMAND #for more write intensive
# * Logging and Replication
back_log = 128 #SVA
#general_log_file    	= /home/mysql/log/mysql.log
#general_log         	= 1
log_warnings   	 = 2
slow_query_log = 1
slow_query_log_file    = /home/mysql/log/mariadb-slow.log
long_query_time = 10
#log_slow_rate_limit    = 1000
log_slow_verbosity    = query_plan
#log-queries-not-using-indexes
#log_slow_admin_statements
server-id   	 = 1
#report_host   	 = master1
#auto_increment_increment = 2
#auto_increment_offset    = 1
log_bin   		 = /home/mysql/log/mariadb-bin
log_bin_index    = /home/mysql/log/mariadb-bin.index
#sync_binlog   	 = 1
expire_logs_days    = 4
max_binlog_size 	= 100M
# slaves
#relay_log   	 = /home/mysql/log/relay-bin
#relay_log_index    = /home/mysql/log/relay-bin.index
#relay_log_info_file    = /home/mysql/log/relay-bin.info
#log_slave_updates
#read_only
#sql_mode   	 = NO_ENGINE_SUBSTITUTION,TRADITIONAL
 
# * InnoDB
default_storage_engine    = InnoDB
innodb_log_file_size    = 900M #SVA
innodb_log_files_in_group = 4
innodb_file_per_table    = 1 #SVA
innodb_open_files    = 4000
innodb_flush_method    = O_DIRECT #SVA
innodb_thread_concurrency = 128 #SVA
innodb_flush_log_at_trx_commit = 2 #SVA
innodb_buffer_pool_size = 8G
innodb_io_capacity = 20000
innodb_log_buffer_size = 8M
innodb_old_blocks_time = 1000
innodb_stats_on_metadata = off
innodb_buffer_pool_instances = 4
innodb_max_dirty_pages_pct = 20
innodb_write_io_threads = 64
innodb_file_format=barracuda
 
# * Security Features
# chroot = /var/lib/mysql/
# ssl-ca=/etc/mysql/cacert.pem
# ssl-cert=/etc/mysql/server-cert.pem
# ssl-key=/etc/mysql/server-key.pem
 
bind-address = 0.0.0.0
group_concat_max_len = 1M
 
key_buffer_size = 4G
max_connections = 300
max_heap_table_size = 256M
max_sp_recursion_depth = 100
query_cache_size = 0
query_cache_limit = 512K
read_buffer_size = 256K
read_rnd_buffer_size = 512K
table_definition_cache = 2000
table_open_cache = 2000
tmp_table_size = 256M
 
 
# SVA : optimisation sous requetes et hash join grosses requeuquete qui pue
#Per-test optimizations
optimizer_switch='index_merge=on'
optimizer_switch='index_merge_union=on'
optimizer_switch='index_merge_sort_union=on'
optimizer_switch='index_merge_intersection=on'
optimizer_switch='index_merge_sort_intersection=off'
optimizer_switch='index_condition_pushdown=on'
optimizer_switch='derived_merge=on'
optimizer_switch='derived_with_keys=on'
optimizer_switch='firstmatch=off'
optimizer_switch='loosescan=off'
optimizer_switch='materialization=on'
optimizer_switch='in_to_exists=on'
optimizer_switch='semijoin=on'
optimizer_switch='partial_match_rowid_merge=on'
optimizer_switch='partial_match_table_scan=on'
optimizer_switch='subquery_cache=off'
optimizer_switch='mrr=on'
optimizer_switch='mrr_cost_based=off'
optimizer_switch='mrr_sort_keys=on'
optimizer_switch='outer_join_with_cache=on'
optimizer_switch='semijoin_with_cache=off'
optimizer_switch='join_cache_incremental=on'
optimizer_switch='join_cache_hashed=on'
optimizer_switch='join_cache_bka=on'
optimizer_switch='optimize_join_buffer_size=on'
optimizer_switch='table_elimination=on'
optimizer_switch='extended_keys=on'
 
join_buffer_space_limit = 3072M
join_buffer_size = 1536M
join_cache_level = 6
mrr_buffer_size = 96M
 
loose_tokudb_row_format = tokudb_fast
loose_plugin-load=ha_tokudb.so



 Comments   
Comment by Sergei Golubchik [ 2013-10-04 ]

could you explain, what exactly one has to do to repeat the bug? my.cnf and the error log don't really help here.

Comment by VAROQUI Stephane [ 2013-10-04 ]

we restored 4 backup files taken from mysqldump in // using the mariadb client from localhost, the server has 32g ram so far enouth for 16g toku buffer and 8g innodb buffer. we started the install from scratch with a proper install-db script as it was for a slave provisionning .

Comment by Elena Stepanova [ 2013-10-04 ]

Hi Stephane,

Could you please provide more details, I fail to see a consistent story so far.

What does "in concurrency" in the subject stand for?

What does it mean "restoring dump per table", exactly, and where does it happen in the scenario you described in the comment?

You are saying that you "started the install from scratch" but before that that you "restored backup files". What do backup files have to do with the story if you started install from scratch anyway?

You are saying that your server is supposed to use ~16+8 Gb memory and it should be enough. But in addition, your server is given 1.5 Gb of join_buffer_size, 4 Gb of key_buffer_size, 1G bulk_insert_buffer_size, 1G myisam_sort_buffer_size ... Do you take into account all that?

Also, more often than not the "io_setup() failed with EAGAIN" errors mean that you have other server(s) running on the same machine that consumed the resource. Are you sure it's not the case here, and do you know why it fails on the machine?

Thanks.

Comment by VAROQUI Stephane [ 2013-10-04 ]

Helena,

Here is the story

1 - Clean the datadir
2 - Create the system table
3 - Start MariaDB with the provided cnf
4 - Inject data from master dump files pipe into sed to replace MyISAM and InnodB with TokuDB .
5 - We had 4 different dumps because some MyISAM tables are huge and saved separately
6 - We restore dump files inside background shell
7 - After 10 minutes it crashed

I have no idea of the content of those dumps but you get a point here it may contain the system table as well
All Resulting tables after the crash have been stored in TokuDB

Sylvain can you retry with monitoring memory usage of the box during the load ?
Can you also check that you backup files does not have mysql system table?

Tx

Stéphane Varoqui, Senior Consultant
SkySQL | t: +33 695-926-401 | Skype: svaroqui

Comment by Elena Stepanova [ 2013-10-04 ]

I see, so "restoring dump per table in concurrency" must mean that you do steps 4-6 for all 4 dumps in parallel.
Had all dumps been loaded by the time when the crash happened?

All in all, given the configuration, I don't see right away anything particularly surprising in the memory problem, especially since you have huge MyISAM tables (and hence big MyISAM buffers might be in use). Considering parallel big INSERTs into MyISAM tables, bulk_insert_buffer_size might have even more effect, as it's a per-thread value, so you might at some point have 4 such buffers 1 Gb each?..

It would be indeed interesting to see the memory usage statistics. Please paste it when you get it.

Thanks.

Comment by VAROQUI Stephane [ 2013-10-08 ]

Sylvain,

Thank you investigation and time on this issue.
Something useful would be to activate the general log and send us the last query and the table definition on that last query .

Stéphane

Stéphane Varoqui, Senior Consultant
SkySQL | t: +33 695-926-401 | Skype: svaroqui

Comment by VAROQUI Stephane [ 2013-10-09 ]

Not a bug after decreasing some InnoDB configuration variables the single process load went fine this morning .We found that transparent huge page was enable and not checked at MariADB startup

note that the official Tokutek release refuse to load the storage engine if transparent huge page is enable.

Comment by Elena Stepanova [ 2013-10-18 ]

Hi Stephane,

This is strange. From all I see, it is checked in MariaDB version just as well:

131018 18:57:01 InnoDB: The InnoDB memory heap is disabled
131018 18:57:01 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131018 18:57:01 InnoDB: Compressed tables use zlib 1.2.3
131018 18:57:01 InnoDB: Using Linux native AIO
131018 18:57:01 InnoDB: Initializing buffer pool, size = 128.0M
131018 18:57:01 InnoDB: Completed initialization of buffer pool
131018 18:57:01 InnoDB: highest supported file format is Barracuda.
131018 18:57:01 InnoDB: Waiting for the background threads to start
131018 18:57:02 Percona XtraDB (http://www.percona.com) 5.5.33a-MariaDB-31.1 started; log sequence number 1597945
sh: 1: sysctl: not found
Transparent huge pages are enabled, according to /sys/kernel/mm/transparent_hugepage/enabled
131018 18:57:02 [ERROR] Plugin 'TokuDB' init function returned error.
131018 18:57:02 [ERROR] Plugin 'TokuDB' registration as a STORAGE ENGINE failed.
131018 18:57:02 [Note] Server socket created on IP: '0.0.0.0'.
131018 18:57:02 [Note] Event Scheduler: Loaded 0 events
131018 18:57:02 [Note] /home/elenst/mariadb-5.5.33a/sql/mysqld: ready for connections.
Version: '5.5.33a-MariaDB' socket: '/home/elenst/mariadb-5.5.33a/data/tmp/mysql.sock' port: 3306 Source distribution

The only difference is that in MariaDB version TokuDB is not the default engine, so even although TokuDB fails to initialize, the server still starts.
If you make TokuDB default, it will be exactly as in Tokutek build:

131018 18:58:37 InnoDB: The InnoDB memory heap is disabled
131018 18:58:37 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131018 18:58:37 InnoDB: Compressed tables use zlib 1.2.3
131018 18:58:37 InnoDB: Using Linux native AIO
131018 18:58:37 InnoDB: Initializing buffer pool, size = 128.0M
131018 18:58:37 InnoDB: Completed initialization of buffer pool
131018 18:58:37 InnoDB: highest supported file format is Barracuda.
131018 18:58:37 InnoDB: Waiting for the background threads to start
131018 18:58:38 Percona XtraDB (http://www.percona.com) 5.5.33a-MariaDB-31.1 started; log sequence number 1597945
sh: 1: sysctl: not found
Transparent huge pages are enabled, according to /sys/kernel/mm/transparent_hugepage/enabled
131018 18:58:38 [ERROR] Plugin 'TokuDB' init function returned error.
131018 18:58:38 [ERROR] Plugin 'TokuDB' registration as a STORAGE ENGINE failed.
131018 18:58:38 [ERROR] Unknown/unsupported storage engine: TokuDB
131018 18:58:38 [ERROR] Aborting

131018 18:58:38 InnoDB: Starting shutdown...
131018 18:58:39 InnoDB: Shutdown completed; log sequence number 1597945
131018 18:58:39 [Note] /home/elenst/mariadb-5.5.33a/sql/mysqld: Shutdown complete

Comment by VAROQUI Stephane [ 2013-10-25 ]

They found out that the issue is only happening using mysqlimport and that this was also happening with the TokuDB official release

Using standard load data does not produce any error

Comment by VAROQUI Stephane [ 2013-10-25 ]
  • We used mkfifo with the load data local in file too, and that worked.
  • I'm pretty sure it's not an out of memory because the mysql server dies alone and not because of OOMkiller invocation.
Comment by Elena Stepanova [ 2013-11-01 ]

Hi Stephane,

So what is the nature of this bug report, should we do anything else about it? Which part are you referring to in your last comments?

Initially you complained about the memory problem during concurrent restoring a dump.
Then you confirmed that it was caused by InnoDB misconfiguration and after fixing it everything was fine; but then you mentioned that there is also a problem that the transparent huge is not checked at MariaDB startup.
From what I see it is, which my previous comment is about.
Now you are mentioning some issue about mysqlimport, load data and back to out of memory which you are saying it is NOT. What problem are you talking about now?

Comment by VAROQUI Stephane [ 2013-11-01 ]

Elena

The client confirmed me that he was able to load his data but not using mysqlimport
Using mysqlimport it breaks with those error messages talking about memory .

But this nothing to do with system memory that is fine all the way .

Thanks

Stéphane Varoqui, Senior Consultant
SkySQL | t: +33 695-926-401 | Skype: svaroqui

Comment by Elena Stepanova [ 2013-11-01 ]

Stephane,

What data? Initially you said that you were loading dump files created by mysqldump, you even sed-replaced MyISAM with InnoDB on the way. What does it have to do with mysqlimport and LOAD DATA?
And how is it related to transparent huge that you mentioned on the way?

If you are talking about a different problem now, which needs to be solved, please create a new bug report describing it, it becomes too confusing to distinguish between several parallel complaints.

Comment by Elena Stepanova [ 2013-11-06 ]

So, there were three separate issues discussed in this entry:

1. Server crashed with memory allocation failures during concurrent load of dump files. According to the comment by Stephane (http://tinyurl.com/p3z9p4g), it was not a bug but a configuration issue resolved by proper adjustments to server options;

2. (From the same comment by the link above) – transparent huge page wasn't checked on MariaDB startup. As described in my comment http://tinyurl.com/ng27rh8 , it is actually checked, so it's not a bug either.

3. Some obscure issue with mysqlimport mentioned here http://tinyurl.com/nfxa9pz. As the comment suggests, it also happens with a TokuDB build, so it's most likely not a MariaDB bug. In any case, if there is something that needs to be done about it, I suggest to create a new report for it, with all relevant details.

Generated at Thu Feb 08 07:01:40 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.