cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Peter Schuller (JIRA)" <j...@apache.org>
Subject [jira] Created: (CASSANDRA-1840) nodetool move caused the moved node to drop itself from 'nodetool ring' output; others think it's 'joining'
Date Fri, 10 Dec 2010 10:02:03 GMT
nodetool move caused the moved node to drop itself from 'nodetool ring' output; others think
it's 'joining'
-----------------------------------------------------------------------------------------------------------

                 Key: CASSANDRA-1840
                 URL: https://issues.apache.org/jira/browse/CASSANDRA-1840
             Project: Cassandra
          Issue Type: Bug
            Reporter: Peter Schuller


I have a test cluster with three nodes on a very recent 0.7 (last few days branch). It has
very little data in it (so maybe timing can be an issue given how fast operations complete).
It was otherwise healthy; nodetool ring was consistent on all nodes and I had just run some
compactions and 'repair' commands on all nodes repeatedly.

I had a single client doing some reads/writes of single columns; nothing extreme (low load).

When I did a 'nodetool move' the node exited the ring, stopped responding to thrift RPC, entered
the ring again, and started accepting RPC requests via thrift. It reports in the log that
it is joined.

However, at this point 'nodetool ring' on the node I moved does *not* show its own location
in the ring, and other nodes show it as 'joining' (with the new token, not the old token).
I will include nodetool ring output and log output below.

The situation was un-wedged by restarting the node that I had moved. After it started and
a few seconds passed, nodetool ring looked correct on the node in question and other nodes
now reported it as 'up' rather than 'joining'.

Moved node said post-move (.61 in the below pastes is the node that I moved):

Address         Status State   Load            Owns    Token                             
         
                                                       110288156320304836825416347816186393502
    
78.31.15.204    Up     Normal  224.34 KB       61.44%  44678687293344048155696022135861768368
     
193.182.3.229   Up     Normal  251.84 KB       38.56%  110288156320304836825416347816186393502
    

And the other two:


Address         Status State   Load            Owns    Token                             
         
                                                       164957594472845753490452447750528540018
    
78.31.15.204    Up     Normal  224.34 KB       29.31%  44678687293344048155696022135861768368
     
193.182.3.229   Up     Normal  251.84 KB       38.56%  110288156320304836825416347816186393502
    
193.182.3.61    Up     Joining 194.76 KB       32.13%  164957594472845753490452447750528540018
    

Address         Status State   Load            Owns    Token                             
         
                                                       164957594472845753490452447750528540018
    

78.31.15.204    Up     Normal  
224.34 KB       29.31%  44678687293344048155696022135861768368      
193.182.3.229   Up     Normal  251.84 KB       38.56%  110288156320304836825416347816186393502
    
193.182.3.61    Up     Joining 194.76 KB       32.13%  164957594472845753490452447750528540018
    

I'll try reproducing a few times, and also merge latest 0.7.

Here is some system log output from the node that got moved; it looks good to me:

 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:38:17,560 StorageService.java (line
455) Leaving: sleeping 30000 ms for pending range setup
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:38:47,564 StorageService.java (line
455) Leaving: streaming data to other nodes
 INFO [StreamStage:1] 2010-12-10 09:38:47,566 StreamOut.java (line 75) Beginning transfer
to /78.31.15.204
 INFO [StreamStage:1] 2010-12-10 09:38:47,566 StreamOut.java (line 98) Flushing memtables
for KeyspaceSlask...
 INFO [StreamStage:1] 2010-12-10 09:38:47,567 ColumnFamilyStore.java (line 639) switching
in a fresh Memtable for KeyValue at CommitLogContext(file='/var/lib/spotify-cassandra/slask/commitlog/CommitLog-1291973418600.log',
position=2573610)
 INFO [StreamStage:1] 2010-12-10 09:38:47,567 ColumnFamilyStore.java (line 943) Enqueuing
flush of Memtable-KeyValue@1131602880(370711 bytes, 5533 operations)
 INFO [FlushWriter:1] 2010-12-10 09:38:47,567 Memtable.java (line 155) Writing Memtable-KeyValue@1131602880(370711
bytes, 5533 operations)
 INFO [FlushWriter:1] 2010-12-10 09:38:47,599 Memtable.java (line 162) Completed flushing
/var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-68-Data.db (15042 bytes)
 INFO [StreamStage:1] 2010-12-10 09:38:47,601 StreamOut.java (line 171) Stream context metadata
[/var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-67-Data.db/(0,10094)
         progress=0/10094 - 0%, /var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-68-Data.db/(0,10094)
         progress=0/10094 - 0%], 2 sstables.
 INFO [StreamStage:1] 2010-12-10 09:38:47,601 StreamOutSession.java (line 175) Streaming to
/78.31.15.204
 INFO [StreamStage:1] 2010-12-10 09:38:47,601 StreamOut.java (line 75) Beginning transfer
to /193.182.3.229
 INFO [StreamStage:1] 2010-12-10 09:38:47,602 StreamOut.java (line 98) Flushing memtables
for KeyspaceSlask...
 INFO [StreamStage:1] 2010-12-10 09:38:47,602 ColumnFamilyStore.java (line 639) switching
in a fresh Memtable for KeyValue at CommitLogContext(file='/var/lib/spotify-cassandra/slask/commitlog/CommitLog-1291973418600.log',
position=2573755)
 INFO [StreamStage:1] 2010-12-10 09:38:47,602 ColumnFamilyStore.java (line 943) Enqueuing
flush of Memtable-KeyValue@1894688899(67 bytes, 1 operations)
 INFO [FlushWriter:1] 2010-12-10 09:38:47,604 Memtable.java (line 155) Writing Memtable-KeyValue@1894688899(67
bytes, 1 operations)
 INFO [FlushWriter:1] 2010-12-10 09:38:47,635 Memtable.java (line 162) Completed flushing
/var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-69-Data.db (198 bytes)
 INFO [StreamStage:1] 2010-12-10 09:38:47,637 StreamOut.java (line 171) Stream context metadata
[/var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-67-Data.db/(10094,15042)
         progress=0/4948 - 0%, /var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-68-Data.db/(10094,15042)
         progress=0/4948 - 0%], 3 sstables.
 INFO [StreamStage:1] 2010-12-10 09:38:47,637 StreamOutSession.java (line 175) Streaming to
/193.182.3.229
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:38:49,734 StorageService.java (line
1682) re-bootstrapping to new token 164957594472845753490452447750528540018
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:38:49,735 ColumnFamilyStore.java
(line 639) switching in a fresh Memtable for LocationInfo at CommitLogContext(file='/var/lib/spotify-cassandra/slask/commitlog/CommitLog-1291973418600.log',
position=2576080)
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:38:49,736 ColumnFamilyStore.java
(line 943) Enqueuing flush of Memtable-LocationInfo@578162504(53 bytes, 2 operations)
 INFO [FlushWriter:1] 2010-12-10 09:38:49,737 Memtable.java (line 155) Writing Memtable-LocationInfo@578162504(53
bytes, 2 operations)
 INFO [FlushWriter:1] 2010-12-10 09:38:49,865 Memtable.java (line 162) Completed flushing
/var/lib/spotify-cassandra/slask/data/system/LocationInfo-e-17-Data.db (301 bytes)
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:38:49,866 StorageService.java (line
455) Joining: sleeping 30000 ms for pending range setup
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:39:19,866 StorageService.java (line
455) Bootstrapping
 INFO [CompactionExecutor:1] 2010-12-10 09:39:19,960 SSTableReader.java (line 170) Opening
/var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-70
 INFO [CompactionExecutor:1] 2010-12-10 09:39:19,981 SSTableReader.java (line 170) Opening
/var/lib/spotify-cassandra/slask/data/KeyspaceSlask/KeyValue-e-71
 INFO [Thread-71] 2010-12-10 09:39:19,983 StreamInSession.java (line 160) Finished streaming
session 258244662990017 from /193.182.3.229
 INFO [RMI TCP Connection(32)-193.182.3.61] 2010-12-10 09:39:19,983 StorageService.java (line
249) Bootstrap/move completed! Now serving reads.

So based on the output the node certainly claims to have finished the entire bootstrapping
procedure and started serving reads (which it is; reads are working against it).


-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


Mime
View raw message