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 19FD7188C5 for ; Fri, 4 Dec 2015 20:33:50 +0000 (UTC) Received: (qmail 88499 invoked by uid 500); 4 Dec 2015 20:33:46 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 88456 invoked by uid 500); 4 Dec 2015 20:33:46 -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 88446 invoked by uid 99); 4 Dec 2015 20:33:46 -0000 Received: from Unknown (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 04 Dec 2015 20:33:46 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id 27969C15CA for ; Fri, 4 Dec 2015 20:33:46 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 3.129 X-Spam-Level: *** X-Spam-Status: No, score=3.129 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, FREEMAIL_ENVFROM_END_DIGIT=0.25, HTML_MESSAGE=3, RCVD_IN_MSPIKE_H3=-0.01, RCVD_IN_MSPIKE_WL=-0.01, SPF_PASS=-0.001] autolearn=disabled Authentication-Results: spamd1-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-us-west.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id bDwchggwXoE7 for ; Fri, 4 Dec 2015 20:33:45 +0000 (UTC) Received: from mail-lb0-f180.google.com (mail-lb0-f180.google.com [209.85.217.180]) by mx1-us-west.apache.org (ASF Mail Server at mx1-us-west.apache.org) with ESMTPS id 618B835C3C for ; Fri, 4 Dec 2015 20:33:44 +0000 (UTC) Received: by lbbed20 with SMTP id ed20so12832401lbb.2 for ; Fri, 04 Dec 2015 12:33:36 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=PXt/q6VN+gw7Lm2r26MJhX58iNbCLedaiXdChxWLBeM=; b=aDY6SAV3ZTH5VLDD2C9XqywIbtAq6784jrKVYfFRIIdcZsBZT72ygHFosJ1X/vC02H TIn9HZizi9BGIZCSjZsecAIADJQk+7mT7sex5kvIKrs4k+rkJ9mt3yLti1fgzYdVBVaL 9lmW2sU2yA+hDsG7oiu7hHZFXWF+B76PDb8EiArnTyci4uREgYwBn2gp7wNp8sOFLoUr Mm+YmiyD7jonZYhgRdyEi0CdbTQi1epc5kn07tcZ/pksOx3tt7vm3ntuFZbhDEt2UGZD I46Oy/Kb8RIRf9cX8cZDM+2+cE6Lnt3tJO8kT4vyU0QArzP9+9SkB59XJwjJhSVQc//P 37zw== MIME-Version: 1.0 X-Received: by 10.112.181.102 with SMTP id dv6mr1065412lbc.18.1449261216785; Fri, 04 Dec 2015 12:33:36 -0800 (PST) Received: by 10.25.73.8 with HTTP; Fri, 4 Dec 2015 12:33:36 -0800 (PST) In-Reply-To: References: Date: Fri, 4 Dec 2015 14:33:36 -0600 Message-ID: Subject: Re: Infinite loop in SliceQueryFilter From: Chris Lohfink To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=001a11c36908036c280526186ce4 --001a11c36908036c280526186ce4 Content-Type: text/plain; charset=UTF-8 May just be going over a lot of data. Does output of 'nodetool cfstats' show large partitions? (partition maximum bytes). "collecting 1 of 2147483647" is suspicious. Are your queries using ALLOW FILTERING or have very high limits? If trying to read 2 billion entries in 1 query you will have memory issues. May want to check with jvmtop/htop to make sure its not GCs using CPU as well. Is there a sane amount of sstables? Providing some more details can help (cfstats, cfhistograms, queries your making, schema) Chris On Fri, Dec 4, 2015 at 10:43 AM, Xihui He wrote: > Dear All, > > Recently one of node in our cluster has high cpu load ~100%. It seems to > me there is a infinite loop in SliceQueryFilter. > > The below log is repeated in 5000ms (range_request_timeout_in_ms). > TRACE [SharedPool-Worker-11] 2015-12-04 19:25:33,418 > SliceQueryFilter.java:269 - collecting 1 of 2147483647: > images:b608719e728d11e5812b57f4c5416142:false:62@1444838867382000 > > Our version is 2.19. Here is the bt: > > org.apache.cassandra.db.composites.AbstractComposite.isEmpty(AbstractComposite.java:30) > > org.apache.cassandra.db.OnDiskAtom$Serializer.deserializeFromSSTable(OnDiskAtom.java:76) > org.apache.cassandra.db.AbstractCell$1.computeNext(AbstractCell.java:52) > org.apache.cassandra.db.AbstractCell$1.computeNext(AbstractCell.java:46) > > com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) > > com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) > > org.apache.cassandra.db.columniterator.SimpleSliceReader.computeNext(SimpleSliceReader.java:83) > > org.apache.cassandra.db.columniterator.SimpleSliceReader.computeNext(SimpleSliceReader.java:37) > > com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) > > com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) > > org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(SSTableSliceIterator.java:82) > org.apache.cassandra.db.filter.QueryFilter$2.getNext(QueryFilter.java:173) > org.apache.cassandra.db.filter.QueryFilter$2.hasNext(QueryFilter.java:156) > > org.apache.cassandra.utils.MergeIterator$Candidate.advance(MergeIterator.java:146) > > org.apache.cassandra.utils.MergeIterator$ManyToOne.advance(MergeIterator.java:125) > > org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:99) > > com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) > > com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) > > org.apache.cassandra.db.filter.SliceQueryFilter.collectReducedColumns(SliceQueryFilter.java:264) > > org.apache.cassandra.db.filter.QueryFilter.collateColumns(QueryFilter.java:108) > > org.apache.cassandra.db.filter.QueryFilter.collateOnDiskAtom(QueryFilter.java:82) > > org.apache.cassandra.db.filter.QueryFilter.collateOnDiskAtom(QueryFilter.java:69) > > org.apache.cassandra.db.CollationController.collectAllData(CollationController.java:314) > > org.apache.cassandra.db.CollationController.getTopLevelColumns(CollationController.java:65) > > org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:2033) > > org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1876) > org.apache.cassandra.db.Keyspace.getRow(Keyspace.java:357) > > org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:85) > org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:47) > > org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:64) > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > > org.apache.cassandra.concurrent.AbstractTracingAwareExecutorService$FutureTask.run(AbstractTracingAwareExecutorService.java:164) > org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105) > > java.lang.Thread.run(Thread.java:745) > > Appreciate if anyone could help. > > Thanks in advance, > Xihui > --001a11c36908036c280526186ce4 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
May just be going over a lot of data. Does output of '= nodetool cfstats' show large partitions? (partition maximum bytes). "collecting 1 of=C2=A02147483647&q= uot; is suspicious.=C2=A0Are your queries using ALLOW FILTERING or have ver= y high limits? If trying to read 2 billion entries in 1 query you will have= memory issues. May want to check with jvmtop/htop to make sure its not GCs= using CPU as well. Is there a sane amount of sstables? Providing some more= details can help (cfstats, cfhistograms, queries your making, schema)
=
Chris

On Fri, Dec 4, 2015 at 10:43 AM, Xihui He <xihuihe@gmail.= com> wrote:
Dear All,

Recently one of nod= e in our cluster has high cpu load ~100%. It seems to me there is a infinit= e loop in SliceQueryFilter.

The below log is repeated in= 5000ms (range_request_timeout_in_ms).
TRACE [SharedPool-Worker-11] 2015-12-04 = 19:25:33,418 SliceQueryFilter.java:269 - collecting 1 of 2147483647: images:b6= 08719e728d11e5812b57f4c5416142:false:62@1444838867382000

Our version is 2.19. Here is th= e bt:
org= .apache.cassandra.db.composites.AbstractComposite.isEmpty(AbstractComposite= .java:30)
org.apache.cassandra.db.OnDiskAtom$Serializer.deserializeFromSSTable(OnDis= kAtom.java:76)
org.apache.cassandra.db.AbstractCell$1.computeNext(AbstractCell.java:= 52)
org.a= pache.cassandra.db.AbstractCell$1.computeNext(AbstractCell.java:46)
com.google.commo= n.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
com.google.co= mmon.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
org.apache.cassandr= a.db.columniterator.SimpleSliceReader.computeNext(SimpleSliceReader.java:83= )
org.apa= che.cassandra.db.columniterator.SimpleSliceReader.computeNext(SimpleSliceRe= ader.java:37)
com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIt= erator.java:143)
com.google.common.collect.AbstractIterator.hasNext(AbstractIterator= .java:138)
org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(SSTab= leSliceIterator.java:82)
org.apache.cassandra.db.filter.QueryFilter$2.getNext(QueryF= ilter.java:173)
org.apache.cassandra.db.filter.QueryFilter$2.hasNext(QueryFilter.jav= a:156)
or= g.apache.cassandra.utils.MergeIterator$Candidate.advance(MergeIterator.java= :146)
org= .apache.cassandra.utils.MergeIterator$ManyToOne.advance(MergeIterator.java:= 125)
org.= apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.ja= va:99)
co= m.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.= java:143)
com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:1= 38)
org.a= pache.cassandra.db.filter.SliceQueryFilter.collectReducedColumns(SliceQuery= Filter.java:264)
org.apache.cassandra.db.filter.QueryFilter.collateColumns(QueryFilt= er.java:108)
org.apache.cassandra.db.filter.QueryFilter.collateOnDiskAtom(QueryFilte= r.java:82)
org.apache.cassandra.db.filter.QueryFilter.collateOnDiskAtom(QueryFilter.= java:69)
= org.apache.cassandra.db.CollationController.collectAllData(CollationControl= ler.java:314)
org.apache.cassandra.db.CollationController.getTopLevelColumns(Collati= onController.java:65)
org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(C= olumnFamilyStore.java:2033)
org.apache.cassandra.db.ColumnFamilyStore.getColumnFamil= y(ColumnFamilyStore.java:1876)
org.apache.cassandra.db.Keyspace.getRow(Keyspace.java= :357)
org= .apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:= 85)
org.a= pache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:47)
org.apache.cassan= dra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:64)
java.util.concurrent.Ex= ecutors$RunnableAdapter.call(Executors.java:471)
org.apache.cassandra.concurrent.Abs= tractTracingAwareExecutorService$FutureTask.run(AbstractTracingAwareExecuto= rService.java:164)
org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:105)=

java.= lang.Thread.run(Thread.java:745)

Appreciate if anyone could help.

Thanks in advance,
Xihui
<= /blockquote>

--001a11c36908036c280526186ce4--