2010-09-27 14:19:40 [ndbd] INFO -- Angel pid: 32519 ndb pid: 32520 NDBMT: non-mt 2010-09-27 14:19:40 [ndbd] INFO -- NDB Cluster -- DB node 4 2010-09-27 14:19:40 [ndbd] INFO -- mysql-5.1.41 ndb-7.0.13 -- 2010-09-27 14:19:40 [ndbd] INFO -- Ndbd_mem_manager::init(1) min: 134Mb initial: 154Mb Adding 155Mb to ZONE_LO (1,4935) 2010-09-27 14:19:41 [ndbd] INFO -- Start initiated (mysql-5.1.41 ndb-7.0.13) WARNING: timerHandlingLab now: 4716734 sent: 4716675 diff: 59 NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer WOPool::init(61, 9) RWPool::init(22, 13) RWPool::init(42, 18) RWPool::init(62, 13) Using 1 fragments per node RWPool::init(c2, 18) RWPool::init(e2, 16) WOPool::init(41, 8) RWPool::init(82, 12) RWPool::init(a2, 54) WOPool::init(21, 10) 2010-09-27 14:19:41 [ndbd] INFO -- Start phase 0 completed 2010-09-27 14:19:44 [ndbd] INFO -- findNeighbours from: 2043 old (left: 65535 right: 65535) new (3 3) 2010-09-27 14:19:44 [ndbd] INFO -- Start phase 1 completed 2010-09-27 14:19:44 [ndbd] INFO -- Start phase 2 completed 2010-09-27 14:19:44 [ndbd] INFO -- Start phase 3 completed 2010-09-27 14:19:51 [ndbd] INFO -- Start phase 4 completed 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 5 completed 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 6 completed m_active_buckets.set(1) 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 7 completed 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 8 completed 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 9 completed 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 100 completed 2010-09-27 14:19:54 [ndbd] INFO -- Start phase 101 completed 2010-09-27 14:19:54 [ndbd] INFO -- Node started 2010-09-27 14:25:55 [ndbd] INFO -- Shutdown initiated 2010-09-27 14:25:55 [ndbd] INFO -- Shutdown completed - exiting 2010-09-27 14:25:55 [ndbd] INFO -- Angel shutting down 2010-09-27 14:25:55 [ndbd] INFO -- Node 4: Node shutdown completed. 2010-09-27 14:26:36 [ndbd] INFO -- Angel pid: 3350 ndb pid: 3351 NDBMT: non-mt 2010-09-27 14:26:36 [ndbd] INFO -- NDB Cluster -- DB node 4 2010-09-27 14:26:36 [ndbd] INFO -- mysql-5.1.41 ndb-7.0.13 -- 2010-09-27 14:26:36 [ndbd] INFO -- Ndbd_mem_manager::init(1) min: 134Mb initial: 154Mb Adding 155Mb to ZONE_LO (1,4935) 2010-09-27 14:26:37 [ndbd] INFO -- Start initiated (mysql-5.1.41 ndb-7.0.13) WARNING: timerHandlingLab now: 5132643 sent: 5132584 diff: 59 NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer WOPool::init(61, 9) RWPool::init(22, 13) RWPool::init(42, 18) RWPool::init(62, 13) Using 1 fragments per node RWPool::init(c2, 18) RWPool::init(e2, 16) WOPool::init(41, 8) RWPool::init(82, 12) RWPool::init(a2, 54) WOPool::init(21, 10) 2010-09-27 14:26:37 [ndbd] INFO -- Start phase 0 completed 2010-09-27 14:26:40 [ndbd] INFO -- findNeighbours from: 2043 old (left: 65535 right: 65535) new (3 3) 2010-09-27 14:26:40 [ndbd] INFO -- Start phase 1 completed 2010-09-27 14:26:40 [ndbd] INFO -- Start phase 2 completed 2010-09-27 14:26:40 [ndbd] INFO -- Start phase 3 completed 2010-09-27 14:26:47 [ndbd] INFO -- Start phase 4 completed 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 5 completed 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 6 completed m_active_buckets.set(1) 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 7 completed 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 8 completed 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 9 completed 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 100 completed 2010-09-27 14:26:50 [ndbd] INFO -- Start phase 101 completed 2010-09-27 14:26:50 [ndbd] INFO -- Node started alloc_chunk(1678 16) - 2010-09-27 14:33:09 [ndbd] INFO -- Shutdown initiated 2010-09-27 14:33:09 [ndbd] INFO -- Shutdown completed - exiting 2010-09-27 14:33:09 [ndbd] INFO -- Angel shutting down 2010-09-27 14:33:09 [ndbd] INFO -- Node 4: Node shutdown completed. 2010-09-27 14:35:16 [ndbd] INFO -- Angel pid: 3489 started child: 3490 2010-09-27 14:35:16 [ndbd] INFO -- Configuration fetched from '127.0.0.1:1186', generation: 1 NDBMT: non-mt 2010-09-27 14:35:16 [ndbd] INFO -- NDB Cluster -- DB node 4 2010-09-27 14:35:16 [ndbd] INFO -- mysql-5.1.47 ndb-7.1.5 -- 2010-09-27 14:35:16 [ndbd] INFO -- Ndbd_mem_manager::init(1) min: 134Mb initial: 154Mb Adding 155Mb to ZONE_LO (1,4935) 2010-09-27 14:35:16 [ndbd] INFO -- Start initiated (mysql-5.1.47 ndb-7.1.5) WARNING: timerHandlingLab now: 5652558 sent: 5652500 diff: 58 NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer NDBFS/AsyncFile: Allocating 310392 for In/Deflate buffer WOPool::init(61, 9) RWPool::init(22, 13) RWPool::init(42, 18) RWPool::init(62, 13) Using 1 fragments per node RWPool::init(c2, 18) RWPool::init(e2, 16) WOPool::init(41, 8) RWPool::init(82, 12) RWPool::init(a2, 54) WOPool::init(21, 10) 2010-09-27 14:35:17 [ndbd] INFO -- Start phase 0 completed 2010-09-27 14:35:17 [ndbd] INFO -- findNeighbours from: 2068 old (left: 65535 right: 65535) new (3 3) 2010-09-27 14:35:17 [ndbd] INFO -- Start phase 1 completed 2010-09-27 14:35:17 [ndbd] INFO -- Start phase 2 completed 2010-09-27 14:35:17 [ndbd] INFO -- Start phase 3 completed 2010-09-27 14:35:17 [ndbd] INFO -- Start phase 4 completed Found pending trans (0) - committing commit create 13 commit create 14 restartCreateObj(1) file: 1 restartCreateObj(2) file: 1 restartCreateObj(3) file: 1 restartCreateObj(4) file: 1 restartCreateObj(5) file: 1 restartCreateObj(6) file: 1 restartCreateObj(7) file: 1 restartCreateObj(9) file: 1 restartCreateObj(11) file: 1 tab: 2 frag: 0 replicaP->nextLcp: 1 scanning idx: 0 lcpId: 1 crashed replicas: 1 VALID maxGciCompleted: 1 maxGciStarted: 2 crashed replica: 0(1) replica(createGci: 2 lastGci: 186 ) Found LCP: 1(0) maxGciStarted: 2 maxGciCompleted: 1 restorable: 186(186) newestRestorableGCI: 250 tab: 2 frag: 1 replicaP->nextLcp: 1 scanning idx: 0 lcpId: 1 crashed replicas: 1 VALID maxGciCompleted: 1 maxGciStarted: 2 crashed replica: 0(1) replica(createGci: 2 lastGci: 186 ) Found LCP: 1(0) maxGciStarted: 2 maxGciCompleted: 1 restorable: 186(186) newestRestorableGCI: 250 tab: 3 frag: 0 replicaP->nextLcp: 1 scanning idx: 0 lcpId: 1 crashed replicas: 1 VALID maxGciCompleted: 1 maxGciStarted: 1 crashed replica: 0(1) replica(createGci: 2 lastGci: 186 ) Found LCP: 1(0) maxGciStarted: 1 maxGciCompleted: 1 restorable: 186(186) newestRestorableGCI: 250 tab: 3 frag: 1 replicaP->nextLcp: 1 scanning idx: 0 lcpId: 1 crashed replicas: 1 VALID maxGciCompleted: 1 maxGciStarted: 1 crashed replica: 0(1) replica(createGci: 2 lastGci: 186 ) Found LCP: 1(0) maxGciStarted: 1 maxGciCompleted: 1 restorable: 186(186) newestRestorableGCI: 250 tab: 4 frag: 0 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 4 frag: 0 tab: 4 frag: 1 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 4 frag: 1 tab: 5 frag: 0 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 5 frag: 0 tab: 5 frag: 1 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 5 frag: 1 tab: 6 frag: 0 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 6 frag: 0 tab: 6 frag: 1 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 6 frag: 1 tab: 7 frag: 0 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 7 frag: 0 tab: 7 frag: 1 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 7 frag: 1 tab: 9 frag: 0 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 9 frag: 0 tab: 9 frag: 1 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 9 frag: 1 tab: 11 frag: 0 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 11 frag: 0 tab: 11 frag: 1 replicaP->nextLcp: 0 scanning idx: 1 lcpId: 0 crashed replicas: 1 NOT VALID scanning idx: 0 lcpId: 0 crashed replicas: 1 NOT VALID - scanning idx: 2 lcpId: 0 Didnt find any LCP for node: 4 tab: 11 frag: 1 RESTORE table: 2 1037 rows applied RESTORE table: 2 1011 rows applied RESTORE table: 3 0 rows applied RESTORE table: 3 0 rows applied RedoPageCache: avoided 0 (0/0) page-reads RedoOpenFileCache: Avoided 0 file-open/close closed: 0 2010-09-27 14:35:23 [ndbd] INFO -- Start phase 5 completed 2010-09-27 14:35:23 [ndbd] INFO -- Start phase 6 completed 2010-09-27 14:35:23 [ndbd] INFO -- Start phase 7 completed 2010-09-27 14:35:23 [ndbd] INFO -- Start phase 8 completed 2010-09-27 14:35:23 [ndbd] INFO -- Start phase 9 completed 2010-09-27 14:35:23 [ndbd] INFO -- Start phase 100 completed alloc_chunk(1687 16) - 2010-09-27 14:35:24 [ndbd] INFO -- Suma: handover from node 3 gci: 256 buckets: 00000002 (2) 256/0 (255/4294967295) switchover complete bucket 1 state: 1starting 2010-09-27 14:35:29 [ndbd] INFO -- Start phase 101 completed 2010-09-27 14:35:29 [ndbd] INFO -- Node started