cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Michael Kjellman (JIRA)" <j...@apache.org>
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
Date Fri, 11 Jan 2013 17:04:13 GMT

    [ 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

Mime
View raw message