From user-return-30591-apmail-cassandra-user-archive=cassandra.apache.org@cassandra.apache.org Wed Dec 12 20:16:07 2012 Return-Path: X-Original-To: apmail-cassandra-user-archive@www.apache.org Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 8B501DCC0 for ; Wed, 12 Dec 2012 20:16:07 +0000 (UTC) Received: (qmail 54617 invoked by uid 500); 12 Dec 2012 20:16:04 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 54593 invoked by uid 500); 12 Dec 2012 20:16:04 -0000 Mailing-List: contact user-help@cassandra.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@cassandra.apache.org Delivered-To: mailing list user@cassandra.apache.org Received: (qmail 54585 invoked by uid 99); 12 Dec 2012 20:16:04 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 12 Dec 2012 20:16:04 +0000 X-ASF-Spam-Status: No, hits=1.3 required=5.0 tests=RCVD_IN_DNSWL_NONE,SPF_PASS,URI_HEX X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: local policy) Received: from [208.113.200.5] (HELO homiemail-a45.g.dreamhost.com) (208.113.200.5) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 12 Dec 2012 20:15:56 +0000 Received: from homiemail-a45.g.dreamhost.com (localhost [127.0.0.1]) by homiemail-a45.g.dreamhost.com (Postfix) with ESMTP id 6C6E348096 for ; Wed, 12 Dec 2012 12:15:52 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha1; c=relaxed; d=thelastpickle.com; h= content-type:mime-version:subject:from:in-reply-to:date :content-transfer-encoding:message-id:references:to; s= thelastpickle.com; bh=5vdX2eNDi7aZ7J7uFkLbLYA7UoI=; b=ignZzK4krB WTwJ/4lmFLbbDCnq6+WwqoDHEorj5t0cQm7o1/pnQMbhmLAFmRLYx3Eb7nq3XkbY L17IGokasbmjutI3dAxVB89x1SOuqDq5O5uKqMmvl22vy5ohfN1Y/ssxxuHvWfIH RY6IKm3Z1NY9K5BzkPjHVgDZ1MNavAsIo= Received: from [192.168.2.13] (unknown [116.90.132.105]) (using TLSv1 with cipher AES128-SHA (128/128 bits)) (No client certificate requested) (Authenticated sender: aaron@thelastpickle.com) by homiemail-a45.g.dreamhost.com (Postfix) with ESMTPSA id 9720E4804F for ; Wed, 12 Dec 2012 12:15:51 -0800 (PST) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 6.2 \(1499\)) Subject: Re: Multiple Data Center shows very uneven load From: aaron morton In-Reply-To: <1355268235485-7584232.post@n2.nabble.com> Date: Thu, 13 Dec 2012 09:15:33 +1300 Content-Transfer-Encoding: quoted-printable Message-Id: References: <1355234434695-7584206.post@n2.nabble.com> <3EBEA264-9711-45E2-A1C9-715A7D592FF7@thelastpickle.com> <1355268235485-7584232.post@n2.nabble.com> To: user@cassandra.apache.org X-Mailer: Apple Mail (2.1499) X-Virus-Checked: Checked by ClamAV on apache.org > c:\SERVERS\apache-cassandra-1.1.6\bin>nodetool -h 11.111.111.1 ring > Starting NodeTool > Address DC Rack Status State Load =20= > Effective-Ownership Token >=20 > Token(bytes[6c03]) > 11.111.111.1 VA SVA Up Normal 1.44 GB =20= > 33.33% Token(bytes[6101]) > 22.222.22.2 LA SLA Up Normal 361.25 MB =20= > 33.33% Token(bytes[6103]) > 33.333.333.3 VA SVA Up Normal 357.01 MB =20= > 33.33% Token(bytes[6601]) > 44.444.44.4 LA SLA Up Normal 380.05 MB =20= > 33.33% Token(bytes[6603]) > 55.555.555.5 VA SNY Up Normal 498.43 MB =20= > 33.33% Token(bytes[6c01]) > 66.666.666.6 LA SNY Up Normal 512.21 MB =20= > 33.33% Token(bytes[6c03]) >=20 > 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).=20 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.=20 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.=20 > 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).=20 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.=20 If this is still a test the easiest thing to do is nuke it and start = again.=20 Cheers ----------------- Aaron Morton Freelance Cassandra Developer New Zealand @aaronmorton http://www.thelastpickle.com On 12/12/2012, at 12:23 PM, Sergey Olefir wrote: > aaron morton wrote >> Hi Sergey, I think you have forgotten to include some information in = your >> email.=20 >=20 > 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)> >=20 > 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):=20 >=20 > c:\SERVERS\apache-cassandra-1.1.6\bin>nodetool -h 11.111.111.1 ring > Starting NodeTool > Address DC Rack Status State Load =20= > Effective-Ownership Token >=20 > Token(bytes[6c03]) > 11.111.111.1 VA SVA Up Normal 1.44 GB =20= > 33.33% Token(bytes[6101]) > 22.222.22.2 LA SLA Up Normal 361.25 MB =20= > 33.33% Token(bytes[6103]) > 33.333.333.3 VA SVA Up Normal 357.01 MB =20= > 33.33% Token(bytes[6601]) > 44.444.44.4 LA SLA Up Normal 380.05 MB =20= > 33.33% Token(bytes[6603]) > 55.555.555.5 VA SNY Up Normal 498.43 MB =20= > 33.33% Token(bytes[6c01]) > 66.666.666.6 LA SNY Up Normal 512.21 MB =20= > 33.33% Token(bytes[6c03]) >=20 > 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).=20 >=20 > However I then proceeded to drop the single keyspace that was on this > cluster and I got this:=20 >=20 > 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 =20 > Token >=20 > Token(bytes[6c03]) > 11.111.111.1 VA SVA Up Normal 767.16 MB =20= > 16.67% Token(bytes[6101]) > 22.222.22.2 LA SLA Up Normal 35.19 KB =20= > 16.67% Token(bytes[6103]) > 33.333.333.3 VA SVA Up Normal 52.91 KB =20= > 16.67% Token(bytes[6601]) > 44.444.44.4 LA SLA Up Normal 50.09 KB =20= > 16.67% Token(bytes[6603]) > 55.555.555.5 VA SNY Up Normal 50.12 KB =20= > 16.67% Token(bytes[6c01]) > 66.666.666.6 LA SNY Up Normal 44.23 KB =20= > 16.67% Token(bytes[6c03]) >=20 >=20 > 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).=20 >=20 > Here's info from the filesystem on that node:=20 > cassa1-1:/var/log/cassandra# du -k /spool1/cassandra/data/1.1/ > 375372=20 > = /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily/sna= pshots/1355222054452-marquisColumnFamily > 375376=20 > = /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily/sna= pshots > 375380=20 > /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/ >=20 >=20 > cassa1-1:/var/log/cassandra# ls -la > = /spool1/cassandra/data/1.1/rainmanLoadTestKeyspace/marquisColumnFamily/sna= pshots/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 >=20 >=20 >=20 > 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 >=20 > 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/ >=20 > 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 >=20 >=20 > 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 >=20 >=20 > And here is syslog from Cassandra when I restarted 11.111.111.1 node:=20= > 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-cli= entutil-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-cl= i-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/lib= thrift-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:./../l= ib/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 >=20 > 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_colu= mnfamilies-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-HintsColumnFami= ly-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-HintsColumnFami= ly-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 >=20 >=20 >=20 > 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=3D1355223438516, > position=3D0) > 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-D= ata.db > (80 bytes) for commitlog position = ReplayPosition(segmentId=3D1355223438516, > position=3D363) > 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-D= ata.db > (149 bytes) for commitlog position = ReplayPosition(segmentId=3D1355223438516, > position=3D530) > 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=3D'/spool1/cassandra/data/1.1/system/LocationInfo/syst= em-LocationInfo-hf-19-Data.db'), > = SSTableReader(path=3D'/spool1/cassandra/data/1.1/system/LocationInfo/syste= m-LocationInfo-hf-17-Data.db'), > = SSTableReader(path=3D'/spool1/cassandra/data/1.1/system/LocationInfo/syste= m-LocationInfo-hf-20-Data.db'), > = SSTableReader(path=3D'/spool1/cassandra/data/1.1/system/LocationInfo/syste= m-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,].=20 > 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-D= ata.db > (75 bytes) for commitlog position = ReplayPosition(segmentId=3D1355223438516, > position=3D614) > 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 >=20 >=20 > I'd much appreciate if someone can provide some insight as to what is = going > on and what (if anything) needs to be done.=20 >=20 > Best regards,=20 > Sergey >=20 >=20 >=20 > -- > 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.