incubator-cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From aaron morton <aa...@thelastpickle.com>
Subject Re: Multiple Data Center shows very uneven load
Date Wed, 12 Dec 2012 20:15:33 GMT
> c:\SERVERS\apache-cassandra-1.1.6\bin>nodetool -h 11.111.111.1 ring
> Starting NodeTool
> Address         DC          Rack        Status State   Load           
> Effective-Ownership Token
> 
> Token(bytes[6c03])
> 11.111.111.1    VA          SVA         Up     Normal  1.44 GB        
> 33.33%              Token(bytes[6101])
> 22.222.22.2     LA          SLA         Up     Normal  361.25 MB      
> 33.33%              Token(bytes[6103])
> 33.333.333.3    VA          SVA         Up     Normal  357.01 MB      
> 33.33%              Token(bytes[6601])
> 44.444.44.4     LA          SLA         Up     Normal  380.05 MB      
> 33.33%              Token(bytes[6603])
> 55.555.555.5    VA          SNY         Up     Normal  498.43 MB      
> 33.33%              Token(bytes[6c01])
> 66.666.666.6    LA          SNY         Up     Normal  512.21 MB      
> 33.33%              Token(bytes[6c03])
> 
> This already shows uneven load despite the fact that nodes actually hold the
> same amount of data (according to effective-ownership and application design
> / token values). 

Assuming you are using the Byte Ordered Partitioner. If so it's up to you to ensure your rows
are evenly distributed between the nodes. 

Node 11.111.111.1 is responsible for a very wide range of tokens. I would suggest using the
Random Partitioner unless you have a *very good* reason not to. I would go as far to say if
you are using Cassandra for the firs time avoid the BOP until you have a better understanding
of how Cassandra works. 


> Why 11.111.111.1 still has 700+ MB of data? I tried nodetool repair,
> nodetool cleanup, and node restart (for 11.111.111.1) -- none of that helped
> (it still had those 700+ MB of data). 
Glancing at the logs it could be Hints or commit log replaying.
Use nodetool cfstats to see which CF's are on the node and what their size is. 

If this is still a test the easiest thing to do is nuke it and start again. 

Cheers


-----------------
Aaron Morton
Freelance Cassandra Developer
New Zealand

@aaronmorton
http://www.thelastpickle.com

On 12/12/2012, at 12:23 PM, Sergey Olefir <solf.lists@gmail.com> wrote:

> aaron morton wrote
>> Hi Sergey, I think you have forgotten to include some information in your
>> email. 
> 
> Ah, I used Nable's markup and it seems to have eaten text somehow. Anyway,
> here it is without formatting (much harder to read though)>
> 
> I have a very similar issue myself and would love to know what (if anything)
> needs to be done (I'm using 1.1.6 at the moment). After stress-test (maximum
> load), I had the following on my nodes (every IP is changed to the
> corresponding fake number): 
> 
> c:\SERVERS\apache-cassandra-1.1.6\bin>nodetool -h 11.111.111.1 ring
> Starting NodeTool
> Address         DC          Rack        Status State   Load           
> Effective-Ownership Token
> 
> Token(bytes[6c03])
> 11.111.111.1    VA          SVA         Up     Normal  1.44 GB        
> 33.33%              Token(bytes[6101])
> 22.222.22.2     LA          SLA         Up     Normal  361.25 MB      
> 33.33%              Token(bytes[6103])
> 33.333.333.3    VA          SVA         Up     Normal  357.01 MB      
> 33.33%              Token(bytes[6601])
> 44.444.44.4     LA          SLA         Up     Normal  380.05 MB      
> 33.33%              Token(bytes[6603])
> 55.555.555.5    VA          SNY         Up     Normal  498.43 MB      
> 33.33%              Token(bytes[6c01])
> 66.666.666.6    LA          SNY         Up     Normal  512.21 MB      
> 33.33%              Token(bytes[6c03])
> 
> This already shows uneven load despite the fact that nodes actually hold the
> same amount of data (according to effective-ownership and application design
> / token values). 
> 
> However I then proceeded to drop the single keyspace that was on this
> cluster and I got this: 
> 
> c:\SERVERS\apache-cassandra-1.1.6\bin>nodetool -h 11.111.111.1 ring
> Starting NodeTool
> Note: Ownership information does not include topology, please specify a
> keyspace.
> Address         DC          Rack        Status State   Load            Owns         
     
