From commits-return-213891-archive-asf-public=cust-asf.ponee.io@cassandra.apache.org Wed Sep 5 15:21:06 2018 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id 571FE180654 for ; Wed, 5 Sep 2018 15:21:05 +0200 (CEST) Received: (qmail 77403 invoked by uid 500); 5 Sep 2018 13:21:04 -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 77391 invoked by uid 99); 5 Sep 2018 13:21:04 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 05 Sep 2018 13:21:04 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id D221B1800D8 for ; Wed, 5 Sep 2018 13:21:03 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -109.501 X-Spam-Level: X-Spam-Status: No, score=-109.501 tagged_above=-999 required=6.31 tests=[ENV_AND_HDR_SPF_MATCH=-0.5, KAM_ASCII_DIVIDERS=0.8, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, USER_IN_DEF_SPF_WL=-7.5, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id b608FjaMa8HX for ; Wed, 5 Sep 2018 13:21:02 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id 5AAEC5F3CD for ; Wed, 5 Sep 2018 13:21:01 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 89B18E12FE for ; Wed, 5 Sep 2018 13:21:00 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 1DF6426B57 for ; Wed, 5 Sep 2018 13:21:00 +0000 (UTC) Date: Wed, 5 Sep 2018 13:21:00 +0000 (UTC) From: "Thomas Steinmaurer (JIRA)" To: commits@cassandra.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CASSANDRA-14691) Cassandra 2.1 backport - The JVM should exit if jmx fails to bind MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CASSANDRA-14691?page=3Dcom.atla= ssian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId= =3D16604394#comment-16604394 ]=20 Thomas Steinmaurer commented on CASSANDRA-14691: ------------------------------------------------ Could be a source for corruption. {noformat} ERROR [main] 2018-08-05 21:10:24,046 CassandraDaemon.java:120 - Error start= ing local jmx server:=20 java.rmi.server.ExportException: Port already in use: 7199; nested exceptio= n is:=20 java.net.BindException: Address already in use (Bind failed= ) =E2=80=A6 =20 But then continuing with stuff like opening system and even user tables: =20 INFO [main] 2018-08-05 21:10:24,060 CacheService.java:110 - Initializing k= ey cache with capacity of 100 MBs. INFO [main] 2018-08-05 21:10:24,067 CacheService.java:132 - Initializing r= ow cache with capacity of 0 MBs INFO [main] 2018-08-05 21:10:24,073 CacheService.java:149 - Initializing c= ounter cache with capacity of 50 MBs INFO [main] 2018-08-05 21:10:24,074 CacheService.java:160 - Scheduling cou= nter cache save to every 7200 seconds (going to save all keys). INFO [main] 2018-08-05 21:10:24,161 ColumnFamilyStore.java:365 - Initializ= ing system.sstable_activity INFO [SSTableBatchOpen:2] 2018-08-05 21:10:24,692 SSTableReader.java:475 -= Opening /var/opt/xxx-managed/cassandra/system/sstable_activity-5a1ff267ace= 03f128563cfae6103c65e/system-sstable_activity-ka-165 (2023 bytes) INFO [SSTableBatchOpen:3] 2018-08-05 21:10:24,692 SSTableReader.java:475 -= Opening /var/opt/xxx-managed/cassandra/system/sstable_activity-5a1ff267ace= 03f128563cfae6103c65e/system-sstable_activity-ka-167 (2336 bytes) INFO [SSTableBatchOpen:1] 2018-08-05 21:10:24,692 SSTableReader.java:475 -= Opening /var/opt/xxx-managed/cassandra/system/sstable_activity-5a1ff267ace= 03f128563cfae6103c65e/system-sstable_activity-ka-166 (2686 bytes) INFO [main] 2018-08-05 21:10:24,755 ColumnFamilyStore.java:365 - Initializ= ing system.hints INFO [SSTableBatchOpen:1] 2018-08-05 21:10:24,758 SSTableReader.java:475 -= Opening /var/opt/xxx-managed/cassandra/system/hints-2666e20573ef38b390fefe= cf96e8f0c7/system-hints-ka-377 (46210621 bytes) INFO [main] 2018-08-05 21:10:24,766 ColumnFamilyStore.java:365 - Initializ= ing system.compaction_history INFO [SSTableBatchOpen:1] 2018-08-05 21:10:24,768 SSTableReader.java:475 -= Opening /var/opt/xxx-managed/cassandra/system/compaction_history-b4dbb7b4d= c493fb5b3bfce6e434832ca/system-compaction_history-ka-129 (91269 bytes) =E2=80=A6 =20 Replaying commit logs: =20 =E2=80=A6 INFO [main] 2018-08-05 21:10:25,896 CommitLogReplayer.java:267 - Replaying= /var/opt/xxx-managed/cassandra/commitlog/CommitLog-4-1533133668366.log INFO [main] 2018-08-05 21:10:25,896 CommitLogReplayer.java:270 - Replaying= /var/opt/xxx-managed/cassandra/commitlog/CommitLog-4-1533133668366.log (CL= version 4, messaging version 8) =E2=80=A6 =20 Even writing memtables already (below just pasted system tables, but also u= ser tables): =20 =E2=80=A6 INFO [MemtableFlushWriter:4] 2018-08-05 21:11:52,524 Memtable.java:347 - W= riting Memtable-size_estimates@1941663179(2.655MiB serialized bytes, 325710= ops, 2%/0% of on/off-heap limit) INFO [MemtableFlushWriter:3] 2018-08-05 21:11:52,552 Memtable.java:347 - W= riting Memtable-peer_events@1474667699(0.199KiB serialized bytes, 4 ops, 0%= /0% of on/off-heap limit) =E2=80=A6 =20 Until it comes to a point where it can=E2=80=99t bind ports like the storag= e port 7000: =20 ERROR [main] 2018-08-05 21:11:54,350 CassandraDaemon.java:395 - Fatal confi= guration error org.apache.cassandra.exceptions.ConfigurationException: /XXX:7000 is in use= by another process. Change listen_address:storage_port in cassandra.yaml = to values that do not conflict with other services at org.apache.cassandra.net.MessagingService.getServerSocke= ts(MessagingService.java:495) ~[apache-cassandra-2.1.18.jar:2.1.18] =E2=80=A6 =20 Until Cassandra stops: =20 =E2=80=A6 INFO [StorageServiceShutdownHook] 2018-08-05 21:11:54,361 Gossiper.java:14= 54 - Announcing shutdown =E2=80=A6 =20 =20 So, we have around 2 minutes where Cassandra is mangling with existing data= , although it shouldn=E2=80=99t. =20 Sounds like a potential candidate for data corruption, right? E.g. later on= we then see things like (still while being in progress to shutdown?): =20 WARN [SharedPool-Worker-1] 2018-08-05 21:11:58,181 AbstractTracingAwareExe= cutorService.java:169 - Uncaught exception on thread Thread[SharedPool-Work= er-1,5,main]: {} java.lang.RuntimeException: java.io.FileNotFoundException: /var/opt/xxx-man= aged/cassandra/xxx/xxx-fdc68b70950611e8ad7179f2d5bfa3cf/xxx-xxx-ka-15-Data.= db (No such file or directory) at org.apache.cassandra.io.compress.CompressedRandomAccessR= eader.open(CompressedRandomAccessReader.java:52) ~[apache-cassandra-2.1.18.= jar:2.1.18] at org.apache.cassandra.io.util.CompressedPoolingSegmentedF= ile.createPooledReader(CompressedPoolingSegmentedFile.java:95) ~[apache-cas= sandra-2.1.18.jar:2.1.18] at org.apache.cassandra.io.util.PoolingSegmentedFile.getSeg= ment(PoolingSegmentedFile.java:62) ~[apache-cassandra-2.1.18.jar:2.1.18] =E2=80=A6 {noformat} > Cassandra 2.1 backport - The JVM should exit if jmx fails to bind > ----------------------------------------------------------------- > > Key: CASSANDRA-14691 > URL: https://issues.apache.org/jira/browse/CASSANDRA-1469= 1 > Project: Cassandra > Issue Type: Bug > Components: Core > Reporter: Thomas Steinmaurer > Assignee: Alex Petrov > Priority: Major > Labels: lhf > Fix For: 2.1.x > > > If you are already running a cassandra instance, but for some reason try = to start another one, this happens: > {noformat} > INFO 20:57:09 JNA mlockall successful > WARN 20:57:09 JMX is not enabled to receive remote connections. Please s= ee cassandra-env.sh for more info. > ERROR 20:57:10 Error starting local jmx server: > java.rmi.server.ExportException: Port already in use: 7199; nested except= ion is: > java.net.BindException: Address already in use > at sun.rmi.transport.tcp.TCPTransport.listen(TCPTransport.java:34= 0) ~[na:1.7.0_76] > at sun.rmi.transport.tcp.TCPTransport.exportObject(TCPTransport.j= ava:248) ~[na:1.7.0_76] > at sun.rmi.transport.tcp.TCPEndpoint.exportObject(TCPEndpoint.jav= a:411) ~[na:1.7.0_76] > at sun.rmi.transport.LiveRef.exportObject(LiveRef.java:147) ~[na:= 1.7.0_76] > at sun.rmi.server.UnicastServerRef.exportObject(UnicastServerRef.= java:207) ~[na:1.7.0_76] > at sun.rmi.registry.RegistryImpl.setup(RegistryImpl.java:122) ~[n= a:1.7.0_76] > at sun.rmi.registry.RegistryImpl.(RegistryImpl.java:98) ~[n= a:1.7.0_76] > at java.rmi.registry.LocateRegistry.createRegistry(LocateRegistry= .java:239) ~[na:1.7.0_76] > at org.apache.cassandra.service.CassandraDaemon.maybeInitJmx(Cass= andraDaemon.java:100) [main/:na] > at org.apache.cassandra.service.CassandraDaemon.setup(CassandraDa= emon.java:222) [main/:na] > at org.apache.cassandra.service.CassandraDaemon.activate(Cassandr= aDaemon.java:564) [main/:na] > at org.apache.cassandra.service.CassandraDaemon.main(CassandraDae= mon.java:653) [main/:na] > Caused by: java.net.BindException: Address already in use > at java.net.PlainSocketImpl.socketBind(Native Method) ~[na:1.7.0_= 76] > at java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.= java:376) ~[na:1.7.0_76] > at java.net.ServerSocket.bind(ServerSocket.java:376) ~[na:1.7.0_7= 6] > at java.net.ServerSocket.(ServerSocket.java:237) ~[na:1.7.0= _76] > at javax.net.DefaultServerSocketFactory.createServerSocket(Server= SocketFactory.java:231) ~[na:1.7.0_76] > at org.apache.cassandra.utils.RMIServerSocketFactoryImpl.createSe= rverSocket(RMIServerSocketFactoryImpl.java:13) ~[main/:na] > at sun.rmi.transport.tcp.TCPEndpoint.newServerSocket(TCPEndpoint.= java:666) ~[na:1.7.0_76] > at sun.rmi.transport.tcp.TCPTransport.listen(TCPTransport.java:32= 9) ~[na:1.7.0_76] > ... 11 common frames omitted > {noformat} > However the startup continues, and ends up replaying commitlogs, which is= probably not a good thing. -- This message was sent by Atlassian JIRA (v7.6.3#76005) --------------------------------------------------------------------- To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org For additional commands, e-mail: commits-help@cassandra.apache.org