incubator-cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Sergey Olefir <solf.li...@gmail.com>
Subject Re: Multiple Data Center shows very uneven load
Date Wed, 12 Dec 2012 20:48:16 GMT
I do have a (good?) reason for ByteOrderedPartitioner - I need to be able to
do range queries. At the same time I'm aware of the need to balance the
cluster - so I'm hashing my keys and prefixing them with latin letters from
a to p (16 in total) - hence the tokens I'm using.

Based on my experiments I also think that "effective ownership" as reported
by nodetool is accurate - so it seems this cluster is perfectly balanced.

What I'm worrying about here is the fact that the load on the cluster is
very uneven even after a short test and it doesn't get better when cluster
is idle. Even more worryingly it doesn't fix itself after I dropped the only
keyspace that was ever on this cluster. So I'm afraid that some data is
getting orphaned - and it could become a real problem in production.

I'd love some kind of confirmation one way or another - is this something I
need to worry about or will it fix itself somehow over time?

P.S. I actually had a repeat performance under another test - hugely uneven
data load and data that won't go away even after keyspace drop.


aaron morton wrote
>> 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 &lt;

> solf.lists@

> &gt; 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@.apache

>  mailing list archive at Nabble.com.





--
View this message in context: http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Multiple-Data-Center-shows-very-uneven-load-tp7584197p7584254.html
Sent from the cassandra-user@incubator.apache.org mailing list archive at Nabble.com.

Mime
View raw message