Return-Path: X-Original-To: apmail-cassandra-commits-archive@www.apache.org Delivered-To: apmail-cassandra-commits-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 5838DE5FF for ; Fri, 11 Jan 2013 17:04:15 +0000 (UTC) Received: (qmail 58722 invoked by uid 500); 11 Jan 2013 17:04:13 -0000 Delivered-To: apmail-cassandra-commits-archive@cassandra.apache.org Received: (qmail 58656 invoked by uid 500); 11 Jan 2013 17:04:13 -0000 Mailing-List: contact commits-help@cassandra.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cassandra.apache.org Delivered-To: mailing list commits@cassandra.apache.org Received: (qmail 58597 invoked by uid 99); 11 Jan 2013 17:04:13 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 11 Jan 2013 17:04:13 +0000 Date: Fri, 11 Jan 2013 17:04:13 +0000 (UTC) From: "Michael Kjellman (JIRA)" To: commits@cassandra.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Comment Edited] (CASSANDRA-5068) CLONE - Once a host has been hinted to, log messages for it repeat every 10 mins even if no hints are delivered MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CASSANDRA-5068?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13551246#comment-13551246 ] Michael Kjellman edited comment on CASSANDRA-5068 at 1/11/13 5:04 PM: ---------------------------------------------------------------------- a bit messy due to the repair log lines {code} tem-local-ib-671-Data.db'), SSTableReader(path='/data2/cassandra/system/local/system-local-ib-672-Data.db'), SSTableReader(path='/data2/cassandra/system/local/system-local-ib-670-Data.db')] INFO [CompactionExecutor:45] 2013-01-10 21:57:11,166 CompactionTask.java (line 267) Compacted 4 sstables to [/data/cassandra/system/local/system-local-ib-673,]. 975 bytes to 590 (~60% of original) in 214ms = 0.002629MB/s. 4 tot al rows, 1 unique. Row merge counts were {1:0, 2:0, 3:0, 4:1, } INFO [GossipStage:1] 2013-01-10 21:57:16,342 Gossiper.java (line 772) InetAddress /10.8.30.102 is now dead. INFO [GossipStage:1] 2013-01-10 21:59:01,958 Gossiper.java (line 790) Node /10.8.30.102 has restarted, now UP INFO [GossipStage:1] 2013-01-10 21:59:01,959 Gossiper.java (line 758) InetAddress /10.8.30.102 is now UP INFO [HintedHandoff:2] 2013-01-10 21:59:01,960 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 21:59:02,000 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-hints@479784922(38/69 serialized/live bytes, 46 ops) INFO [FlushWriter:9] 2013-01-10 21:59:02,001 Memtable.java (line 424) Writing Memtable-hints@479784922(38/69 serialized/live bytes, 46 ops) INFO [FlushWriter:9] 2013-01-10 21:59:02,195 Memtable.java (line 458) Completed flushing /data2/cassandra/system/hints/system-hints-ib-187-Data.db (85 bytes) for commitlog position ReplayPosition(segmentId=1357883369951, position =806355) INFO [CompactionExecutor:60] 2013-01-10 21:59:02,200 CompactionTask.java (line 120) Compacting [SSTableReader(path='/data2/cassandra/system/hints/system-hints-ib-187-Data.db'), SSTableReader(path='/data2/cassandra/system/hints/sy stem-hints-ib-186-Data.db')] INFO [CompactionExecutor:60] 2013-01-10 21:59:02,431 CompactionTask.java (line 267) Compacted 2 sstables to [/data2/cassandra/system/hints/system-hints-ib-188,]. 32,814 bytes to 32,729 (~99% of original) in 230ms = 0.135708MB/s. 8 total rows, 7 unique. Row merge counts were {1:8, 2:0, } INFO [HintedHandoff:2] 2013-01-10 21:59:02,432 HintedHandOffManager.java (line 408) Finished hinted handoff of 47 rows to endpoint /10.8.30.102 INFO [GossipStage:1] 2013-01-10 21:59:11,999 StorageService.java (line 1288) Node /10.8.30.102 state jump to normal INFO [GossipStage:1] 2013-01-10 21:59:12,003 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-peers@1233529943(306/5247 serialized/live bytes, 21 ops) INFO [FlushWriter:10] 2013-01-10 21:59:12,004 Memtable.java (line 424) Writing Memtable-peers@1233529943(306/5247 serialized/live bytes, 21 ops) INFO [FlushWriter:10] 2013-01-10 21:59:12,265 Memtable.java (line 458) Completed flushing /data2/cassandra/system/peers/system-peers-ib-589-Data.db (351 bytes) for commitlog position ReplayPosition(segmentId=1357883369951, position=806482) INFO [GossipStage:1] 2013-01-10 21:59:12,272 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-local@1657301357(69/69 serialized/live bytes, 2 ops) INFO [FlushWriter:9] 2013-01-10 21:59:12,273 Memtable.java (line 424) Writing Memtable-local@1657301357(69/69 serialized/live bytes, 2 ops) INFO [FlushWriter:9] 2013-01-10 21:59:12,455 Memtable.java (line 458) Completed flushing /data2/cassandra/system/local/system-local-ib-674-Data.db (129 bytes) for commitlog position ReplayPosition(segmentId=1357883369951, position=806675) WARN [MemoryMeter:1] 2013-01-10 21:59:30,213 Memtable.java (line 191) setting live ratio to minimum of 1.0 instead of 0.09066707435830113 INFO [MemoryMeter:1] 2013-01-10 21:59:30,214 Memtable.java (line 207) CFS(Keyspace='evidence', ColumnFamily='messages') liveRatio is 1.0 (just-counted was 1.0). calculation took 7ms for 55 columns INFO [HintedHandoff:1] 2013-01-10 22:00:20,287 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 22:00:20,288 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [Thread-50] 2013-01-10 22:02:39,618 StorageService.java (line 2304) Starting repair command #1, repairing 1 ranges for keyspace evidence INFO [AntiEntropySessions:1] 2013-01-10 22:02:39,637 AntiEntropyService.java (line 652) [repair #815023d0-5bb4-11e2-906d-dd50a26832ff] new session: will sync /10.8.25.101, /10.8.30.14 on range (28356863910078205288614550619314017620,42535295865117307932921825928971026436] for evidence.[fingerprints, messages] INFO [AntiEntropySessions:1] 2013-01-10 22:02:39,646 AntiEntropyService.java (line 857) [repair #815023d0-5bb4-11e2-906d-dd50a26832ff] requesting merkle trees for fingerprints (to [/10.8.30.14, /10.8.25.101]) INFO [ValidationExecutor:1] 2013-01-10 22:02:39,665 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-fingerprints@1756165009(409626/409626 serialized/live bytes, 53 ops) INFO [FlushWriter:11] 2013-01-10 22:02:39,666 Memtable.java (line 424) Writing Memtable-fingerprints@1756165009(409626/409626 serialized/live bytes, 53 ops) INFO [FlushWriter:11] 2013-01-10 22:02:39,871 Memtable.java (line 458) Completed flushing /data2/cassandra/evidence/fingerprints/evidence-fingerprints-ib-195-Data.db (349405 bytes) for commitlog position ReplayPosition(segmentId=1357883369951, position=3000340) WARN [MemoryMeter:1] 2013-01-10 22:02:39,917 Memtable.java (line 191) setting live ratio to minimum of 1.0 instead of 0.03491183672633014 INFO [MemoryMeter:1] 2013-01-10 22:02:39,917 Memtable.java (line 207) CFS(Keyspace='evidence', ColumnFamily='messages') liveRatio is 1.0 (just-counted was 1.0). calculation took 19ms for 106 columns INFO [AntiEntropyStage:1] 2013-01-10 22:05:31,251 AntiEntropyService.java (line 214) [repair #815023d0-5bb4-11e2-906d-dd50a26832ff] Received merkle tree for fingerprints from /10.8.25.101 WARN [MemoryMeter:1] 2013-01-10 22:05:53,141 Memtable.java (line 191) setting live ratio to minimum of 1.0 instead of 0.0038005359709140643 INFO [MemoryMeter:1] 2013-01-10 22:05:53,142 Memtable.java (line 207) CFS(Keyspace='evidence', ColumnFamily='fingerprints') liveRatio is 1.0 (just-counted was 1.0). calculation took 6ms for 10 columns INFO [MemoryMeter:1] 2013-01-10 22:08:53,699 Memtable.java (line 207) CFS(Keyspace='brts', ColumnFamily='evidence_index') liveRatio is 3.018170276918194 (just-counted was 3.018170276918194). calculation took 24ms for 235 columns INFO [HintedHandoff:2] 2013-01-10 22:10:20,290 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:10:20,291 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 WARN [MemoryMeter:1] 2013-01-10 22:12:57,094 Memtable.java (line 191) setting live ratio to minimum of 1.0 instead of 0.033105659834837216 INFO [MemoryMeter:1] 2013-01-10 22:12:57,095 Memtable.java (line 207) CFS(Keyspace='evidence', ColumnFamily='messages') liveRatio is 1.0 (just-counted was 1.0). calculation took 18ms for 213 columns INFO [HintedHandoff:1] 2013-01-10 22:20:20,293 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 22:20:20,294 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:30:20,296 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:30:20,297 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 22:40:20,299 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 22:40:20,300 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 WARN [MemoryMeter:1] 2013-01-10 22:44:25,510 Memtable.java (line 191) setting live ratio to minimum of 1.0 instead of 0.03129749755193589 INFO [MemoryMeter:1] 2013-01-10 22:44:25,510 Memtable.java (line 207) CFS(Keyspace='evidence', ColumnFamily='messages') liveRatio is 1.0 (just-counted was 1.0). calculation took 20ms for 387 columns WARN [MemoryMeter:1] 2013-01-10 22:47:55,174 Memtable.java (line 191) setting live ratio to minimum of 1.0 instead of 0.013355315914417125 INFO [MemoryMeter:1] 2013-01-10 22:47:55,175 Memtable.java (line 207) CFS(Keyspace='evidence', ColumnFamily='fingerprints') liveRatio is 1.0 (just-counted was 1.0). calculation took 11ms for 63 columns INFO [HintedHandoff:2] 2013-01-10 22:50:20,302 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:50:20,307 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 23:00:20,304 HintedHandOffManager.java (line 293) Started hinted handoff for host: a1429d88-a084-46b2-a92d-81bb43b7ccc4 with IP: /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 23:00:20,305 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 {code} digest version {code} INFO [HintedHandoff:1] 2013-01-10 22:00:20,288 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:10:20,291 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 22:20:20,294 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:30:20,297 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 22:40:20,300 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 22:50:20,307 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 23:00:20,305 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 23:10:20,308 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 23:20:20,311 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:2] 2013-01-10 23:30:20,314 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 INFO [HintedHandoff:1] 2013-01-10 23:40:20,317 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.102 {code} was (Author: mkjellman): {code} INFO [GossipStage:1] 2013-01-10 23:45:19,580 Gossiper.java (line 772) InetAddress /10.8.30.103 is now dead. INFO [GossipStage:1] 2013-01-10 23:45:19,900 Gossiper.java (line 758) InetAddress /10.8.30.103 is now UP INFO [HintedHandoff:2] 2013-01-10 23:45:19,901 HintedHandOffManager.java (line 293) Started hinted handoff for host: a6c4d3f6-dcbd-4801-aad3-ef0a26959e51 with IP: /10.8.30.103 INFO [HintedHandoff:2] 2013-01-10 23:45:19,903 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.103 INFO [GossipTasks:1] 2013-01-10 23:45:44,330 Gossiper.java (line 772) InetAddress /10.8.30.103 is now dead. INFO [GossipStage:1] 2013-01-10 23:45:47,600 Gossiper.java (line 790) Node /10.8.30.103 has restarted, now UP INFO [GossipStage:1] 2013-01-10 23:45:47,601 Gossiper.java (line 758) InetAddress /10.8.30.103 is now UP INFO [HintedHandoff:1] 2013-01-10 23:45:47,602 HintedHandOffManager.java (line 293) Started hinted handoff for host: a6c4d3f6-dcbd-4801-aad3-ef0a26959e51 with IP: /10.8.30.103 INFO [HintedHandoff:1] 2013-01-10 23:45:47,603 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.30.103 INFO [GossipStage:1] 2013-01-10 23:45:57,645 StorageService.java (line 1288) Node /10.8.30.103 state jump to normal INFO [GossipStage:1] 2013-01-10 23:45:57,650 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-peers@1717997204(251/5063 serialized/live bytes, 17 ops) INFO [FlushWriter:1] 2013-01-10 23:45:57,651 Memtable.java (line 424) Writing Memtable-peers@1717997204(251/5063 serialized/live bytes, 17 ops) INFO [FlushWriter:1] 2013-01-10 23:45:57,836 Memtable.java (line 458) Completed flushing /data/cassandra/system/peers/system-peers-ib-564-Data.db (318 bytes) for commitlog position ReplayPosition(segmentId=1357890248318, position=464810) INFO [CompactionExecutor:5] 2013-01-10 23:45:57,839 CompactionTask.java (line 120) Compacting [SSTableReader(path='/data/cassandra/system/peers/system-peers-ib-564-Data.db'), SSTableReader(path='/data/cassandra/system/peers/system-peers-ib-561-Data.db'), SSTableReader(path='/data/cassandra/system/peers/system-peers-ib-563-Data.db'), SSTableReader(path='/data/cassandra/system/peers/system-peers-ib-562-Data.db')] INFO [GossipStage:1] 2013-01-10 23:45:57,856 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-local@555590564(70/70 serialized/live bytes, 2 ops) INFO [FlushWriter:2] 2013-01-10 23:45:57,857 Memtable.java (line 424) Writing Memtable-local@555590564(70/70 serialized/live bytes, 2 ops) INFO [FlushWriter:2] 2013-01-10 23:45:58,031 Memtable.java (line 458) Completed flushing /data2/cassandra/system/local/system-local-ib-621-Data.db (129 bytes) for commitlog position ReplayPosition(segmentId=1357890248318, position=465004) INFO [GossipStage:1] 2013-01-10 23:45:58,033 StorageService.java (line 1288) Node /10.8.30.103 state jump to normal INFO [GossipStage:1] 2013-01-10 23:45:58,038 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-peers@1963979017(11/221 serialized/live bytes, 1 ops) INFO [FlushWriter:1] 2013-01-10 23:45:58,039 Memtable.java (line 424) Writing Memtable-peers@1963979017(11/221 serialized/live bytes, 1 ops) INFO [CompactionExecutor:5] 2013-01-10 23:45:58,053 CompactionTask.java (line 267) Compacted 4 sstables to [/data/cassandra/system/peers/system-peers-ib-565,]. 2,579 bytes to 1,512 (~58% of original) in 213ms = 0.006770MB/s. 20 total rows, 13 unique. Row merge counts were {1:9, 2:2, 3:1, 4:1, } INFO [FlushWriter:1] 2013-01-10 23:45:58,265 Memtable.java (line 458) Completed flushing /data2/cassandra/system/peers/system-peers-ib-566-Data.db (71 bytes) for commitlog position ReplayPosition(segmentId=1357890248318, position=465131) INFO [GossipStage:1] 2013-01-10 23:45:58,285 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-local@232075815(70/70 serialized/live bytes, 2 ops) INFO [FlushWriter:2] 2013-01-10 23:45:58,286 Memtable.java (line 424) Writing Memtable-local@232075815(70/70 serialized/live bytes, 2 ops) INFO [FlushWriter:2] 2013-01-10 23:45:58,472 Memtable.java (line 458) Completed flushing /data/cassandra/system/local/system-local-ib-622-Data.db (129 bytes) for commitlog position ReplayPosition(segmentId=1357890248318, position=465325) INFO [CompactionExecutor:11] 2013-01-10 23:45:58,475 CompactionTask.java (line 120) Compacting [SSTableReader(path='/data2/cassandra/system/local/system-local-ib-621-Data.db'), SSTableReader(path='/data/cassandra/system/local/system-local-ib-622-Data.db'), SSTableReader(path='/data/cassandra/system/local/system-local-ib-619-Data.db'), SSTableReader(path='/data/cassandra/system/local/system-local-ib-620-Data.db')] INFO [GossipStage:1] 2013-01-10 23:45:58,475 Gossiper.java (line 772) InetAddress /10.8.25.113 is now dead. INFO [GossipStage:1] 2013-01-10 23:45:58,477 Gossiper.java (line 758) InetAddress /10.8.25.113 is now UP INFO [HintedHandoff:2] 2013-01-10 23:45:58,477 HintedHandOffManager.java (line 293) Started hinted handoff for host: 0c11b261-7514-4c98-b94c-baa79c6c4faf with IP: /10.8.25.113 INFO [HintedHandoff:2] 2013-01-10 23:45:58,478 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.25.113 INFO [CompactionExecutor:11] 2013-01-10 23:45:58,680 CompactionTask.java (line 267) Compacted 4 sstables to [/data/cassandra/system/local/system-local-ib-623,]. 978 bytes to 591 (~60% of original) in 204ms = 0.002763MB/s. 4 total rows, 1 unique. Row merge counts were {1:0, 2:0, 3:0, 4:1, } INFO [GossipTasks:1] 2013-01-10 23:46:23,389 Gossiper.java (line 772) InetAddress /10.8.25.113 is now dead. INFO [GossipStage:1] 2013-01-10 23:46:27,397 Gossiper.java (line 790) Node /10.8.25.113 has restarted, now UP INFO [GossipStage:1] 2013-01-10 23:46:27,398 Gossiper.java (line 758) InetAddress /10.8.25.113 is now UP INFO [HintedHandoff:1] 2013-01-10 23:46:27,399 HintedHandOffManager.java (line 293) Started hinted handoff for host: 0c11b261-7514-4c98-b94c-baa79c6c4faf with IP: /10.8.25.113 INFO [HintedHandoff:1] 2013-01-10 23:46:27,400 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.25.113 INFO [GossipStage:1] 2013-01-10 23:46:34,972 StorageService.java (line 1288) Node /10.8.25.113 state jump to normal INFO [GossipStage:1] 2013-01-10 23:46:34,976 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-peers@583864609(251/5063 serialized/live bytes, 17 ops) INFO [FlushWriter:1] 2013-01-10 23:46:34,977 Memtable.java (line 424) Writing Memtable-peers@583864609(251/5063 serialized/live bytes, 17 ops) INFO [FlushWriter:1] 2013-01-10 23:46:35,200 Memtable.java (line 458) Completed flushing /data/cassandra/system/peers/system-peers-ib-567-Data.db (318 bytes) for commitlog position ReplayPosition(segmentId=1357890248318, position=473846) INFO [GossipStage:1] 2013-01-10 23:46:35,215 ColumnFamilyStore.java (line 647) Enqueuing flush of Memtable-local@2025685109(70/70 serialized/live bytes, 2 ops) INFO [FlushWriter:2] 2013-01-10 23:46:35,216 Memtable.java (line 424) Writing Memtable-local@2025685109(70/70 serialized/live bytes, 2 ops) INFO [FlushWriter:2] 2013-01-10 23:46:35,401 Memtable.java (line 458) Completed flushing /data/cassandra/system/local/system-local-ib-624-Data.db (129 bytes) for commitlog position ReplayPosition(segmentId=1357890248318, position=474040) INFO [GossipStage:1] 2013-01-10 23:46:38,124 Gossiper.java (line 772) InetAddress /10.8.25.101 is now dead. INFO [GossipStage:1] 2013-01-10 23:46:38,268 Gossiper.java (line 758) InetAddress /10.8.25.101 is now UP INFO [HintedHandoff:2] 2013-01-10 23:46:38,269 HintedHandOffManager.java (line 293) Started hinted handoff for host: dd3a40e2-fef1-4574-87b8-e2929fd80235 with IP: /10.8.25.101 INFO [HintedHandoff:2] 2013-01-10 23:46:38,270 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.25.101 INFO [MemoryMeter:1] 2013-01-10 23:46:40,471 Memtable.java (line 207) CFS(Keyspace='brts', ColumnFamily='evidence_index') liveRatio is 2.471362417743115 (just-counted was 2.471362417743115). calculation took 47ms for 39 columns INFO [GossipTasks:1] 2013-01-10 23:47:03,442 Gossiper.java (line 772) InetAddress /10.8.25.101 is now dead. INFO [GossipStage:1] 2013-01-10 23:47:04,449 Gossiper.java (line 790) Node /10.8.25.101 has restarted, now UP INFO [GossipStage:1] 2013-01-10 23:47:04,449 Gossiper.java (line 758) InetAddress /10.8.25.101 is now UP INFO [HintedHandoff:1] 2013-01-10 23:47:04,450 HintedHandOffManager.java (line 293) Started hinted handoff for host: dd3a40e2-fef1-4574-87b8-e2929fd80235 with IP: /10.8.25.101 INFO [HintedHandoff:1] 2013-01-10 23:47:04,451 HintedHandOffManager.java (line 408) Finished hinted handoff of 0 rows to endpoint /10.8.25.101 INFO [GossipStage:1] 2013-01-10 23:47:12,892 StorageService.java (line 1288) Node /10.8.25.101 state jump to normal {code} > CLONE - Once a host has been hinted to, log messages for it repeat every 10 mins even if no hints are delivered > --------------------------------------------------------------------------------------------------------------- > > Key: CASSANDRA-5068 > URL: https://issues.apache.org/jira/browse/CASSANDRA-5068 > Project: Cassandra > Issue Type: Bug > Components: Core > Affects Versions: 1.1.6, 1.2.0 > Environment: cassandra 1.1.6 > java 1.6.0_30 > Reporter: Peter Haggerty > Assignee: Brandon Williams > Priority: Minor > Labels: hinted, hintedhandoff, phantom > > We have "0 row" hinted handoffs every 10 minutes like clockwork. This impacts our ability to monitor the cluster by adding persistent noise in the handoff metric. > Previous mentions of this issue are here: > http://www.mail-archive.com/user@cassandra.apache.org/msg25982.html > The hinted handoffs can be scrubbed away with > nodetool -h 127.0.0.1 scrub system HintsColumnFamily > but they return after anywhere from a few minutes to multiple hours later. > These started to appear after an upgrade to 1.1.6 and haven't gone away despite rolling cleanups, rolling restarts, multiple rounds of scrubbing, etc. > A few things we've noticed about the handoffs: > 1. The phantom handoff endpoint changes after a non-zero handoff comes through > 2. Sometimes a non-zero handoff will be immediately followed by an "off schedule" phantom handoff to the endpoint the phantom had been using before > 3. The sstable2json output seems to include multiple sub-sections for each handoff with the same "deletedAt" information. > The phantom handoff endpoint changes after a non-zero handoff comes through: > INFO [HintedHandoff:1] 2012-12-11 06:57:35,093 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.1 > INFO [HintedHandoff:1] 2012-12-11 07:07:35,092 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.1 > INFO [HintedHandoff:1] 2012-12-11 07:07:37,915 HintedHandOffManager.java (line 392) Finished hinted handoff of 1058 rows to endpoint /10.10.10.2 > INFO [HintedHandoff:1] 2012-12-11 07:17:35,093 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.2 > INFO [HintedHandoff:1] 2012-12-11 07:27:35,093 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.2 > Sometimes a non-zero handoff will be immediately followed by an "off schedule" phantom handoff to the endpoint the phantom had been using before: > INFO [HintedHandoff:1] 2012-12-12 21:47:39,335 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.3 > INFO [HintedHandoff:1] 2012-12-12 21:57:39,335 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.3 > INFO [HintedHandoff:1] 2012-12-12 22:07:43,319 HintedHandOffManager.java (line 392) Finished hinted handoff of 1416 rows to endpoint /10.10.10.4 > INFO [HintedHandoff:1] 2012-12-12 22:07:43,320 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.3 > INFO [HintedHandoff:1] 2012-12-12 22:17:39,357 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.4 > INFO [HintedHandoff:1] 2012-12-12 22:27:39,337 HintedHandOffManager.java (line 392) Finished hinted handoff of 0 rows to endpoint /10.10.10.4 > The first few entries from one of the json files: > { > "0aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa": { > "ccf5dc203a2211e20000e154da71a9bb": { > "deletedAt": -9223372036854775808, > "subColumns": [] > }, > "ccf603303a2211e20000e154da71a9bb": { > "deletedAt": -9223372036854775808, > "subColumns": [] > }, -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira