cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Peter Schuller (Commented) (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-3857) AIOOB during bootstrap causes insta-join as Normal in ring, serving bad reads
Date Mon, 06 Feb 2012 04:41:59 GMT

    [ https://issues.apache.org/jira/browse/CASSANDRA-3857?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13201032#comment-13201032
] 

Peter Schuller commented on CASSANDRA-3857:
-------------------------------------------

I was indeed running without {{-ea}}, which is consistent with the assertion not triggering.
                
> AIOOB during bootstrap causes insta-join as Normal in ring, serving bad reads
> -----------------------------------------------------------------------------
>
>                 Key: CASSANDRA-3857
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-3857
>             Project: Cassandra
>          Issue Type: Bug
>            Reporter: Peter Schuller
>            Assignee: Peter Schuller
>            Priority: Critical
>
> The reason I realized there was something still fishy in CASSANDRA-3832 was that I thought
I had seen nodes just join instantly into Normal state earlier on trunk. When I tried to re-produce
that I got what I'm mentioning in CASSANDRA-3832. While investigating *THAT* I now triggered
what I believe to be insta-join again. The node that was bootstrapping died with the below
exception during start-up, automatically re-started (due to monit in this case) and then joined
the ring. I'm pretty sure it didn't go into Joining first, I *just* managed to catch the "watch"
I had going on a nodetool | grep on another node. Additionally, looking at the log below I
see no evidence of waiting for ring delay which is should as part of boot-strap, nor do I
see "Starting to bootstrap ... " logged.
> A quick look at the code makes me confused how this is possible given that the bootstrap
flag is set *after* the point int he code where we bailed with the exception.
> As for the exception, I've seen something like this when investigating CASSANDRA-3831
and CASSANDRA-3417, but I never got to the bottom of it believing it had to do with the lack
of synchronization. I look back now and it seems my trunk is one that doesn't have the latest
patch that I submitted to CASSANDRA-3417, but I haven't looked at it in detail to determine
whether it fixes it. In any case, the insta-join is a problem.
> {code}
>  INFO [main] 2012-02-06 03:59:34,059 StorageService.java (line 728) JOINING: schema complete,
ready to bootstrap
>  INFO [main] 2012-02-06 03:59:34,059 StorageService.java (line 728) JOINING: getting
bootstrap token
> ERROR [main] 2012-02-06 03:59:34,062 AbstractCassandraDaemon.java (line 370) Exception
encountered during startup
> java.lang.ArrayIndexOutOfBoundsException: -2
>         at java.util.ArrayList.get(ArrayList.java:324)
>         at org.apache.cassandra.locator.TokenMetadata.getPredecessor(TokenMetadata.java:521)
>         at org.apache.cassandra.locator.TokenMetadata.getPrimaryRangeFor(TokenMetadata.java:463)
>         at org.apache.cassandra.locator.TokenMetadata.pendingRangeChanges(TokenMetadata.java:111)
>         at org.apache.cassandra.dht.BootStrapper$1.compare(BootStrapper.java:144)
>         at org.apache.cassandra.dht.BootStrapper$1.compare(BootStrapper.java:141)
>         at java.util.Arrays.mergeSort(Arrays.java:1270)
>         at java.util.Arrays.mergeSort(Arrays.java:1281)
>         at java.util.Arrays.mergeSort(Arrays.java:1281)
>         at java.util.Arrays.mergeSort(Arrays.java:1281)
>         at java.util.Arrays.mergeSort(Arrays.java:1281)
>         at java.util.Arrays.mergeSort(Arrays.java:1281)
>         at java.util.Arrays.sort(Arrays.java:1210)
>         at java.util.Collections.sort(Collections.java:159)
>         at org.apache.cassandra.dht.BootStrapper.getBootstrapSource(BootStrapper.java:140)
>         at org.apache.cassandra.dht.BootStrapper.getBalancedToken(BootStrapper.java:116)
>         at org.apache.cassandra.dht.BootStrapper.getBootstrapToken(BootStrapper.java:111)
>         at org.apache.cassandra.service.StorageService.joinTokenRing(StorageService.java:585)
>         at org.apache.cassandra.service.StorageService.initServer(StorageService.java:502)
>         at org.apache.cassandra.service.StorageService.initServer(StorageService.java:411)
>         at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:231)
>         at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:353)
>         at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:107)
>  INFO [StorageServiceShutdownHook] 2012-02-06 03:59:34,065 MessagingService.java (line
541) Waiting for messaging service to quiesce
>  INFO [ACCEPT-/10.40.33.128] 2012-02-06 03:59:34,065 MessagingService.java (line 697)
MessagingService shutting down server thread.
>  INFO [main] 2012-02-06 03:59:39,760 AbstractCassandraDaemon.java (line 100) Logging
initialized
>  INFO [main] 2012-02-06 03:59:39,763 AbstractCassandraDaemon.java (line 121) JVM vendor/version:
Java HotSpot(TM) 64-Bit Server VM/1.6.0_24
>  INFO [main] 2012-02-06 03:59:39,764 AbstractCassandraDaemon.java (line 122) Heap size:
12845645824/12845645824
>  INFO [main] 2012-02-06 03:59:39,764 AbstractCassandraDaemon.java (line 123) Classpath:
/usr/local/cassandra/current/conf/atla/cassandra.prod.cuckoo:/usr/local/cassandra/current/vendor/cassandra/build/classes:/usr/local/cassandra/current/vendor/cassandra/lib/antlr-3.2.jar:/usr/local/cassandra/current/vendor/cassandra/lib/apache-cassandra-clientutil-twttr-cassandra-trunk-upstream-but-buildable-log-calc-pending-6.jar:/usr/local/cassandra/current/vendor/cassandra/lib/apache-cassandra-thrift-twttr-cassandra-trunk-upstream-but-buildable-log-calc-pending-6.jar:/usr/local/cassandra/current/vendor/cassandra/lib/apache-cassandra-twttr-cassandra-trunk-upstream-but-buildable-log-calc-pending-6.jar:/usr/local/cassandra/current/vendor/cassandra/lib/avro-1.4.0-fixes.jar:/usr/local/cassandra/current/vendor/cassandra/lib/avro-1.4.0-sources-fixes.jar:/usr/local/cassandra/current/vendor/cassandra/lib/commons-cli-1.1.jar:/usr/local/cassandra/current/vendor/cassandra/lib/commons-codec-1.2.jar:/usr/local/cassandra/current/vendor/cassandra/lib/commons-lang-2.4.jar:/usr/local/cassandra/current/vendor/cassandra/lib/compress-lzf-0.8.4.jar:/usr/local/cassandra/current/vendor/cassandra/lib/concurrentlinkedhashmap-lru-1.2.jar:/usr/local/cassandra/current/vendor/cassandra/lib/guava-r08.jar:/usr/local/cassandra/current/vendor/cassandra/lib/high-scale-lib-1.1.2.jar:/usr/local/cassandra/current/vendor/cassandra/lib/jackson-core-asl-1.9.2.jar:/usr/local/cassandra/current/vendor/cassandra/lib/jackson-mapper-asl-1.9.2.jar:/usr/local/cassandra/current/vendor/cassandra/lib/jamm-0.2.5.jar:/usr/local/cassandra/current/vendor/cassandra/lib/jline-0.9.94.jar:/usr/local/cassandra/current/vendor/cassandra/lib/json-simple-1.1.jar:/usr/local/cassandra/current/vendor/cassandra/lib/libthrift-0.7.0.jar:/usr/local/cassandra/current/vendor/cassandra/lib/log4j-1.2.16.jar:/usr/local/cassandra/current/vendor/cassandra/lib/servlet-api-2.5-20081211.jar:/usr/local/cassandra/current/vendor/cassandra/lib/slf4j-api-1.6.1.jar:/usr/local/cassandra/current/vendor/cassandra/lib/slf4j-log4j12-1.6.1.jar:/usr/local/cassandra/current/vendor/cassandra/lib/snakeyaml-1.6.jar:/usr/local/cassandra/current/vendor/cassandra/lib/snappy-java-1.0.4.1.jar:/usr/local/cassandra/current/vendor/cassandra/lib/snaptree-0.1-SNAPSHOT.jar:/usr/local/cassandra/current/vendor/cassandra/build/lib/jars/*.jar:/usr/local/cassandra/current/vendor/cassandra/build/lib/twitter-jars/*.jar:/usr/local/cassandra/current/vendor/cassandra/lib/twitter-jars/*.jar
>  INFO [main] 2012-02-06 03:59:39,765 CLibrary.java (line 66) JNA not found. Native methods
will be disabled.
>  INFO [main] 2012-02-06 03:59:39,772 DatabaseDescriptor.java (line 127) Loading settings
from file:/usr/local/cassandra/releases/20120206035358/conf/atla/cassandra.prod.cuckoo-upstream-trunk/cassandra.yaml
>  INFO [main] 2012-02-06 03:59:39,874 DatabaseDescriptor.java (line 181) DiskAccessMode
'auto' determined to be mmap, indexAccessMode is mmap
>  INFO [main] 2012-02-06 03:59:39,884 DatabaseDescriptor.java (line 246) Global memtable
threshold is enabled at 4083MB
>  INFO [main] 2012-02-06 03:59:39,992 CacheService.java (line 100) Initializing key cache
with capacity of 2 MBs.
>  INFO [main] 2012-02-06 03:59:40,003 CacheService.java (line 111) Scheduling key cache
save to each 14400 seconds (going to save all keys).
>  INFO [main] 2012-02-06 03:59:40,004 CacheService.java (line 125) Initializing row cache
with capacity of 0 MBs and provider org.apache.cassandra.cache.ConcurrentLinkedHashCacheProvider
>  INFO [main] 2012-02-06 03:59:40,006 CacheService.java (line 137) Scheduling row cache
save to each 0 seconds (going to save all keys).
>  INFO [SSTableBatchOpen:1] 2012-02-06 03:59:40,070 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/schema_columnfamilies/system-schema_columnfamilies-hc-30 (1399
bytes)
>  INFO [SSTableBatchOpen:2] 2012-02-06 03:59:40,071 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/schema_columnfamilies/system-schema_columnfamilies-hc-29 (1399
bytes)
>  INFO [SSTableBatchOpen:3] 2012-02-06 03:59:40,071 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/schema_columnfamilies/system-schema_columnfamilies-hc-31 (1399
bytes)
>  INFO [SSTableBatchOpen:1] 2012-02-06 03:59:40,106 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/schema_keyspaces/system-schema_keyspaces-hc-30 (255 bytes)
>  INFO [SSTableBatchOpen:3] 2012-02-06 03:59:40,107 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/schema_keyspaces/system-schema_keyspaces-hc-29 (255 bytes)
>  INFO [SSTableBatchOpen:2] 2012-02-06 03:59:40,107 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/schema_keyspaces/system-schema_keyspaces-hc-31 (255 bytes)
>  INFO [SSTableBatchOpen:1] 2012-02-06 03:59:40,116 SSTableReader.java (line 156) Opening
/data/diskarray/tables/system/LocationInfo/system-LocationInfo-hc-245 (6775 bytes)
>  INFO [main] 2012-02-06 03:59:40,391 AbstractCassandraDaemon.java (line 208) completed
pre-loading (4 keys) key cache.
>  INFO [main] 2012-02-06 03:59:40,504 CommitLog.java (line 142) Replaying /data/disk1/commitlog/CommitLog-650613166587178.log,
/data/disk1/commitlog/CommitLog-650613060900385.log
>  INFO [main] 2012-02-06 03:59:40,508 CommitLog.java (line 185) Replaying /data/disk1/commitlog/CommitLog-650613166587178.log
>  INFO [main] 2012-02-06 03:59:40,509 CommitLog.java (line 339) Finished reading /data/disk1/commitlog/CommitLog-650613166587178.log
>  INFO [main] 2012-02-06 03:59:40,509 CommitLog.java (line 185) Replaying /data/disk1/commitlog/CommitLog-650613060900385.log
>  INFO [main] 2012-02-06 03:59:40,584 CommitLog.java (line 339) Finished reading /data/disk1/commitlog/CommitLog-650613060900385.log
>  INFO [main] 2012-02-06 03:59:40,588 ColumnFamilyStore.java (line 590) Enqueuing flush
of Memtable-Versions@275980095(141/176 serialized/live bytes, 3 ops)
>  INFO [FlushWriter:1] 2012-02-06 03:59:40,600 Memtable.java (line 252) Writing Memtable-Versions@275980095(141/176
serialized/live bytes, 3 ops)
>  INFO [FlushWriter:1] 2012-02-06 03:59:40,618 Memtable.java (line 293) Completed flushing
/data/diskarray/tables/system/Versions/system-Versions-hc-1-Data.db (305 bytes)
>  INFO [main] 2012-02-06 03:59:40,625 CommitLog.java (line 144) Log replay complete, 3
replayed mutations
>  INFO [main] 2012-02-06 03:59:40,637 StorageService.java (line 416) Cassandra version:
twttr-cassandra-trunk-upstream-but-buildable-log-calc-pending-6
>  INFO [main] 2012-02-06 03:59:40,638 StorageService.java (line 417) Thrift API version:
19.28.0
>  INFO [main] 2012-02-06 03:59:40,639 StorageService.java (line 418) CQL supported versions:
2.0.0,3.0.0-beta1 (default: 2.0.0)
>  INFO [main] 2012-02-06 03:59:40,639 StorageService.java (line 431) Loading persisted
ring state
>  INFO [main] 2012-02-06 03:59:40,670 StorageService.java (line 512) Starting up server
gossip
>  INFO [main] 2012-02-06 03:59:40,676 ColumnFamilyStore.java (line 590) Enqueuing flush
of Memtable-LocationInfo@1983702821(29/36 serialized/live bytes, 1 ops)
>  INFO [FlushWriter:1] 2012-02-06 03:59:40,676 Memtable.java (line 252) Writing Memtable-LocationInfo@1983702821(29/36
serialized/live bytes, 1 ops)
>  INFO [FlushWriter:1] 2012-02-06 03:59:40,683 Memtable.java (line 293) Completed flushing
/data/diskarray/tables/system/LocationInfo/system-LocationInfo-hc-246-Data.db (80 bytes)
>  INFO [main] 2012-02-06 03:59:40,689 MessagingService.java (line 286) Starting Messaging
Service on port 7000
>  WARN [main] 2012-02-06 03:59:40,697 StorageService.java (line 619) Generated random
token 100588447224685279983438741296967523984. Random tokens will result in an unbalanced
ring; see http://wiki.apache.org/cassandra/Operations
>  INFO [main] 2012-02-06 03:59:40,697 ColumnFamilyStore.java (line 590) Enqueuing flush
of Memtable-LocationInfo@44130647(53/66 serialized/live bytes, 2 ops)
>  INFO [FlushWriter:1] 2012-02-06 03:59:40,698 Memtable.java (line 252) Writing Memtable-LocationInfo@44130647(53/66
serialized/live bytes, 2 ops)
>  INFO [FlushWriter:1] 2012-02-06 03:59:40,703 Memtable.java (line 293) Completed flushing
/data/diskarray/tables/system/LocationInfo/system-LocationInfo-hc-247-Data.db (163 bytes)
>  INFO [main] 2012-02-06 03:59:40,705 StorageService.java (line 1049) Node /10.40.33.128
state jump to normal
>  INFO [main] 2012-02-06 03:59:40,711 StorageService.java (line 1275) calculate pending
ranges called, took 6 ms
>  INFO [main] 2012-02-06 03:59:40,711 StorageService.java (line 641) Bootstrap/Replace/Move
completed! Now serving reads.
>  INFO [main] 2012-02-06 03:59:40,712 Mx4jTool.java (line 72) Will not load MX4J, mx4j-tools.jar
is not in the classpath
>  INFO [main] 2012-02-06 03:59:40,736 CassandraDaemon.java (line 125) Binding thrift service
to localhost/127.0.0.1:9160
>  INFO [main] 2012-02-06 03:59:40,738 CassandraDaemon.java (line 134) Using TFastFramedTransport
with a max frame size of 15728640 bytes.
>  INFO [main] 2012-02-06 03:59:40,740 CassandraDaemon.java (line 161) Using synchronous/threadpool
thrift server on localhost/127.0.0.1 : 9160
>  INFO [Thread-2] 2012-02-06 03:59:40,741 CassandraDaemon.java (line 213) Listening for
thrift clients...
> {code}

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

       

Mime
View raw message