Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 339C2200B69 for ; Sat, 20 Aug 2016 14:40:24 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 2F877160ABB; Sat, 20 Aug 2016 12:40:24 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 28F51160AAA for ; Sat, 20 Aug 2016 14:40:23 +0200 (CEST) Received: (qmail 70529 invoked by uid 500); 20 Aug 2016 12:40:22 -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 70518 invoked by uid 99); 20 Aug 2016 12:40:22 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 20 Aug 2016 12:40:22 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 348492C0050 for ; Sat, 20 Aug 2016 12:40:22 +0000 (UTC) Date: Sat, 20 Aug 2016 12:40:22 +0000 (UTC) From: "Stefano Ortolani (JIRA)" To: commits@cassandra.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CASSANDRA-11906) Unstable JVM due too many files when anticompacting big LCS tables MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Sat, 20 Aug 2016 12:40:24 -0000 [ https://issues.apache.org/jira/browse/CASSANDRA-11906?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15429360#comment-15429360 ] Stefano Ortolani commented on CASSANDRA-11906: ---------------------------------------------- How many SStables are created during AntiCompaction? With my current setup I have three CFs that spike to 700/800 on every node during repairs. > Unstable JVM due too many files when anticompacting big LCS tables > ------------------------------------------------------------------ > > Key: CASSANDRA-11906 > URL: https://issues.apache.org/jira/browse/CASSANDRA-11906 > Project: Cassandra > Issue Type: Bug > Reporter: Stefano Ortolani > Assignee: Sean McCarthy > Fix For: 3.0.x > > > I have recently moved from C* 2.1.x to C* 3.0.6. The setup is quite > heavy: > - 13 nodes with spinning disks > - ~120 GB of data per node > - 50% of CFs are LCS and have quite wide rows. > - 2/3 CFs with LCS have more than 200 SStables > Incremental repairs do not seem to play really well with that. > I have been running some tests node by node by using the -pr option: > {code:xml} > nodetool -h localhost repair -pr keyscheme > {code} > and to my surprise the whole process takes quite some time (1 hour > minimum, 8 hours if I haven't been repairing for 5/6 days). > Yesterday I tried to run the command with the -seq option so to > decrease the number of simultanoues compactions. After a while > the node on which I was running the repair simply died during > the anticompaction phase with the following > exception in the logs. > {code:xml} > ERROR [metrics-graphite-reporter-1-thread-1] 2016-05-25 21:54:21,868 ScheduledReporter.java:119 - RuntimeException thrown from GraphiteReporter#report. Exception was suppressed. > java.lang.RuntimeException: Failed to list files in /data/cassandra/data/keyschema/columnfamily-3996ce80b7ac11e48a9b6776bf484396 > at org.apache.cassandra.db.lifecycle.LogAwareFileLister.list(LogAwareFileLister.java:57) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.lifecycle.LifecycleTransaction.getFiles(LifecycleTransaction.java:547) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.Directories$SSTableLister.filter(Directories.java:691) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.Directories$SSTableLister.listFiles(Directories.java:662) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.Directories$TrueFilesSizeVisitor.(Directories.java:981) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.Directories.getTrueAllocatedSizeIn(Directories.java:893) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.Directories.trueSnapshotsSize(Directories.java:883) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.ColumnFamilyStore.trueSnapshotsSize(ColumnFamilyStore.java:2332) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.metrics.TableMetrics$32.getValue(TableMetrics.java:637) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.metrics.TableMetrics$32.getValue(TableMetrics.java:634) ~[apache-cassandra-3.0.6.jar:3.0.6] > at com.codahale.metrics.graphite.GraphiteReporter.reportGauge(GraphiteReporter.java:281) ~[metrics-graphite-3.1.0.jar:3.1.0] > at com.codahale.metrics.graphite.GraphiteReporter.report(GraphiteReporter.java:158) ~[metrics-graphite-3.1.0.jar:3.1.0] > at com.codahale.metrics.ScheduledReporter.report(ScheduledReporter.java:162) ~[metrics-core-3.1.0.jar:3.1.0] > at com.codahale.metrics.ScheduledReporter$1.run(ScheduledReporter.java:117) ~[metrics-core-3.1.0.jar:3.1.0] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_91] > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_91] > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_91] > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_91] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_91] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_91] > at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91] > Caused by: java.lang.RuntimeException: java.nio.file.FileSystemException: /data/cassandra/data/keyschema/columnfamily-3996ce80b7ac11e48a9b6776bf484396/ma_txn_anticompactionafterrepair_f20b50d0-22bd-11e6-970f-6f22464f4624.log: Too many open files > at org.apache.cassandra.io.util.FileUtils.readLines(FileUtils.java:622) ~[apache-cassandra-3.0.6.jar:3.0.6] > at java.util.stream.Collectors.lambda$toMap$58(Collectors.java:1321) ~[na:1.8.0_91] > at java.util.stream.ReduceOps$3ReducingSink.accept(ReduceOps.java:169) ~[na:1.8.0_91] > at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193) ~[na:1.8.0_91] > at java.util.Iterator.forEachRemaining(Iterator.java:116) ~[na:1.8.0_91] > at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801) ~[na:1.8.0_91] > at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) ~[na:1.8.0_91] > at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[na:1.8.0_91] > at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708) ~[na:1.8.0_91] > at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:1.8.0_91] > at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499) ~[na:1.8.0_91] > at org.apache.cassandra.db.lifecycle.LogReplicaSet.readRecords(LogReplicaSet.java:105) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.lifecycle.LogFile.verify(LogFile.java:132) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.lifecycle.LogAwareFileLister.readTxnLog(LogAwareFileLister.java:113) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.lifecycle.LogAwareFileLister.classifyFiles(LogAwareFileLister.java:106) ~[apache-cassandra-3.0.6.jar:3.0.6] > at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184) ~[na:1.8.0_91] > at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175) ~[na:1.8.0_91] > at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1374) ~[na:1.8.0_91] > at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) ~[na:1.8.0_91] > at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[na:1.8.0_91] > at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151) ~[na:1.8.0_91] > at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174) ~[na:1.8.0_91] > at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:1.8.0_91] > at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418) ~[na:1.8.0_91] > at org.apache.cassandra.db.lifecycle.LogAwareFileLister.innerList(LogAwareFileLister.java:75) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.lifecycle.LogAwareFileLister.list(LogAwareFileLister.java:53) ~[apache-cassandra-3.0.6.jar:3.0.6] > ... 20 common frames omitted > Caused by: java.nio.file.FileSystemException: /data/cassandra/data/keyschema/columnfamily-3996ce80b7ac11e48a9b6776bf484396/ma_txn_anticompactionafterrepair_f20b50d0-22bd-11e6-970f-6f22464f4624.log: Too many open files > at sun.nio.fs.UnixException.translateToIOException(UnixException.java:91) ~[na:1.8.0_91] > at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102) ~[na:1.8.0_91] > at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107) ~[na:1.8.0_91] > at sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:214) ~[na:1.8.0_91] > at java.nio.file.Files.newByteChannel(Files.java:361) ~[na:1.8.0_91] > at java.nio.file.Files.newByteChannel(Files.java:407) ~[na:1.8.0_91] > at java.nio.file.spi.FileSystemProvider.newInputStream(FileSystemProvider.java:384) ~[na:1.8.0_91] > at java.nio.file.Files.newInputStream(Files.java:152) ~[na:1.8.0_91] > at java.nio.file.Files.newBufferedReader(Files.java:2784) ~[na:1.8.0_91] > at java.nio.file.Files.readAllLines(Files.java:3202) ~[na:1.8.0_91] > at org.apache.cassandra.io.util.FileUtils.readLines(FileUtils.java:615) ~[apache-cassandra-3.0.6.jar:3.0.6] > ... 45 common frames omitted > WARN [HintsWriteExecutor:1] 2016-05-25 21:54:28,389 CLibrary.java:256 - open(/var/lib/cassandra/hints, O_RDONLY) failed, errno (24). > ERROR [CompactionExecutor:2660] 2016-05-25 21:54:29,915 JVMStabilityInspector.java:139 - JVM state determined to be unstable. Exiting forcefully due to: > java.io.FileNotFoundException: /data/cassandra/data/keyschema/columnfamily-3996ce80b7ac11e48a9b6776bf484396/ma-92661-big-Filter.db (Too many open files) > at java.io.FileOutputStream.open0(Native Method) ~[na:1.8.0_91] > at java.io.FileOutputStream.open(FileOutputStream.java:270) ~[na:1.8.0_91] > at java.io.FileOutputStream.(FileOutputStream.java:213) ~[na:1.8.0_91] > at java.io.FileOutputStream.(FileOutputStream.java:101) ~[na:1.8.0_91] > at org.apache.cassandra.io.sstable.format.big.BigTableWriter$IndexWriter.flushBf(BigTableWriter.java:431) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.io.sstable.format.big.BigTableWriter$IndexWriter.doPrepare(BigTableWriter.java:461) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.utils.concurrent.Transactional$AbstractTransactional.prepareToCommit(Transactional.java:173) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.io.sstable.format.big.BigTableWriter$TransactionalProxy.doPrepare(BigTableWriter.java:303) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.utils.concurrent.Transactional$AbstractTransactional.prepareToCommit(Transactional.java:173) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.io.sstable.format.SSTableWriter.prepareToCommit(SSTableWriter.java:229) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.io.sstable.SSTableRewriter.doPrepare(SSTableRewriter.java:357) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.utils.concurrent.Transactional$AbstractTransactional.prepareToCommit(Transactional.java:173) ~[apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.compaction.CompactionManager.antiCompactGroup(CompactionManager.java:1303) [apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.compaction.CompactionManager.doAntiCompaction(CompactionManager.java:1232) [apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.compaction.CompactionManager.performAnticompaction(CompactionManager.java:569) [apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.db.compaction.CompactionManager$7.runMayThrow(CompactionManager.java:479) [apache-cassandra-3.0.6.jar:3.0.6] > at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28) [apache-cassandra-3.0.6.jar:3.0.6] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_91] > at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_91] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_91] > at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_91] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_91] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_91] > at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91] > {code} > Seems like that by using the -seq option, C* just opened wat too > many files. The limits are currently quite ok though, as showed below: > {code:xml} > root@node3:/# cat /etc/security/limits.d/cassandra.conf > # Provided by the cassandra package > cassandra - memlock unlimited > cassandra - nofile 100000 > cassandra - as unlimited > cassandra - nproc 8096 > {code} > Today I checked the number of file opened by C* (admittedly while running > another repair without the -seq option): > {code:xml} > pssh --inline-stdout -h cassandra-hosts.txt -l root -t 0 "lsof -n | grep java | grep cassandra | wc -l" > [1] 14:29:43 [SUCCESS] node3 (where the repair is taking place) > 25452 > [2] 14:29:43 [SUCCESS] node4 > 46779 > pssh --inline-stdout -h cassandra-hosts.txt -l root -t 0 "lsof -n | grep java | grep cassandra | grep 'REG' | wc -l" > [1] 14:26:40 [SUCCESS] node3 (where the repair is taking place) > 24020 > [2] 14:26:41 [SUCCESS] node4 > 4050 > {code} > Looks like that during a repair, lots of file descriptors on the repairing node > relate to regular files, while on all others the stark majority relate to memory > mapped files. > Nevertheless 25K is still way less then 100K (still high though). > (To be honest, when I started the repair nodetool logged it with "Starting repair > command #2". I didn't pay that much attention to that as the previous repair > had returned already for quite some time, but it might have been the case that > another repair was still lingering (weird if that was the case). > In conclusion, is this behavior normal? Shall I increase the limits, or is > AntiCompaction really playing badly with incremental repairs and LCS > (and quite overloaded to be honest) tables? -- This message was sent by Atlassian JIRA (v6.3.4#6332)