> Token
> 
> Token(bytes[6c03])
> 11.111.111.1    VA          SVA         Up     Normal  767.16 MB      
> 16.67%              Token(bytes[6101])
> 22.222.22.2     LA          SLA         Up     Normal  35.19 KB       
> 16.67%              Token(bytes[6103])
> 33.333.333.3    VA          SVA         Up     Normal  52.91 KB       
> 16.67%              Token(bytes[6601])
> 44.444.44.4     LA          SLA         Up     Normal  50.09 KB       
> 16.67%              Token(bytes[6603])
> 55.555.555.5    VA          SNY         Up     Normal  50.12 KB       
> 16.67%              Token(bytes[6c01])
> 66.666.666.6    LA          SNY         Up     Normal  44.23 KB       
> 16.67%              Token(bytes[6c03])
> 
> 
> Why 11.111.111.1 still has 700+ MB of data? I tried nodetool repair,
> nodetool cleanup, and node restart (for 11.111.111.1) -- none of that helped
> (it still had those 700+ MB of data). 
> 
> Here's info from the filesystem on that node: 
> cassa1-1:/var/log/cassandra# du -k /spool1/cassandra/data/1.1/
> 375372 
> /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily/snapshots/1355222054452-marquisColumnFamily
> 375376 
> /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily/snapshots
> 375380 
> /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily
> 375384  /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace
> 4       /spool1/cassandra/data/1.1/system/Versions
> 52      /spool1/cassandra/data/1.1/system/schema_columns
> 4       /spool1/cassandra/data/1.1/system/Schema
> 28      /spool1/cassandra/data/1.1/system/NodeIdInfo
> 4       /spool1/cassandra/data/1.1/system/Migrations
> 28      /spool1/cassandra/data/1.1/system/schema_keyspaces
> 28      /spool1/cassandra/data/1.1/system/schema_columnfamilies
> 786348  /spool1/cassandra/data/1.1/system/HintsColumnFamily
> 52      /spool1/cassandra/data/1.1/system/LocationInfo
> 4       /spool1/cassandra/data/1.1/system/IndexInfo
> 786556  /spool1/cassandra/data/1.1/system
> 1161944 /spool1/cassandra/data/1.1/
> 
> 
> cassa1-1:/var/log/cassandra# ls -la
> /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily/snapshots/1355222054452-marquisColumnFamily/
> total 375376
> drwxr-xr-x 2 root root      4096 Dec 11 10:34 .
> drwxr-xr-x 3 root root      4096 Dec 11 10:34 ..
> -rw-r--r-- 1 root root    103366 Dec 10 18:11
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-149-CompressionInfo.db
> -rw-r--r-- 1 root root 162034489 Dec 10 18:11
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-149-Data.db
> -rw-r--r-- 1 root root   3860656 Dec 10 18:11
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-149-Filter.db
> -rw-r--r-- 1 root root  39377544 Dec 10 18:11
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-149-Index.db
> -rw-r--r-- 1 root root      4361 Dec 10 18:11
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-149-Statistics.db
> -rw-r--r-- 1 root root     38462 Dec 10 18:56
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-186-CompressionInfo.db
> -rw-r--r-- 1 root root  54668322 Dec 10 18:56
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-186-Data.db
> -rw-r--r-- 1 root root   1783456 Dec 10 18:56
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-186-Filter.db
> -rw-r--r-- 1 root root  32613827 Dec 10 18:56
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-186-Index.db
> -rw-r--r-- 1 root root      4361 Dec 10 18:56
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-186-Statistics.db
> -rw-r--r-- 1 root root     26446 Dec 10 19:17
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-203-CompressionInfo.db
> -rw-r--r-- 1 root root  34201519 Dec 10 19:17
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-203-Data.db
> -rw-r--r-- 1 root root   1603216 Dec 10 19:17
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-203-Filter.db
> -rw-r--r-- 1 root root  27858083 Dec 10 19:17
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-203-Index.db
> -rw-r--r-- 1 root root      4361 Dec 10 19:17
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-203-Statistics.db
> -rw-r--r-- 1 root root      4542 Dec 10 19:18
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-204-CompressionInfo.db
> -rw-r--r-- 1 root root   4742122 Dec 10 19:18
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-204-Data.db
> -rw-r--r-- 1 root root    217416 Dec 10 19:18
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-204-Filter.db
> -rw-r--r-- 1 root root   7155100 Dec 10 19:18
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-204-Index.db
> -rw-r--r-- 1 root root      4345 Dec 10 19:18
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-204-Statistics.db
> -rw-r--r-- 1 root root      5094 Dec 11 10:34
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-205-CompressionInfo.db
> -rw-r--r-- 1 root root   5340189 Dec 11 10:34
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-205-Data.db
> -rw-r--r-- 1 root root    241536 Dec 11 10:34
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-205-Filter.db
> -rw-r--r-- 1 root root   7963399 Dec 11 10:34
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-205-Index.db
> -rw-r--r-- 1 root root      4345 Dec 11 10:34
> rainmanLoadTestKeyspace-marquisColumnFamily-hf-205-Statistics.db
> 
> 
> 
> cassa1-1:/var/log/cassandra# ls -la
> /spool1/cassandra/data/1.1/system/HintsColumnFamily/
> total 786352
> drwxr-xr-x  2 root root      4096 Dec 11 10:45 .
> drwxr-xr-x 12 root root      4096 Dec 10 15:33 ..
> -rw-r--r--  1 root root 757534484 Dec 11 10:34
> system-HintsColumnFamily-hf-31-Data.db
> -rw-r--r--  1 root root        80 Dec 11 10:34
> system-HintsColumnFamily-hf-31-Digest.sha1
> -rw-r--r--  1 root root      1456 Dec 11 10:34
> system-HintsColumnFamily-hf-31-Filter.db
> -rw-r--r--  1 root root        12 Dec 11 10:34
> system-HintsColumnFamily-hf-31-Index.db
> -rw-r--r--  1 root root      4357 Dec 11 10:34
> system-HintsColumnFamily-hf-31-Statistics.db
> -rw-r--r--  1 root root  46841360 Dec 11 10:45
> system-HintsColumnFamily-hf-32-Data.db
> -rw-r--r--  1 root root        80 Dec 11 10:45
> system-HintsColumnFamily-hf-32-Digest.sha1
> -rw-r--r--  1 root root        16 Dec 11 10:45
> system-HintsColumnFamily-hf-32-Filter.db
> -rw-r--r--  1 root root        12 Dec 11 10:45
> system-HintsColumnFamily-hf-32-Index.db
> -rw-r--r--  1 root root      4345 Dec 11 10:45
> system-HintsColumnFamily-hf-32-Statistics.db
> 
> cassa1-1:/var/log/cassandra# du -k /var/lib/cassandra/1.1/
> 754496  /var/lib/cassandra/1.1/commitlog
> 119748  /var/lib/cassandra/1.1/saved_caches
> 874248  /var/lib/cassandra/1.1/
> 
> cassa1-1:/var/log/cassandra# ls -la /var/lib/cassandra/1.1/commitlog/
> total 754500
> drwxr-xr-x 2 root root     4096 Dec 11 10:34 .
> drwxr-xr-x 4 root root     4096 Dec 10 15:33 ..
> -rw-r--r-- 1 root root 33554432 Dec 10 15:47 CommitLog-1355153616861.log
> -rw-r--r-- 1 root root 33554432 Dec 11 10:34 CommitLog-1355153617410.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:12 CommitLog-1355153617411.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:13 CommitLog-1355153617412.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:13 CommitLog-1355153617413.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:13 CommitLog-1355153617414.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617415.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617416.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617417.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617418.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617419.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617420.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617421.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:15 CommitLog-1355153617422.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:17 CommitLog-1355153617423.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:17 CommitLog-1355153617424.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:17 CommitLog-1355153617425.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:18 CommitLog-1355153617426.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:18 CommitLog-1355153617427.log
> -rw-r--r-- 1 root root 33554432 Dec 10 19:18 CommitLog-1355153617428.log
> -rw-r--r-- 1 root root 33554432 Dec 11 10:34 CommitLog-1355153617429.log
> -rw-r--r-- 1 root root 33554432 Dec 11 10:34 CommitLog-1355153617430.log
> -rw-r--r-- 1 root root 33554432 Dec 11 10:34 CommitLog-1355153617431.log
> 
> 
> cassa1-1:/var/log/cassandra# ls -la /var/lib/cassandra/1.1/saved_caches/
> total 119752
> drwxr-xr-x 2 root root      4096 Dec 11 07:33 .
> drwxr-xr-x 4 root root      4096 Dec 10 15:33 ..
> -rw-r--r-- 1 root root 122479231 Dec 11 07:33
> rainmanLoadTestKeyspace-marquisColumnFamily-KeyCache
> -rw-r--r-- 1 root root        12 Dec 11 07:33
> system-HintsColumnFamily-KeyCache
> -rw-r--r-- 1 root root         5 Dec 11 07:33 system-LocationInfo-KeyCache
> 
> 
> And here is syslog from Cassandra when I restarted 11.111.111.1 node: 
> cassa1-1:/var/log/cassandra# tail -f system.log
> INFO [StorageServiceShutdownHook] 2012-12-11 10:57:02,606
> MessagingService.java (line 534) Waiting for messaging service to quiesce
> INFO [ACCEPT-localhost/11.111.111.1] 2012-12-11 10:57:02,607
> MessagingService.java (line 690) MessagingService shutting down server
> thread.
> INFO [main] 2012-12-11 10:57:17,154 AbstractCassandraDaemon.java (line 101)
> Logging initialized
> INFO [main] 2012-12-11 10:57:17,164 AbstractCassandraDaemon.java (line 122)
> JVM vendor/version: Java HotSpot(TM) 64-Bit Server VM/1.6.0_26
> INFO [main] 2012-12-11 10:57:17,164 AbstractCassandraDaemon.java (line 123)
> Heap size: 4211081216/4211081216
> INFO [main] 2012-12-11 10:57:17,165 AbstractCassandraDaemon.java (line 124)
> Classpath:
> ./../conf:./../build/classes/main:./../build/classes/thrift:./../lib/antlr-3.2.jar:./../lib/apache-cassandra-1.1.6.jar:./../lib/apache-cassandra-clientutil-1.1.6.jar:./../lib/apache-cassandra-thrift-1.1.6.jar:./../lib/avro-1.4.0-fixes.jar:./../lib/avro-1.4.0-sources-fixes.jar:./../lib/commons-cli-1.1.jar:./../lib/commons-codec-1.2.jar:./../lib/commons-lang-2.4.jar:./../lib/compress-lzf-0.8.4.jar:./../lib/concurrentlinkedhashmap-lru-1.3.jar:./../lib/guava-r08.jar:./../lib/high-scale-lib-1.1.2.jar:./../lib/jackson-core-asl-1.9.2.jar:./../lib/jackson-mapper-asl-1.9.2.jar:./../lib/jamm-0.2.5.jar:./../lib/jline-0.9.94.jar:./../lib/json-simple-1.1.jar:./../lib/libthrift-0.7.0.jar:./../lib/log4j-1.2.16.jar:./../lib/metrics-core-2.0.3.jar:./../lib/servlet-api-2.5-20081211.jar:./../lib/slf4j-api-1.6.1.jar:./../lib/slf4j-log4j12-1.6.1.jar:./../lib/snakeyaml-1.6.jar:./../lib/snappy-java-1.0.4.1.jar:./../lib/snaptree-0.1.jar:./../lib/jamm-0.2.5.jar
> INFO [main] 2012-12-11 10:57:17,167 CLibrary.java (line 62) JNA not found.
> Native methods will be disabled.
> INFO [main] 2012-12-11 10:57:17,178 DatabaseDescriptor.java (line 124)
> Loading settings from file:/opt/apache-cassandra-1.1.6/conf/cassandra.yaml
> INFO [main] 2012-12-11 10:57:17,317 DatabaseDescriptor.java (line 183)
> DiskAccessMode 'auto' determined to be mmap, indexAccessMode is mmap
> INFO [main] 2012-12-11 10:57:17,651 DatabaseDescriptor.java (line 249)
> Global memtable threshold is enabled at 1338MB
> 
> INFO [main] 2012-12-11 10:57:18,102 CacheService.java (line 96)
> Initializing key cache with capacity of 100 MBs.
> INFO [main] 2012-12-11 10:57:18,114 CacheService.java (line 107) Scheduling
> key cache save to each 14400 seconds (going to save all keys).
> INFO [main] 2012-12-11 10:57:18,115 CacheService.java (line 121)
> Initializing row cache with capacity of 0 MBs and provider
> org.apache.cassandra.cache.SerializingCacheProvider
> INFO [main] 2012-12-11 10:57:18,118 CacheService.java (line 133) Scheduling
> row cache save to each 0 seconds (going to save all keys).
> INFO [SSTableBatchOpen:1] 2012-12-11 10:57:18,211 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/schema_columnfamilies/system-schema_columnfamilies-hf-5
> (73 bytes)
> INFO [SSTableBatchOpen:1] 2012-12-11 10:57:18,267 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/NodeIdInfo/system-NodeIdInfo-hf-1 (90
> bytes)
> INFO [SSTableBatchOpen:1] 2012-12-11 10:57:18,283 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/schema_columns/system-schema_columns-hf-1
> (73 bytes)
> INFO [SSTableBatchOpen:2] 2012-12-11 10:57:18,283 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/schema_columns/system-schema_columns-hf-2
> (73 bytes)
> INFO [SSTableBatchOpen:1] 2012-12-11 10:57:18,291 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/schema_keyspaces/system-schema_keyspaces-hf-5
> (73 bytes)
> INFO [main] 2012-12-11 10:57:18,294 AutoSavingCache.java (line 108) reading
> saved cache /var/lib/cassandra/1.1/saved_caches/system-LocationInfo-KeyCache
> INFO [SSTableBatchOpen:1] 2012-12-11 10:57:18,296 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-18 (75
> bytes)
> INFO [SSTableBatchOpen:2] 2012-12-11 10:57:18,296 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-17
> (659 bytes)
> INFO [main] 2012-12-11 10:57:18,309 AutoSavingCache.java (line 108) reading
> saved cache
> /var/lib/cassandra/1.1/saved_caches/system-HintsColumnFamily-KeyCache
> INFO [SSTableBatchOpen:1] 2012-12-11 10:57:18,311 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/HintsColumnFamily/system-HintsColumnFamily-hf-31
> (757534484 bytes)
> INFO [SSTableBatchOpen:2] 2012-12-11 10:57:18,311 SSTableReader.java (line
> 169) Opening
> /spool1/cassandra/data/1.1/system/HintsColumnFamily/system-HintsColumnFamily-hf-32
> (46841360 bytes)
> INFO [main] 2012-12-11 10:57:18,384 AbstractCassandraDaemon.java (line 216)
> completed pre-loading (1 keys) key cache.
> INFO [main] 2012-12-11 10:57:18,528 CommitLog.java (line 129) Replaying
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153616861.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617411.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617412.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617414.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617413.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617416.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617418.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617415.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617417.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617422.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617421.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617419.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617420.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617424.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617423.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617425.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617426.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617427.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617428.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617431.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617410.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617429.log,
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617430.log
> INFO [main] 2012-12-11 10:57:18,532 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153616861.log
> 
> 
> 
> INFO [main] 2012-12-11 10:57:19,216 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153616861.log
> INFO [main] 2012-12-11 10:57:19,216 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617411.log
> INFO [main] 2012-12-11 10:57:19,216 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617411.log
> INFO [main] 2012-12-11 10:57:19,217 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617412.log
> INFO [main] 2012-12-11 10:57:19,217 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617412.log
> INFO [main] 2012-12-11 10:57:19,217 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617414.log
> INFO [main] 2012-12-11 10:57:19,218 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617414.log
> INFO [main] 2012-12-11 10:57:19,218 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617413.log
> INFO [main] 2012-12-11 10:57:19,218 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617413.log
> INFO [main] 2012-12-11 10:57:19,218 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617416.log
> INFO [main] 2012-12-11 10:57:19,219 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617416.log
> INFO [main] 2012-12-11 10:57:19,219 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617418.log
> INFO [main] 2012-12-11 10:57:19,219 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617418.log
> INFO [main] 2012-12-11 10:57:19,220 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617415.log
> INFO [main] 2012-12-11 10:57:19,220 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617415.log
> INFO [main] 2012-12-11 10:57:19,220 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617417.log
> INFO [main] 2012-12-11 10:57:19,220 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617417.log
> INFO [main] 2012-12-11 10:57:19,221 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617422.log
> INFO [main] 2012-12-11 10:57:19,221 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617422.log
> INFO [main] 2012-12-11 10:57:19,221 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617421.log
> INFO [main] 2012-12-11 10:57:19,222 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617421.log
> INFO [main] 2012-12-11 10:57:19,222 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617419.log
> INFO [main] 2012-12-11 10:57:19,222 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617419.log
> INFO [main] 2012-12-11 10:57:19,222 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617420.log
> INFO [main] 2012-12-11 10:57:19,223 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617420.log
> INFO [main] 2012-12-11 10:57:19,223 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617424.log
> INFO [main] 2012-12-11 10:57:19,223 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617424.log
> INFO [main] 2012-12-11 10:57:19,223 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617423.log
> INFO [main] 2012-12-11 10:57:19,224 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617423.log
> INFO [main] 2012-12-11 10:57:19,224 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617425.log
> INFO [main] 2012-12-11 10:57:19,224 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617425.log
> INFO [main] 2012-12-11 10:57:19,225 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617426.log
> INFO [main] 2012-12-11 10:57:19,225 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617426.log
> INFO [main] 2012-12-11 10:57:19,225 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617427.log
> INFO [main] 2012-12-11 10:57:19,225 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617427.log
> INFO [main] 2012-12-11 10:57:19,226 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617428.log
> INFO [main] 2012-12-11 10:57:19,226 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617428.log
> INFO [main] 2012-12-11 10:57:19,226 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617431.log
> INFO [main] 2012-12-11 10:57:19,226 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617431.log
> INFO [main] 2012-12-11 10:57:19,227 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617410.log
> INFO [main] 2012-12-11 10:57:19,272 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617410.log
> INFO [main] 2012-12-11 10:57:19,272 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617429.log
> INFO [main] 2012-12-11 10:57:19,273 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617429.log
> INFO [main] 2012-12-11 10:57:19,273 CommitLogReplayer.java (line 119)
> Replaying /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617430.log
> INFO [main] 2012-12-11 10:57:19,274 CommitLogReplayer.java (line 272)
> Finished reading
> /var/lib/cassandra/1.1/commitlog/CommitLog-1355153617430.log
> INFO [main] 2012-12-11 10:57:19,274 CommitLogReplayer.java (line 103)
> Skipped 125113 mutations from unknown (probably removed) CF with id 1000
> INFO [main] 2012-12-11 10:57:19,277 ColumnFamilyStore.java (line 659)
> Enqueuing flush of Memtable-Versions@606971302(83/103 serialized/live bytes,
> 3 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,284 Memtable.java (line 264)
> Writing Memtable-Versions@606971302(83/103 serialized/live bytes, 3 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,311 Memtable.java (line 305)
> Completed flushing
> /spool1/cassandra/data/1.1/system/Versions/system-Versions-hf-1-Data.db (247
> bytes) for commitlog position ReplayPosition(segmentId=1355223438516,
> position=0)
> INFO [main] 2012-12-11 10:57:19,318 CommitLog.java (line 131) Log replay
> complete, 3 replayed mutations
> INFO [main] 2012-12-11 10:57:19,378 StorageService.java (line 423)
> Cassandra version: 1.1.6
> INFO [main] 2012-12-11 10:57:19,378 StorageService.java (line 424) Thrift
> API version: 19.32.0
> INFO [main] 2012-12-11 10:57:19,380 StorageService.java (line 425) CQL
> supported versions: 2.0.0,3.0.0-beta1 (default: 2.0.0)
> INFO [main] 2012-12-11 10:57:19,442 StorageService.java (line 455) Loading
> persisted ring state
> INFO [main] 2012-12-11 10:57:19,460 StorageService.java (line 536) Starting
> up server gossip
> INFO [main] 2012-12-11 10:57:19,462 ColumnFamilyStore.java (line 659)
> Enqueuing flush of Memtable-LocationInfo@1667363742(29/36 serialized/live
> bytes, 1 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,462 Memtable.java (line 264)
> Writing Memtable-LocationInfo@1667363742(29/36 serialized/live bytes, 1 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,468 Memtable.java (line 305)
> Completed flushing
> /spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-19-Data.db
> (80 bytes) for commitlog position ReplayPosition(segmentId=1355223438516,
> position=363)
> INFO [main] 2012-12-11 10:57:19,486 MessagingService.java (line 284)
> Starting Messaging Service on port 7000
> INFO [main] 2012-12-11 10:57:19,492 StorageService.java (line 675) Using
> saved token Token(bytes[6101])
> INFO [main] 2012-12-11 10:57:19,494 ColumnFamilyStore.java (line 659)
> Enqueuing flush of Memtable-LocationInfo@2039421489(39/48 serialized/live
> bytes, 2 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,495 Memtable.java (line 264)
> Writing Memtable-LocationInfo@2039421489(39/48 serialized/live bytes, 2 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,500 Memtable.java (line 305)
> Completed flushing
> /spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-20-Data.db
> (149 bytes) for commitlog position ReplayPosition(segmentId=1355223438516,
> position=530)
> INFO [main] 2012-12-11 10:57:19,502 StorageService.java (line 1119) Node
> localhost/11.111.111.1 state jump to normal
> INFO [main] 2012-12-11 10:57:19,503 StorageService.java (line 687)
> Bootstrap/Replace/Move completed! Now serving reads.
> INFO [CompactionExecutor:3] 2012-12-11 10:57:19,541 CompactionTask.java
> (line 109) Compacting
> [SSTableReader(path='/spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-19-Data.db'),
> SSTableReader(path='/spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-17-Data.db'),
> SSTableReader(path='/spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-20-Data.db'),
> SSTableReader(path='/spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-18-Data.db')]
> INFO [main] 2012-12-11 10:57:19,563 CassandraDaemon.java (line 124) Binding
> thrift service to localhost/11.111.111.1:9160
> INFO [CompactionExecutor:3] 2012-12-11 10:57:19,564 CompactionTask.java
> (line 221) Compacted to
> [/spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-21-Data.db,].

> 963 to 680 (~70% of original) bytes for 4 keys at 0.032425MB/s.  Time: 20ms.
> INFO [main] 2012-12-11 10:57:19,566 CassandraDaemon.java (line 133) Using
> TFastFramedTransport with a max frame size of 15728640 bytes.
> INFO [main] 2012-12-11 10:57:19,569 CassandraDaemon.java (line 160) Using
> synchronous/threadpool thrift server on localhost/11.111.111.1 : 9160
> INFO [Thread-2] 2012-12-11 10:57:19,569 CassandraDaemon.java (line 212)
> Listening for thrift clients...
> INFO [GossipStage:1] 2012-12-11 10:57:19,606 Gossiper.java (line 848) Node
> /55.555.555.5 has restarted, now UP
> INFO [GossipStage:1] 2012-12-11 10:57:19,606 Gossiper.java (line 816)
> InetAddress /55.555.555.5 is now UP
> INFO [GossipStage:1] 2012-12-11 10:57:19,607 StorageService.java (line
> 1119) Node /55.555.555.5 state jump to normal
> INFO [HintedHandoff:1] 2012-12-11 10:57:19,607 HintedHandOffManager.java
> (line 296) Started hinted handoff for token: Token(bytes[6c01]) with IP:
> /55.555.555.5
> INFO [GossipStage:1] 2012-12-11 10:57:19,607 Gossiper.java (line 848) Node
> /44.444.44.4 has restarted, now UP
> INFO [HintedHandoff:1] 2012-12-11 10:57:19,608 HintedHandOffManager.java
> (line 392) Finished hinted handoff of 0 rows to endpoint /55.555.555.5
> INFO [GossipStage:1] 2012-12-11 10:57:19,608 Gossiper.java (line 816)
> InetAddress /44.444.44.4 is now UP
> INFO [HintedHandoff:1] 2012-12-11 10:57:19,608 HintedHandOffManager.java
> (line 296) Started hinted handoff for token: Token(bytes[6603]) with IP:
> /44.444.44.4
> INFO [GossipStage:1] 2012-12-11 10:57:19,608 StorageService.java (line
> 1119) Node /44.444.44.4 state jump to normal
> INFO [GossipStage:1] 2012-12-11 10:57:19,609 Gossiper.java (line 848) Node
> /22.222.22.2 has restarted, now UP
> INFO [HintedHandoff:1] 2012-12-11 10:57:19,609 HintedHandOffManager.java
> (line 392) Finished hinted handoff of 0 rows to endpoint /44.444.44.4
> INFO [GossipStage:1] 2012-12-11 10:57:19,609 Gossiper.java (line 816)
> InetAddress /22.222.22.2 is now UP
> INFO [HintedHandoff:1] 2012-12-11 10:57:19,609 HintedHandOffManager.java
> (line 296) Started hinted handoff for token: Token(bytes[6103]) with IP:
> /22.222.22.2
> INFO [GossipStage:1] 2012-12-11 10:57:19,609 StorageService.java (line
> 1119) Node /22.222.22.2 state jump to normal
> INFO [GossipStage:1] 2012-12-11 10:57:19,610 Gossiper.java (line 848) Node
> /66.666.666.6 has restarted, now UP
> INFO [GossipStage:1] 2012-12-11 10:57:19,610 Gossiper.java (line 816)
> InetAddress /66.666.666.6 is now UP
> INFO [GossipStage:1] 2012-12-11 10:57:19,611 StorageService.java (line
> 1119) Node /66.666.666.6 state jump to normal
> INFO [GossipStage:1] 2012-12-11 10:57:19,612 ColumnFamilyStore.java (line
> 659) Enqueuing flush of Memtable-LocationInfo@133441329(21/26
> serialized/live bytes, 1 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,612 Memtable.java (line 264)
> Writing Memtable-LocationInfo@133441329(21/26 serialized/live bytes, 1 ops)
> INFO [FlushWriter:1] 2012-12-11 10:57:19,617 Memtable.java (line 305)
> Completed flushing
> /spool1/cassandra/data/1.1/system/LocationInfo/system-LocationInfo-hf-22-Data.db
> (75 bytes) for commitlog position ReplayPosition(segmentId=1355223438516,
> position=614)
> INFO [GossipStage:1] 2012-12-11 10:57:19,618 Gossiper.java (line 848) Node
> /33.333.333.3 has restarted, now UP
> INFO [GossipStage:1] 2012-12-11 10:57:19,618 Gossiper.java (line 816)
> InetAddress /33.333.333.3 is now UP
> INFO [GossipStage:1] 2012-12-11 10:57:19,619 StorageService.java (line
> 1119) Node /33.333.333.3 state jump to normal
> INFO [HintedHandoff:1] 2012-12-11 10:57:27,258 HintedHandOffManager.java
> (line 392) Finished hinted handoff of 0 rows to endpoint /22.222.22.2
> INFO [HintedHandoff:1] 2012-12-11 10:57:27,258 HintedHandOffManager.java
> (line 296) Started hinted handoff for token: Token(bytes[6c03]) with IP:
> /66.666.666.6
> INFO [HintedHandoff:1] 2012-12-11 10:57:27,259 HintedHandOffManager.java
> (line 392) Finished hinted handoff of 0 rows to endpoint /66.666.666.6
> INFO [HintedHandoff:1] 2012-12-11 10:57:27,259 HintedHandOffManager.java
> (line 296) Started hinted handoff for token: Token(bytes[6601]) with IP:
> /33.333.333.3
> INFO [HintedHandoff:1] 2012-12-11 10:57:27,260 HintedHandOffManager.java
> (line 392) Finished hinted handoff of 0 rows to endpoint /33.333.333.3
> 
> 
> I'd much appreciate if someone can provide some insight as to what is going
> on and what (if anything) needs to be done. 
> 
> Best regards, 
> Sergey
> 
> 
> 
> --
> View this message in context: http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Multiple-Data-Center-shows-very-uneven-load-tp7584197p7584232.html
> Sent from the cassandra-user@incubator.apache.org mailing list archive at Nabble.com.


Mime
View raw message