Bootstrap never finishes?

[Michael Brauwerman]

Hi Brisk users,

I had a problem today where I launched a new empty  cluster (seed node only) , inserted a test file into cfs wih hadoop dfs, and then added a second node with auto bootstrap true.

Everything started fine, but bootstrap never finishes after hours. Nodetool ring shows JOINING and netstats shows Bootstrapping. Logs are basically idle but show occasional notes about Streaming from the seed.

So I killed Cassandra, turned off auto bootstrap, started Cassandra, and everything seems mostly fine.

Was I wrong to use auto bootstrap? I am worried about what will happen in the future when I have a nonempty ring and a new node.

Thanks for any advice,

-Mike Brauwerman, via mobile

[Patricio Echagüe]

Is there any relevant info in the log files from both nodes you can share ?

[Michael Brauwerman]

Nothing relevant I can see:

Here is a "grep -i bootstrap"

[root@hadoop-2 deploy]# grep -i Bootstrap /var/log/cassandra/system.log
 INFO [main] 2011-09-20 15:00:00,974 StorageService.java (line 520) Joining: getting bootstrap token
 INFO [main] 2011-09-20 15:00:31,186 StorageService.java (line 520) Bootstrapping

Here is a "grep 10 -i bootstrap"

 INFO [FlushWriter:2] 2011-09-20 14:58:33,688 Memtable.java (line 237) Writing Memtable-Migrations@818048143(9508/11885 serialized/live bytes, 1 ops)
 INFO [FlushWriter:3] 2011-09-20 14:58:34,043 Memtable.java (line 254) Completed flushing /hadoop3/system/IndexInfo-g-4-Data.db (78 bytes)
 INFO [FlushWriter:3] 2011-09-20 14:58:34,045 Memtable.java (line 237) Writing Memtable-Schema@744831307(5228/6535 serialized/live bytes, 5 ops)
 INFO [FlushWriter:1] 2011-09-20 14:58:34,045 Memtable.java (line 237) Writing Memtable-IndexInfo@469605589(29/36 serialized/live bytes, 1 ops)
 INFO [CompactionExecutor:16] 2011-09-20 14:58:34,051 CompactionManager.java (line 543) Compacting Major: [SSTableReader(path='/hadoop1/system/IndexInfo-g-1-Data.db'), SSTableReader(path='/hadoop3/system/IndexInfo-g-4-Data.db'), SSTableReader(path='/hadoop1/system/IndexInfo-g-2-Data.db'), SSTableReader(path='/hadoop2/system/IndexInfo-g-3-Data.db')]
 INFO [CompactionExecutor:16] 2011-09-20 14:58:34,060 CompactionIterator.java (line 167) Major@2009270675(system, IndexInfo, 379/379) now compacting at 16777 bytes/ms.
 INFO [FlushWriter:2] 2011-09-20 14:58:34,099 Memtable.java (line 254) Completed flushing /hadoop3/system/Migrations-g-3-Data.db (9572 bytes)
 INFO [FlushWriter:3] 2011-09-20 14:58:34,406 Memtable.java (line 254) Completed flushing /hadoop1/system/Schema-g-3-Data.db (5378 bytes)
 INFO [FlushWriter:1] 2011-09-20 14:58:34,451 Memtable.java (line 254) Completed flushing /hadoop1/system/IndexInfo-g-5-Data.db (82 bytes)
 INFO [CompactionExecutor:16] 2011-09-20 14:58:34,464 CompactionManager.java (line 606) Compacted to /hadoop1/system/IndexInfo-tmp-g-6-Data.db.  379 to 220 (~58% of original) bytes for 1 keys.  Time: 412ms.
 INFO [main] 2011-09-20 15:00:00,974 StorageService.java (line 520) Joining: getting bootstrap token
 INFO [main] 2011-09-20 15:00:00,976 ColumnFamilyStore.java (line 1013) Enqueuing flush of Memtable-LocationInfo@1424720911(71/88 serialized/live bytes, 2 ops)
 INFO [FlushWriter:4] 2011-09-20 15:00:00,977 Memtable.java (line 237) Writing Memtable-LocationInfo@1424720911(71/88 serialized/live bytes, 2 ops)
 INFO [FlushWriter:4] 2011-09-20 15:00:01,177 Memtable.java (line 254) Completed flushing /hadoop2/system/LocationInfo-g-2-Data.db (176 bytes)
 INFO [main] 2011-09-20 15:00:01,179 StorageService.java (line 520) Joining: sleeping 30000 ms for pending range setup
 INFO [main] 2011-09-20 15:00:31,186 StorageService.java (line 520) Bootstrapping
 INFO [CompactionExecutor:20] 2011-09-20 15:00:31,346 SSTableReader.java (line 158) Opening /hadoop3/cfs/inode-g-1
 INFO [CompactionExecutor:21] 2011-09-20 15:00:31,393 SSTableReader.java (line 158) Opening /hadoop1/cfs/inode-g-2
 INFO [CompactionExecutor:19] 2011-09-20 15:00:31,469 SSTableReader.java (line 158) Opening /hadoop2/cfs/sblocks-g-1
 INFO [Thread-19] 2011-09-20 15:00:31,496 ColumnFamilyStore.java (line 373) Submitting index build of 706172656e745f70617468,70617468,73656e74696e656c, for data in SSTableReader(path='/hadoop3/cfs/inode-g-1-Data.db'), SSTableReader(path='/hadoop1/cfs/inode-g-2-Data.db')
 INFO [Thread-19] 2011-09-20 15:00:31,518 ColumnFamilyStore.java (line 1013) Enqueuing flush of Memtable-inode.parent_path@1615782385(470/587 serialized/live bytes, 10 ops)
 INFO [FlushWriter:5] 2011-09-20 15:00:31,518 Memtable.java (line 237) Writing Memtable-inode.parent_path@1615782385(470/587 serialized/live bytes, 10 ops)
 INFO [CompactionExecutor:18] 2011-09-20 15:00:31,547 SSTableReader.java (line 158) Opening /hadoop2/HiveMetaStore/MetaStore-g-1
 INFO [Thread-16] 2011-09-20 15:00:31,560 StreamInSession.java (line 167) Finished streaming session 88715448820813 from /10.13.0.103
 INFO [FlushWriter:5] 2011-09-20 15:00:31,662 Memtable.java (line 254) Completed flushing /hadoop3/cfs/inode.parent_path-g-1-Data.db (979 bytes)
 INFO [Thread-19] 2011-09-20 15:00:31,663 ColumnFamilyStore.java (line 1013) Enqueuing flush of Memtable-inode.path@1452604994(470/587 serialized/live bytes, 10 ops)


nodetool ring looks like this:

[root@hadoop-3 deploy]# nodetool -h localhost ring
Address         DC          Rack        Status State   Load            Owns    Token
                                                                               850...
10.13.0.102     Brisk       rack1       Up     Joining 105.08 KB       75.00%  425...
10.13.0.103     Brisk       rack1       Up     Normal  110.1 KB        25.00%  850...


nodetool netstats

[root@hadoop-2 deploy]# nodetool netstats  -h localhost
Mode: Bootstrapping
Not sending any streams.
 Nothing streaming from /10.13.0.103
Pool Name                    Active   Pending      Completed
Commands                        n/a         0             12
Responses                       n/a         0           2534

2011/9/21 Patricio Echagüe <patr...@datastax.com>

--
Mike Brauwerman
Data Team, Redfin